【DBA手记】MySQL夯住案例 MHA环境relay-log中继日志导致服务器磁盘满

【DBA手记】MySQL夯住案例 MHA环境relay-log中继日志导致服务器磁盘满
author: superSong
Email: dba.supersong@163.com

背景及环境

今天一早系统组同事找我说，监控告警 有一个mysql服务器磁盘空间不足，空间都给mysql占了，找我清理一下。我登录服务器后，查看了一下相关系统和mha的部署环境，发现所剩空间不多，主要原因是中继日志积累太多，自动清理脚本"失效"，处理过程中眼看空间耗尽导致mysql实例夯住，在这种极端情况下进行了处理，记录处理解决过程。以下是环境配置：

• MHA高可用集群环境，龙蜥anolis8.5.0 ，mysql5.7.30
• zabbix监控告警 |钉钉告警提醒 mysql从节点磁盘空间不足
• 磁盘不足的分区为/data，data下只有mysql的文件，为安装目录和数据存放目录
• mysql的中继日志relay-log积累过多
• 中继日志设置为不自动清理relay_log_purge=0
• crontab有定时任务自动清理中继日志脚本purge_relay_log.sh
  实际会调过perl脚本/usr/bin/purge_relay_logs
• mysql的binlog二进制日志 过期自动清理设置为7天
• 磁盘空间紧张，逐步耗尽 mysql实例夯住

问题分析和排查思路

• 不能直接在linux下rm暴力删除mysql的binlog和relay日志文件
• 没有其它可以清理的垃圾文件，难以释放出一些空间
• binlog有手工清理命令，可以立即释放空间
• relay-log没有手工清理命令，只能依赖mha的脚本，但有时效性，不会立即触发删除动作 要隔一段时间才会清理
• 立即关停从库复制线程stop slave，避免空间持续增长
• stop slave 时夯住 ，要找出一个大文件mv先移走 以释放一些空间，让mysql有机会关停复制线程，解决夯住卡死。
• 移动哪个文件？临时释放点空间呢？给出操作窗口
• 找出一个mysql自带的不无紧要的测试文件mysqltest_embedded ：因为/data下只有mysql的文件，看不到能动的文件，再分析后，可以mv移走这个（本环境中） 在mysql的安装目录的bin目录中找出一个200M的文件/data/mysql/bin/mysqltest_embedded 这是个用来测试的文件并不重要 可以先mv走，回头问题解决了 再mv回来。

总结及建议

• 遇到mysql从库磁盘将近耗尽时，要首先立即关停从库的复制线程，以免空间持续增长
• 以我之前的经验，要在mysql的data里创建一个5G的临时文件xxx.tmp，以备不时之需，当空间耗尽时，可以删除这个临时文件，释放一些空间，留给DBA排查处理问题的操作窗口，不至于linux系统和mysql夯住卡死。
• crontab的定时任务可以跑2个清理中继日志的脚本，以两个不同时间来触发relay-log的删除清理操作 之前在其它mha环境就遇到过这个问题 用2个脚本来解决的
• 观察binlog 和relay-log每天的生成量，如果增长量过大，要提前对磁盘扩容 这里每天relay-log 生成量约8G，相关binlog也在8G左右，一天总增量就有16G了
• binlog二进制日志过期自动清理时间 可以缩短一些，这里已为7天缩短为5天

处理过程

清理relay-log中继日志

进入到data目录下 占用最多的就是binlog日志和relay-log日志。
crontab -l 找出自动清理relay log的脚本

[root@localrsourcemysql02 bin]# crontab -l ... 5 2 * * * /usr/local/bin/scripts/purge_relay_log.sh 

然后手工执行这个脚本 来清理中继日志，但它不会立即生效，需要在从库mysql线程适当的时机才会触发清理删除relay-log，如下

