时间：2022-03-01 10:19:24 | 栏目：Mysql | 点击：次
前几天，有位朋友微信联系我，告知一个生产数据库，在机器宕机恢复后，实例启动失败，而且该实例没有做任何的高可用、容灾、备份等，对业务影响非常大，希望能够协助排查一下，我也在第一时间就加入到排查中。
（1）首先查看错误日志，报错很清晰"Could not open log file"，无法打开日志文件
2021-01-06 13:23:51 20464 [ERROR] Failed to open log (file 'something is definitely wrong and this may fail.', errno 2) 2021-01-06 13:23:51 20464 [ERROR] Could not open log file 2021-01-06 13:23:51 20464 [ERROR] Can't init tc log 2021-01-06 13:23:51 20464 [ERROR] Aborting
（2）看到上述报错后，当然就应该想到，检查下my.cnf配置是否正确、日志目录和权限是否正确，但排查并未发现问题
# less my.cnf datadir=/var/lib/mysql log-bin=mysql-bin relay-log=relay-bin # ls -lrt -rw-rw---- 1 mysql mysql 1073761373 Jan 4 06:18 mysql-bin.007351 -rw-rw---- 1 mysql mysql 1073755587 Jan 4 09:26 mysql-bin.007352 -rw-rw---- 1 mysql mysql 1073777045 Jan 4 12:07 mysql-bin.007353 -rw-rw---- 1 mysql mysql 1073742801 Jan 4 15:12 mysql-bin.007354 -rw-rw---- 1 mysql mysql 1074087344 Jan 4 18:13 mysql-bin.007355 -rw-rw---- 1 mysql mysql 1073869414 Jan 4 21:32 mysql-bin.007356 -rw-rw---- 1 mysql mysql 1073771900 Jan 5 00:16 mysql-bin.007357 -rw-rw---- 1 mysql mysql 213063247 Jan 5 01:00 mysql-bin.007358 -rw-rw---- 1 mysql mysql 1073753668 Jan 5 02:11 mysql-bin.007359 -rw-rw---- 1 mysql mysql 671219722 Jan 5 03:31 mysql-bin.007360 -rw-rw---- 1 mysql mysql 1073774928 Jan 5 07:34 mysql-bin.007361 -rw-rw---- 1 mysql mysql 1073845285 Jan 5 11:33 mysql-bin.007362 -rw-rw---- 1 mysql mysql 1073756444 Jan 5 15:37 mysql-bin.007363 -rw-rw---- 1 mysql mysql 1073790555 Jan 5 19:37 mysql-bin.007364 -rw-rw---- 1 mysql mysql 1073768027 Jan 5 23:59 mysql-bin.007365 -rw-rw---- 1 mysql mysql 311398643 Jan 6 01:00 mysql-bin.007366 -rw-rw---- 1 mysql mysql 1071242043 Jan 6 03:31 mysql-bin.007367 -rw-rw---- 1 mysql mysql 1010516229 Jan 6 07:27 mysql-bin.007368 -rw-rw---- 1 mysql mysql 1651 Jan 6 07:27 mysql-bin.index -rw-rw---- 1 mysql mysql 1073741824 Jan 6 12:08 ib_logfile1 -rw-r--r-- 1 mysql mysql 183 Jan 6 13:23 VM_58_10_centos-slow.log -rw-rw---- 1 mysql mysql 1073741824 Jan 6 13:23 ib_logfile0 -rw-rw---- 1 mysql mysql 7492941 Jan 6 13:23 VM_58_10_centos.err
（3）报错有一个非常奇怪的点，file 'something is definitely wrong and this may fail.' ，为什么日志文件名会那么奇怪呢？这里需要知道的是，mysql-bin.index记录了binlog相关信息，MySQL实例启动时需要读取该文件获取信息；那接下来就检查一下该文件，发现果然有问题，mysql-bin.index后半部分错误写入了错误日志的内容，从而导致实例启动时读取到错误内容(当作binlog日志文件进行处理)报错失败
# cat mysql-bin.index ./mysql-bin.007351 ./mysql-bin.007352 ./mysql-bin.007353 ./mysql-bin.007354 ./mysql-bin.007355 ./mysql-bin.007356 ./mysql-bin.007357 ./mysql-bin.007358 ./mysql-bin.007359 ./mysql-bin.007360 ./mysql-bin.007361 ./mysql-bin.007362 ./mysql-bin.007363 ./mysql-bin.007364 ./mysql-bin.007365 ./mysql-bin.007366 ./mysql-bin.007367 ./mysql-bin.007368 23:27:31 UTC - mysqld got signal 6 ; This could be because you hit a bug. It is also possible that this binary or one of the libraries it was linked against is corrupt, improperly built, or misconfigured. This error can also be caused by malfunctioning hardware. We will try our best to scrape up some info that will hopefully help diagnose the problem, but since we have already crashed, something is definitely wrong and this may fail. key_buffer_size=16777216 read_buffer_size=3145728 max_used_connections=523 max_threads=800 thread_count=522 connection_count=522 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 9037821 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x0 Attempting backtrace. You can use the following information to find out where mysqld died. If you see no messages after this, something went terribly wrong... stack_bottom = 0 thread_stack 0x40000 The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains information that should help you find out what is causing the crash.
（4）原因定位后，解决办法就是将mysql-bin.index文件备份后，手动进行修复，随后启动实例成功
# ./mysql start Starting MySQL.... SUCCESS! Checking mysql connection: connection ok! # ps -ef | grep mysqld root 22955 1 0 13:30 pts/5 00:00:00 /bin/sh /usr/bin/mysqld_safe --datadir=/var/lib/mysql --pid-file=/var/lib/mysql/VM_58_10_centos.pid mysql 23733 22955 24 13:30 pts/5 00:00:05 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/lib/mysql/VM_58_10_centos.err --open-files-limit=20000 --pid-file=/var/lib/mysql/VM_58_10_centos.pid --socket=/var/lib/mysql/mysql.sock --port=3306 root 32075 14929 0 13:30 pts/5 00:00:00 grep mysqld
至此，问题得到解决，至于为什么错误日志内容会写入到mysql-bin.index，个人怀疑是宕机导致文件错乱(该宿主机上的其他虚拟机有出现文件系统损坏的情况)；最后，还是得强调一下，生产系统还是得重视起来，备份、高可用、容灾都是不可或缺的。