[ERROR] [FATAL] InnoDB: Semaphore wait has lasted > 600 seconds. We intentionally crash the server because it appears to be hung.
[ERROR] mysqld got signal 6 ;
DB는 얼마지나지 않아 다시 내려갔다.
눈앞이 캄캄해진다.
--> 며칠전에 오라클에서 마리아DB로 마이그레이션후 수많은 장애로 다시는 마리아DB를 쳐다보고 싶지 않다는 블로그에 글을 읽으며 속으로는 그러게 준비를 잘했어야지 RDB라고 다 같은 줄 아나? 라고 속으로 웃었는데.. 사람은 착하게 살아야; 막상 당해보니 너무 아프네
이제 방법은 2가지 문제를 해결하거나 아니면 MariaDB 10.2.15 로 롤백하는 방법뿐이다.
결정은 롤백에 소요되는 시간을 고려하면 남은시간은 15시간 뿐이다.
문뜩 그런생각이 들었다
이 일을 막을 수 있었나?
--> 막을 수 있었다. 서비스 DB와 동일한 환경에서 테스트를 더 했더라면 충분히 막을 수 있었다. 하지만 대용량DB라 그럴만한 서버가 없었다...아니다 그것을 설득하지 못한 DBA의 핑계일지도..
갑자기 요즘 즐겨보던 유튜브 중 한편이 생각난다.
www.youtube.com/watch?v=DsOUEAbzaIA
#경영효율화로 인한 희생 알래스카 항공 261편 ... 기장은 최선을 다했고 마지막까지 배면비행을 하며 사투를 벌였지만 살아남지 못했다... 나는 살아남을 수 있을까?
그냥그렇다.. 아무생각도 들지않고 멍하니 로그와 구글링 페이지만 30분째 보고 있었다.
하지만 시간은 한정되어 있고 그 시간안에 해결할 방법을 찾아야한다.
일단 정신차리고 error로그 먼저 확인해 본다.
2021-02-27 1:28:41 284 [ERROR] mysqld: Table './xxxDB/TB_STA_xxx' is marked as crashed and last (automatic?) repair failed
2021-02-27 1:28:41 284 [ERROR] mysqld: Table './xxxDB/TB_STA_xxxxx' is marked as crashed and last (automatic?) repair failedDB는 재시작하면서 복구를 했지만 MyISAM 테이블이 일부가 깨졌다. 수동복구를 진행한다.
MariaDB [xxxDB]> check table TB_STA_xxx;
+------------------+-------+----------+-------------------------------------------------------+
| Table | Op | Msg_type | Msg_text |
+--------------------------+----------+-------------------------------------------------------+
| xxxDB.TB_STA_xxx | check | warning | Table is marked as crashed and last repair failed |
| xxxDB.TB_STA_xxx | check | warning | 1 client is using or hasn't closed the table properly |
| xxxDB.TB_STA_xxx | check | warning | Size of indexfile is: 167163904 Should be: 1024 |
| xxxDB.TB_STA_xxx | check | error | Record-count is not ok; is 3159708 Should be: 0 |
| xxxDB.TB_STA_xxx | check | warning | Found 3159715 key parts. Should be: 0 |
| xxxDB.TB_STA_xxx | check | error | Corrupt |
+--------------------------+----------+-------------------------------------------------------+
6 rows in set (7.935 sec)
MariaDB [xxxDB]> repair table TB_STA_xxx;
+------------------+--------+----------+------------------------------------------+
| Table | Op | Msg_type | Msg_text |
+------------------+--------+----------+------------------------------------------+
| xxxDB.TB_STA_xxx | repair | warning | Number of rows changed from 0 to 3159708 |
| xxxDB.TB_STA_xxx | repair | status | OK |
+------------------+--------+----------+------------------------------------------+
2 rows in set (22.793 sec)'
테이블 복구후 DB가 내려간 부분을 확인해본다.
1 lock struct(s), heap size 1128, 0 row lock(s), undo log entries 218
MySQL thread id 21136, OS thread handle 140521381996288, query id 12716892 172.31.8.77 mdlbat Sending data
SELECT COUNT(*) FROM TB_xxx WHERE ..
카운트하는데 락이 생겼다? 뭔가 이상하다.
MetaLock을 확인해본다.
MariaDB [(none)]> SELECT * FROM INFORMATION_SCHEMA.METADATA_LOCK_INFO;
+-----------+-------------------------+---------------+----------------------+--------------+-----------------------+
| THREAD_ID | LOCK_MODE | LOCK_DURATION | LOCK_TYPE | TABLE_SCHEMA | TABLE_NAME |
+-----------+-------------------------+---------------+----------------------+--------------+-----------------------+
| 44657 | xxx_BACKUP_DDL | NULL | Backup lock | | |
| 44657 | xxx_EXCLUSIVE | NULL | Table metadata lock | xxxDB | TB_TEMP_xxx |
| 44657 | xxx_INTENTION_EXCLUSIVE | NULL | Schema metadata lock | xxxDB | |
| 44657 | xxx_SHARED_READ | NULL | Table metadata lock | xxxDB | TB_TEMP_xxx |
| 44657 | xxx_SHARED_READ | NULL | Table metadata lock | xxxDB | TB_BAT_xxx |
+-----------+-------------------------+---------------+----------------------+--------------+-----------------------+Schema metadata lock 이런 락은 처음보는데.. 뭔가 이상하다.
Tool로 접속해서 실제 테이블 데이터를 한번 봐야할 거 같다.
음?..Tool 자체 커넥션이 안된다. 다시 쉘로 돌아와서 보니 Meta LOCK이 잡혀있다.
| 45258 | xxxxx | 210.xxx.xxx.xxx:45944 | xxxDB | Query | 29 | Waiting for table metadata lock |
SELECT cc.CONSTRAINT_NAME, cc.CHECK_CLAUSE, tc.TABLE_NAME
FROM INFORMATION_SCHEMA.CHECK_CONSTRAINTS cc, INFORMATION_SCHEMA.TABLE_CONSTRAINTS tc
WHERE cc.CONSTRAINT_NAME = tc.CONSTRAINT_NAME
AND cc.CONSTRAINT_SCHEMA ='xxxDB' AND tc.TABLE_NAME='TB_TEMP_xxx'
ORDER BY cc.CONSTRAINT_NAME ;뭔가 이상하다. Create table로 대용량테이블에서 인댁스 걸린 일데이터만 쪼개서 생성하는 로직인데,
Tool에서 접속시 information 스키마부분을 조회한다고 Metalock이 잡혀 Tool 접속이 안된다는 것이..
MyISAM도 아니고.. InnoDB인데..
이 떄부터 MariaDB 10.4.17 자체 버그를 의심했다.
구글링하면서 MairDB를 업그레이드하고 동일한 현상의 문제를 겪은 사람들의 블로그를 하나둘씩 찾을 수 있었다.
innodb_purge_threads 를 1로 변경하면 임시조치로 DB가 재시작되는 것은 막을수 있다는 얘기가 있어
일단 반영해보기로 하였다.
MariaDB [(none)]> show global variables like 'innodb_purge%';
+--------------------------------------+-------+
| Variable_name | Value |
+--------------------------------------+-------+
| innodb_purge_batch_size | 300 |
| innodb_purge_rseg_truncate_frequency | 128 |
| innodb_purge_threads | 1 |
+--------------------------------------+-------+
3 rows in set (0.001 sec)
이제 끝났겠지라고 생각했지만 10시간후 DB는 재시작되었다.
이 방법은 아니다. 이제 남은시간은 4시간뿐;
MariaDB jira의 사례를 찾고 또 찾았다.
비슷한 사례의 글을 찾을 수 있었으나 해결했다는 글은 찾아볼 수 없었다.
그러던 중 10.4.15에서 17로 올린 사람은 고통받다 롤백을 결정했다는 글에서 링크걸린 글을 찾다보니
10.4.14에서 17로 올리고 동일한 현상으로 고통받고 있는 사람의 글 맨아래 comment에서
10.5.8에서 10.5.9로 올리고 해결되었다는 글을 찾을 수 있었다. 10.5.9의 10.4.x 동일버전은 10.4.18이다.
jira.mariadb.org/browse/MDEV-24378
Comments: I have been using 10.5.8 ... the problem has been resolved after upgrading to 10.5.9
그렇다면 10.4.18로 올려볼만하다.
--> 하지만 이제 4시간밖에 남지 않았다. 한번 선택하면 끝이다.
그리고 설득도 어려웠다. 업그레이드는 web/was를 내려야하기 때문에 윗선에 결제가 필요했다.
설득하고 또 설득했다. 롤백은 cold 백업후 중단시간이 길기 때문에 한번 해볼만한 시도라고...
(자세히 얘기하면 길어지고 설득하기 쉽지 않을 거 같아 간략하게 설명했지만
사실상 10.2.15로 롤백한다면 mariabackup shell도 xtrabackup으로 변경해야하고 redo log 파일변경부터해서, 10.3.x부터 mysql 부분 information 스키마, 계정관리등등..이 바뀌기 때문에 10.4.x의 mysql 스키마를 쓰지 못하고 이전 mysql 스키마만 다시 떠야하고.. 많이 복잡해진다.)
다행히 1시간만에 업그레이드가 결정되었고 내선택이 최선이길 바라며 MaiaDB 10.4.18로 업그레이드를 진행하였다.
mariadb.com/kb/en/mariadb-10418-release-notes/
Last month long-time MariaDB VP of Engineering, Rasmus Johansson, passed due to complications from cancer.
His loss has been felt keenly by the whole MariaDB team.
Our thoughts are with his family during this difficult time and this release is dedicated to his memory.
-->이번 release는 뭔가 좀 다르다. 마음이 먹먹해지는 글이다. 그를 위해 바치는 이 release가 나에게도 한줄기 빛이 되길 기대해본다 제발!!
[root@xxx-db bin]# service mysqld start
....... [ OK ]
[admin@xxx-db bin]$ mysql -uroot -p
Enter password:
Welcome to the MariaDB monitor. Commands end with ; or \g.
Your MariaDB connection id is 20
Server version: 10.4.18-MariaDB-log MariaDB Server
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
MariaDB [(none)]> show processlist;
+----+-------------+----------------------+-------+---------+------+--------------------------+------------------+----------+
| Id | User | Host | db | Command | Time | State | Info | Progress |
+----+-------------+----------------------+-------+---------+------+--------------------------+------------------+----------+
| 4 | system user | | NULL | Daemon | NULL | InnoDB purge worker | NULL | 0.000 |
| 2 | system user | | NULL | Daemon | NULL | InnoDB purge coordinator | NULL | 0.000 |
| 1 | system user | | NULL | Daemon | NULL | InnoDB purge worker | NULL | 0.000 |
| 3 | system user | | NULL | Daemon | NULL | InnoDB purge worker | NULL | 0.000 |
| 5 | system user | | NULL | Daemon | NULL | InnoDB shutdown handler | NULL | 0.000 |
...
| 20 | root | localhost | NULL | Query | 0 | Init | show processlist | 0.000 |
+----+-------------+----------------------+-------+---------+------+--------------------------+------------------+----------+
17 rows in set (0.000 sec)
MariaDB [(none)]> exit
Bye
//10.4.18로 바뀐거 확인하고 데이터 업그레이드 진행하였다.
[root@xxx-db bin]# ./mysql_upgrade -uroot -p
Enter password:
Phase 1/7: Checking and upgrading mysql database
Processing databases
mysql
mysql.column_stats OK
mysql.columns_priv OK
mysql.db OK
mysql.event OK
mysql.func OK
mysql.global_priv OK
mysql.gtid_slave_pos OK
mysql.help_category OK
mysql.help_keyword OK
mysql.help_relation OK
mysql.help_topic OK
mysql.index_stats OK
mysql.innodb_index_stats OK
mysql.innodb_table_stats OK
mysql.plugin OK
mysql.proc OK
mysql.procs_priv OK
mysql.proxies_priv OK
mysql.roles_mapping OK
mysql.servers OK
mysql.table_stats OK
mysql.tables_priv OK
mysql.time_zone OK
mysql.time_zone_leap_second OK
mysql.time_zone_name OK
mysql.time_zone_transition OK
mysql.time_zone_transition_type OK
mysql.transaction_registry OK
Phase 2/7: Installing used storage engines... Skipped
Phase 3/7: Fixing views
.....
information_schema
performance_schema
test
Phase 7/7: Running 'FLUSH PRIVILEGES'
OK
[root@xxx-db error]# service mysqld restart
Shutting down MariaDB.. [ OK ]
Starting MariaDB.210227 14:39:24 mysqld_safe Logging to '/data/mariadb_logs/error/mysql.err'.
210227 14:39:24 mysqld_safe Starting mysqld daemon with databases from /data/mariadb_data
[ OK ]
DB는 2021.3.15일 현재까지 정상적으로 잘 돌아가고 있다.
결과적으로 MariaDB 10.4.17 stable 버전을 설치했지만 자체버그이고
10.4.17을 10.4.18로 올리고 모든 문제는 해결되었다.
왜 무리하게 버전을 올리려고 했을까? 돌이켜 생각해보면 별도의 튜닝없이도 1시간 걸리는 배치가
40분내외로 줄어드는 성능향상을 확인했고,
100개가 넘는 배치들과 현재DB의 수용능력이 포화상태라 생각해서 결정한 일이었는데,
꼼꼼한 테스트를 하지 못해 악수가 되고 말았다.
DB 업그레이드는 많은 시간과 테스트를 해보고 좀 더 보수적으로 해야한다는 것을 다시한번 느끼게 해주는 경험이었다.
나의 주말은 2주째 치열했지만 누군가 MariaDB 업그레이드후 고통받고 있을 분에게 도움이 되길..
나는 살아남았다.
2차 대응 끝.
'RDB > mariadb' 카테고리의 다른 글
| mariadb partition table(파티션 테이블)을 join 사용할 때는 성능 이슈에 주의해야 한다 (0) | 2023.06.27 |
|---|---|
| 일반 user에게 outfile 권한 할당하기 (0) | 2021.06.04 |
| mariadb 10.4.17 upgrade 이후 장애 1 (0) | 2021.03.12 |
| MariaDB 10.2 to 10.4 upgrade (0) | 2020.11.10 |
| MariaDB 파티션 생성, 삭제, 추가 (0) | 2020.11.04 |
dung beetle
취미는 데이터 수집 직업은 MYSQL과 함께 일하는 DBA의 소소한 일상 이야기