[root@localrsourcemysql02 ~]# df -TH 文件系统            类型      容量  已用  可用 已用% 挂载点 devtmpfs            devtmpfs  2.0G     0  2.0G    0% /dev tmpfs               tmpfs     2.0G     0  2.0G    0% /dev/shm tmpfs               tmpfs     2.0G   18M  2.0G    1% /run tmpfs               tmpfs     2.0G     0  2.0G    0% /sys/fs/cgroup /dev/mapper/ao-root xfs       113G  113G  310M  100% /  ## 空间即将耗尽 /dev/sda1           xfs       1.1G  339M  726M   32% /boot /dev/mapper/ao-home xfs        22G  193M   22G    1% /home tmpfs               tmpfs     391M   21k  391M    1% /run/user/42 [root@localrsourcemysql02 ~]# /usr/local/bin/scripts/purge_relay_log.sh #清理relay日志命令不会立即生效 [root@localrsourcemysql02 ~]#  [root@localrsourcemysql02 ~]# df -TH 文件系统            类型      容量  已用  可用 已用% 挂载点 devtmpfs            devtmpfs  2.0G     0  2.0G    0% /dev tmpfs               tmpfs     2.0G     0  2.0G    0% /dev/shm tmpfs               tmpfs     2.0G   18M  2.0G    1% /run tmpfs               tmpfs     2.0G     0  2.0G    0% /sys/fs/cgroup /dev/mapper/ao-root xfs       113G  113G  234M  100% / # 空间并不会立即释放 /dev/sda1           xfs       1.1G  339M  726M   32% /boot /dev/mapper/ao-home xfs        22G  193M   22G    1% /home tmpfs               tmpfs     391M   21k  391M    1% /run/user/42 

mha环境中实际清理relay-log中继日志的的perl程序脚本

[root@localrsourcemysql02 bin]# cat /usr/local/bin/scripts/purge_relay_log.sh #!/bin/bash source /etc/profile   user=root passwd="XXXXXX" port=3306 log_dir='/data/masterha/log'            # 存储脚本执行日志的路径 work_dir='/data/masterha/data'          # 存放relay bin log 硬链接的地方。 purge='/usr/bin/purge_relay_logs'       # purge 命令  if [ ! -d $log_dir ]                    # 如果没有变量Log_dir 指定的路径，则创建一个。 then    mkdir $log_dir -p fi  $purge --user=$user --password=$passwd --disable_relay_log_purge --port=$port --workdir=$work_dir >> $log_dir/purge_relay_logs.log 2>&1  ## 实际清理relay-log的perl程序脚本 可以关注里面的调用方法："" Executing SET GLOBAL relay_log_purge=1; FLUSH LOGS; sleeping a few seconds so that SQL thread can delete older relay log files (if it keeps up); SET GLOBAL relay_log_purge=0; .."; " [root@localrsourcemysql02 bin]# cat /usr/bin/purge_relay_logs #!/usr/bin/env perl  #  Copyright (C) 2011 DeNA Co.,Ltd. # ... #  51 Franklin Street, Fifth Floor, Boston, MA  02110-1301  USA  use strict; use warnings FATAL => 'all';  use Carp qw(croak); use English qw(-no_match_vars); use Getopt::Long; ...... use MHA::NodeConst; use DBI;  GetOptions(   \my %opt, qw/     help ...     host=s ... ... my $_binlog_manager; my $_relay_log_info_path   = $opt{relay_log_info}; my @relay_log_files_handle = ();  if ( $opt{help} ) {   pod2usage(0); }  if ( $opt{version} ) {   print "purge_relay_logs version $MHA::NodeConst::VERSION.\n";   exit 0; }  exit &main();  sub open_relay_logs() {   my $relay_dir = $_binlog_manager->{dir};   my @files =     MHA::BinlogManager::g ...        " Getting advisory lock failed. Maybe failover script is running?\n";     }     save_error_log($dbh);     print " Executing SET GLOBAL relay_log_purge=1; FLUSH LOGS; sleeping a few seconds so that SQL thread can delete older relay log files (if it keeps up); SET GLOBAL relay_log_purge=0; ..";     MHA::SlaveUtil::purge_relay_logs($dbh);     print " ok.\n";      MHA::SlaveUtil::release_failover_advisory_lock($dbh);     if ( $opt{use_hard_link} ) {       remove_hardlinked_relay_logs(); ... 

磁盘不足分区情况
mysql的程序安装目录和数据目录 都在/data下

