MySQL频繁停库的问题分析(r12笔记第33天）

最近也抽空帮一些网友解决一些问题，有些是Oracle，有些是MySQL，有时候虽然忙忙乎乎，但是解决问题之后还是很有成就感的。

今天来说一个蛮有意思的问题，听起来还很诡异。是一个网友向我咨询，看看能不能给出一些建议。当我看到日志，隐隐感觉这是一个bug的感觉。

详细的日志如下：

2017-04-13 16:25:29 40180 [Note] Server socket created on IP: '::'. 2017-04-13 16:25:29 40180 [Warning] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information. 2017-04-13 16:25:29 40180 [Note] Slave I/O thread: connected to master 'xx@xxxx:6606',replication started in log 'mysql-bin.000105' at position 732153962 2017-04-13 16:25:29 40180 [Warning] Slave SQL: If a crash happens this configuration does not guarantee that the relay log info will be consistent, Error_code: 0 2017-04-13 16:25:29 40180 [Note] Event Scheduler: Loaded 0 events 2017-04-13 16:25:29 40180 [Note] /mysql_base/bin/mysqld: ready for connections. Version: '5.6.20-log' socket: '/tmp/mysql.sock' port: 6607 Source distribution 2017-04-13 16:25:29 40180 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000105' at position 634901970, relay log '/mysql_log/relay-log.000339' position: 25153965 2017-04-13 16:26:01 40180 [Note] /mysql_base/bin/mysqld: Normal shutdown 2017-04-13 16:26:01 40180 [Note] Giving 2 client threads a chance to die gracefully 2017-04-13 16:26:01 40180 [Note] Event Scheduler: Purging the queue. 0 events 2017-04-13 16:26:01 40180 [Note] Shutting down slave threads 2017-04-13 16:26:01 40180 [Note] Slave SQL thread exiting, replication stopped in log 'mysql-bin.000105' at position 637977115 2017-04-13 16:26:01 40180 [Note] Slave I/O thread killed while reading event 2017-04-13 16:26:01 40180 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.000105', position 732432767 2017-04-13 16:26:01 40180 [Note] Forcefully disconnecting 0 remaining clients 2017-04-13 16:26:01 40180 [Note] Binlog end 2017-04-13 16:26:01 40180 [Note] Shutting down plugin 'partition' 2017-04-13 16:26:01 40180 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES' 2017-04-13 16:26:01 40180 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES' 2017-04-13 16:26:01 40180 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'

因为mysql服务进程启动没有一会就自动停止了。而且仔细查看这个日志，会发现里面没有任何Error的字样，有几个warning的信息，但是觉得不应该是问题的根本原因。

通过上面的日志，我们会得到一些基本的信息：

1. 这是一个从库，可以从relay的信息看出
2. 停库的时候看起来是一个顺序的过程，不像是掉电宕机，异常crash的特点
3. 标红的那句： Giving 2 client threads a chance to die gracefu

我觉得这句日志是这个问题查找的一个重点方向，怎么两个thread就可以优雅的die了。

所以我准备从几个角度来查看。

1. 是否是系统层面的异常
2. 是否是内核参数的设置问题
3. 是否是数据库参数的设置
4. bug 第一个问题，我查看了文件系统是ext4,内存是64G,剩余内存还很多，系统的配置和负载都不高。 第二个问题，我查看了内核参数的设置，主要的shmmax这些参数设置都没有问题，我看了里面还指定了很多细节的网络设置，我们纠结了下是否是swap会有影响，尽管目前swap使用率几乎为0，还是带着试试看的心态调试了下，设置swapniess=1，结果测试问题依旧。 第三个问题是否是数据库参数的设置，这个我看buffer_pool_size是40G，其它的参数设置也蛮合理，也没有生疏的参数设置，所以这个地方也无从下手，不过还是试了是把buffer_pool_size从40G设置为4G，结果问题依旧。 第4个问题，查找bug,还真找到一个，https://bugs.mysql.com/bug.php?id=71104 但是这个问题很难解释的通，因为根据这位网友的反馈，这台服务器早上还好好的，下午就是这样了，所以说是bug也有些牵强。 带着疑问，我也尝试了启动加上skip-slave-start都无济于事。

我觉得得换个思路，还有哪些盲点没有考虑到。

我突然看到日志目录下有一个文件，这个文件一看就不是MySQL系统生成的，很像是手工指定生成的文件。查看里面的信息，发现是检测MySQL运行状态的检查。由此我想是不是系统层面设置了什么任务之类的。

使用crontab -l查看，果然看到两个，第2个就是这个检查服务状态的任务脚本，而第一个是一个check_mysql.sh这样的脚本

内容如下：

#!/bin/bash datetime=`date +"%F %H:%M:%S"` /mysql_base/bin/mysql -uxx -pxx -e "select version();" &>/dev/null if [ $? -eq 0 ] then #date +"%F %H:%M:%S" echo "$datetime mysql is running" >>/mysql_log/check_mysql.log else pkill mysql; sleep 5; /mysql_base/bin/mysqld_safe --user=mysql >/dev/null 2>&1 & echo "$datetime ERROR:**************mysql restarted********************" >>/mysql_log/check_mysql.log fi大家细细看看这个脚本有没有问题，基本的思路就是连接到MySQL，查看一下版本，如果得到的结果为0，否则就会杀掉MySQL,然后等待5秒，重启服务。

这里的关键就是第一部分的内容了，如果连接失败，后面的步骤肯定会出问题，也就是会直接杀掉MySQL.

和这位网友确认，他上午是修改了一个数据，这个用户的密码应该修改了，导致连接异常出了这个意料之外的问题。

最快的解决方式就是先注释掉这个cron,然后调整下密码，更关键的是这个逻辑要进行持续的改进。

这个问题的分析也给我好好上了一课，很多复杂的问题，原因其实很简单，但是查找问题的过程不简单。