【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
扫一扫
2508
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