[root@localrsourcemysql02 /]# ll /data 总用量 12 -rw-r--r--  1 root  root  10420 4月   7 15:08 data.7 drwxr-xr-x  3 root  root     17 4月  24 02:05 masterha drwxr-xr-x 10 mysql mysql   158 4月  19 17:09 mysql drwxr-xr-x  2 mysql mysql    22 4月  19 17:10 slowlog  [root@localrsourcemysql02 /]# cd /data/mysql/ [root@localrsourcemysql02 mysql]# ll 总用量 300 drwxr-xr-x  2 mysql mysql   4096 5月   6 10:07 bin drwxr-x---  9 mysql mysql   8192 5月   6 17:21 data  #### 数据目录 占用了空间 drwxr-xr-x  2 mysql mysql     55 4月  19 17:09 docs -rw-r--r--  1 mysql mysql      0 4月  19 17:09 error.log drwxr-xr-x  3 mysql mysql   4096 4月  19 17:09 include drwxr-xr-x  5 mysql mysql    230 4月  19 17:09 lib -rw-r--r--  1 mysql mysql 275235 3月  24 2020 LICENSE drwxr-xr-x  4 mysql mysql     30 4月  19 17:09 man -rw-r--r--  1 mysql mysql    587 3月  24 2020 README drwxr-xr-x 28 mysql mysql   4096 4月  19 17:09 share drwxr-xr-x  2 mysql mysql     90 4月  19 17:09 support-files  

从库运行状态情况

root@db 09:54:  [(none)]> show slave status\G *************************** 1. row ***************************                Slave_IO_State: Waiting for master to send event                   Master_Host: XXXXXX                   Master_User: myslave                   Master_Port: 3306                 Connect_Retry: 60               Master_Log_File: mybinlog.000048           Read_Master_Log_Pos: 372826468                Relay_Log_File: relay-log-bin.000141                 Relay_Log_Pos: 236370533         Relay_Master_Log_File: mybinlog.000047              Slave_IO_Running: Yes             Slave_SQL_Running: Yes               Replicate_Do_DB:            Replicate_Ignore_DB:             Replicate_Do_Table:         Replicate_Ignore_Table:        Replicate_Wild_Do_Table:    Replicate_Wild_Ignore_Table:                     Last_Errno: 0                    Last_Error:                   Skip_Counter: 0           Exec_Master_Log_Pos: 236370322               Relay_Log_Space: 50839026647               Until_Condition: None                Until_Log_File:                  Until_Log_Pos: 0            Master_SSL_Allowed: No            Master_SSL_CA_File:             Master_SSL_CA_Path:                Master_SSL_Cert:              Master_SSL_Cipher:                 Master_SSL_Key:          Seconds_Behind_Master: 11959 Master_SSL_Verify_Server_Cert: No                 Last_IO_Errno: 0                 Last_IO_Error:                 Last_SQL_Errno: 0                Last_SQL_Error:    Replicate_Ignore_Server_Ids:               Master_Server_Id: 1                   Master_UUID: b1fda908-fe18-11ee-afef-005056a86fa6              Master_Info_File: /data/mysql/data/master.info                     SQL_Delay: 0           SQL_Remaining_Delay: NULL       Slave_SQL_Running_State: Reading event from the relay log            Master_Retry_Count: 86400                   Master_Bind:        Last_IO_Error_Timestamp:       Last_SQL_Error_Timestamp:                 Master_SSL_Crl:             Master_SSL_Crlpath:             Retrieved_Gtid_Set: b1fda908-fe18-11ee-afef-005056a86fa6:1-40300328             Executed_Gtid_Set: b1fda908-fe18-11ee-afef-005056a86fa6:1-39343990                 Auto_Position: 1          Replicate_Rewrite_DB:                   Channel_Name:             Master_TLS_Version:  1 row in set (0.00 sec)  

binlog 日志和relay-log日志情况 2者占用最大

# binlog [root@localrsourcemysql02 data]# ll -h mybinlog.* -rw-r----- 1 mysql mysql 1.1G 5月   1 05:20 mybinlog.000005 -rw-r----- 1 mysql mysql 1.1G 5月   1 08:20 mybinlog.000006 -rw-r----- 1 mysql mysql 1.1G 5月   1 11:20 mybinlog.000007 -rw-r----- 1 mysql mysql 1.1G 5月   1 14:20 mybinlog.000008 -rw-r----- 1 mysql mysql 1.1G 5月   1 17:20 mybinlog.000009 -rw-r----- 1 mysql mysql 1.1G 5月   1 20:20 mybinlog.000010 -rw-r----- 1 mysql mysql 1.1G 5月   1 23:20 mybinlog.000011 -rw-r----- 1 mysql mysql 1.1G 5月   2 02:21 mybinlog.000012 ... ... -rw-r----- 1 mysql mysql 1.1G 5月   6 02:21 mybinlog.000044 -rw-r----- 1 mysql mysql 1.1G 5月   6 09:40 mybinlog.000045 -rw-r----- 1 mysql mysql 1.1G 5月   6 10:21 mybinlog.000046 -rw-r----- 1 mysql mysql  81M 5月   6 10:24 mybinlog.000047 -rw-r----- 1 mysql mysql 1.4K 5月   6 10:21 mybinlog.index  # relay-log [root@localrsourcemysql02 data]# ll -h relay-log*|more -rw-r----- 1 mysql mysql  291 4月  30 23:10 relay-log-bin.000010 -rw-r----- 1 mysql mysql 1.1G 5月   1 02:07 relay-log-bin.000011 -rw-r----- 1 mysql mysql  842 5月   1 02:07 relay-log-bin.000012 -rw-r----- 1 mysql mysql  291 5月   1 02:07 relay-log-bin.000013 -rw-r----- 1 mysql mysql 1.1G 5月   1 05:04 relay-log-bin.000014 -rw-r----- 1 mysql mysql 6.2K 5月   1 05:04 relay-log-bin.000015 -rw-r----- 1 mysql mysql  291 5月   1 05:04 relay-log-bin.000016 -rw-r----- 1 mysql mysql 1.1G 5月   1 08:01 relay-log-bin.000017 ... ... -rw-r----- 1 mysql mysql 185M 5月   6 09:24 relay-log-bin.000145 -rw-r----- 1 mysql mysql 4.9M 5月   6 09:25 relay-log-bin.000146 -rw-r----- 1 mysql mysql 351K 5月   6 09:25 relay-log-bin.000147 -rw-r----- 1 mysql mysql 139M 5月   6 09:49 relay-log-bin.000148 -rw-r----- 1 mysql mysql   85 5月   6 09:49 relay-log.info [root@localrsourcemysql02 data]# du -shc relay-log-bin* ... 8.0K	relay-log-bin.000132 4.0K	relay-log-bin.000133 1.1G	relay-log-bin.000134 ... 770M	relay-log-bin.000141 204M	relay-log-bin.000142 51M	relay-log-bin.000143 4.0K	relay-log-bin.000144 185M	relay-log-bin.000145 4.9M	relay-log-bin.000146 352K	relay-log-bin.000147 113M	relay-log-bin.000148 4.0K	relay-log.info 45G	总用量 

手工清理binlog二进制日志 并关停从库

我想通过删除一些binlog日志先临时释放空间，但为时已晚，空间已耗尽，因为从库的中继日志不断增长，那赶快停止从库的复制线程，如下 删除报错，mysql实例也夯住了，这时linux系统在敲打一些命令时，也会同样报错，没有空间来执行了。

[root@localrsourcemysql02 bin]# df -Th 文件系统            类型      容量  已用  可用 已用% 挂载点 ...... /dev/mapper/ao-root xfs       105G  105G   20K  100% /   #空间已耗尽了  ...... root@db 09:54:  [(none)]> purge master logs to 'mybinlog.000010'; ERROR 29 (HY000): File '/data/mysql/data/mybinlog.~rec~' not found (Errcode: 28 - No space left on device) root@db 10:00:  [(none)]> purge master logs to 'mybinlog.000002'; # 删除binlog报错 没空间了 ERROR 29 (HY000): File '/data/mysql/data/mybinlog.~rec~' not found (Errcode: 28 - No space left on device) root@db 10:00:  [(none)]>  root@db 10:00:  [(none)]> stop slave; # 实例夯住 卡主了 没反应 

处理mysql实例夯住

• mv移动走一个无关紧要的文件，临时释放一点微弱空间， 这时磁盘释放出200M的空间，能让 stop slave执行完成了 如下

[root@localrsourcemysql02 bin]# mv /data/mysql/bin/mysqltest_embedded /home root@db 10:00:  [(none)]> stop slave; ## 之前夯住的命令 已执行完了 中继日志不再增长   Query OK, 0 rows affected (2 min 36.72 sec) 

先手工清理少量binlog日志 再一次批量清理 逐步释放

上面，已关停了从库复制，中继日志不再增长，在这个还剩下不多空间的空当下，先手工清理一个binlog日志吧 一个就1G，然后4个，然后30个
同时，要注意在mha环境下 要先查看其它从库复制情况和binlog生成情况，复制环境最近的binlog还是要保留的，以备切换之用。

再多清理一些，空间会立即释放很多个G

root@db 10:04:  [(none)]>  purge master logs to 'mybinlog.000002'; Query OK, 0 rows affected (0.00 sec)  root@db 10:04:  [(none)]>  purge master logs to 'mybinlog.000005'; Query OK, 0 rows affected (0.01 sec)  root@db 10:04:  [(none)]> purge master logs to 'mybinlog.000035'; Query OK, 0 rows affected (0.04 sec) 

等待relay-log清理脚本择机生效后 清理完毕

经过，上面对binlog日志的清理后，系统已经释放了30G的空间了，足够等待relay-log脚本的生效触发删除中继日志的动作
几个小时后，再观察relay-log情况，已自动清理完毕

[root@localrsourcemysql02 data]# ll 总用量 22388872 -rw-r----- 1 mysql mysql         56 4月  19 17:10 auto.cnf -rw------- 1 mysql mysql       1676 4月  19 17:10 ca-key.pem -rw-r--r-- 1 mysql mysql       1112 4月  19 17:10 ca.pem -rw-r--r-- 1 mysql mysql       1112 4月  19 17:10 client-cert.pem -rw------- 1 mysql mysql       1680 4月  19 17:10 client-key.pem -rw-r----- 1 mysql mysql          7 4月  23 15:34 db.pid -rw-r----- 1 mysql mysql      76880 5月   6 14:52 error.log -rw-r----- 1 mysql mysql        329 4月  23 14:45 ib_buffer_pool -rw-r----- 1 mysql mysql 1073741824 5月   6 17:02 ibdata1 -rw-r----- 1 mysql mysql 2147483648 5月   6 17:25 ib_logfile0 -rw-r----- 1 mysql mysql 2147483648 5月   6 10:09 ib_logfile1 -rw-r----- 1 mysql mysql   12582912 4月  23 15:34 ibtmp1 -rw-r----- 1 mysql mysql       9508 5月   6 17:24 innodb_status.180711 -rw-r----- 1 mysql mysql        148 5月   6 17:25 master.info -rw-r----- 1 mysql mysql 1073742093 5月   4 23:21 mybinlog.000035 -rw-r----- 1 mysql mysql 1073743271 5月   5 02:21 mybinlog.000036 -rw-r----- 1 mysql mysql 1073743093 5月   5 05:21 mybinlog.000037 -rw-r----- 1 mysql mysql 1073744200 5月   5 08:21 mybinlog.000038 -rw-r----- 1 mysql mysql 1073742152 5月   5 11:21 mybinlog.000039 -rw-r----- 1 mysql mysql 1073743774 5月   5 14:21 mybinlog.000040 -rw-r----- 1 mysql mysql 1073746089 5月   5 17:21 mybinlog.000041 -rw-r----- 1 mysql mysql 1073745109 5月   5 20:21 mybinlog.000042 -rw-r----- 1 mysql mysql 1073742856 5月   5 23:21 mybinlog.000043 -rw-r----- 1 mysql mysql 1073745098 5月   6 02:21 mybinlog.000044 -rw-r----- 1 mysql mysql 1073745214 5月   6 09:40 mybinlog.000045 -rw-r----- 1 mysql mysql 1073742390 5月   6 10:21 mybinlog.000046 -rw-r----- 1 mysql mysql 1073742053 5月   6 11:21 mybinlog.000047 -rw-r----- 1 mysql mysql 1073742064 5月   6 14:21 mybinlog.000048 -rw-r----- 1 mysql mysql 1073743303 5月   6 17:21 mybinlog.000049 -rw-r----- 1 mysql mysql   22739595 5月   6 17:25 mybinlog.000050 -rw-r----- 1 mysql mysql        528 5月   6 17:21 mybinlog.index drwxr-x--- 2 mysql mysql       4096 4月  19 17:10 mysql srwxrwxrwx 1 mysql mysql          0 4月  23 15:34 mysql.sock -rw------- 1 mysql mysql          7 4月  23 15:34 mysql.sock.lock ... drwxr-x--- 2 mysql mysql       8192 4月  19 17:10 performance_schema -rw------- 1 mysql mysql       1680 4月  19 17:10 private_key.pem -rw-r--r-- 1 mysql mysql        452 4月  19 17:10 public_key.pem ...  ## 如下 只剩下4个relay-log了 之前的都已自动清理完毕！！ -rw-r----- 1 mysql mysql    5494669 5月   6 13:51 relay-log-bin.000160 -rw-r----- 1 mysql mysql  334294304 5月   6 14:46 relay-log-bin.000161 -rw-r----- 1 mysql mysql        291 5月   6 14:46 relay-log-bin.000162 -rw-r----- 1 mysql mysql  961967353 5月   6 17:25 relay-log-bin.000163 -rw-r----- 1 mysql mysql         85 5月   6 17:25 relay-log.info