几年前MySQL数据库出现突然的从库延迟故障和CPU爆高时,如何排查具体原因,可能说已在腾讯云的MySQL库里开启了SQL全审计,记录了全部执行的SQL,再通过下面的方法就可以很容易找到原因:
1,实用QPS和TPS高的高效分析方法
但如果没有开通SQL全审计,如何去找原因。当然说可以看慢SQL日志,但这时的慢SQL日志记录的SQL不全,就不好判断分析出具体是哪些SQL引起的。
如何在非开通SQL全审计的MySQL数据库(因实例不可能都开SQL审计,自建MySQL开还不方便存储查看等),有什么办法? 有更多信息来分析出原因!
当时接手公司数据库运维时,研发已经写了一个Shell,每10秒保存一下当前的:show full processlist ,保留当前执行SQL情况到文件中,后来发现这些还不够,后来加上长事务和表锁,可能更好,Shell脚本如下:
1,CPU爆高:
监控shell:
每10秒执行一次保留当前查询的监控到txt文本中
#!/bin/bash
cd $(dirname $0)
echo $log_file
sql=" show full processlist"
ip=172.16.0.15
start_time=$(date +%s)
let "check_time=start_time+60";
now=$start_time
while [ $now -lt $check_time ];
do
log_dir=/root/monitor/$(date +"%Y-%m-%d")/$(date +"%H")/$(date +"%M")
mkdir -p $log_dir
log_file=$log_dir/$(date +"%Y-%m-%d-%H-%M-%S")
echo $sql | mysql -udba_op -ppwd -h$ip mysql > $log_file.master
mysql -udba_op -ppwd -h$ip mysql </root/shell/long_tran.sql > $log_file.master_tran
echo "next "
sleep 10;
now=$(date +%s)
done
long_tran.sql下的SQL脚本:
select timestampdiff(SECOND,trx_started,now()) diffsecond,b.host,b.user,concat('kill ',b.ID,' ;') killsql,b.db,
IFNULL(b.INFO,a.trx_query) runsql
from information_schema.innodb_trx a left join
information_schema.PROCESSLIST b on a.trx_mysql_thread_id=b.ID
where timestampdiff(SECOND,trx_started,now()) >=1
order by 1 desc limit 20;
show open tables where in_use >=1;
Crontab运行调度和清理10天前的日志
*/1 * * * * sh /root/shell/sg_monitor_master.sh > /dev/null 2>&1
1 1 * * * find /root/monitor/ -name "20*" -type d -mtime +10 -exec rm -rf {} \; > /dev/null 2>&1
这样每隔10秒就有下面2个文件:
可以结合慢SQL和这2个文件,监控出出问题时当前的数据库的SQL执行情况,找出问题。
2,从库突然延迟
因为当时公司是做在线教育的,但从库延迟几十秒,对他们影响很大,同时领导就会收到报警短信,钉钉群里叫,就要查是什么原因导致的从库延迟,一种方法是查看上面的监控处理的SQL获取信息,另外当时还有解析出binlog信息,查出具体的SQL,看是什么SQL导致的,具体做法:
1,从腾讯云的下载出问题时间的binlog日志本地的机器
2,根据出问题的时间范围,解析binlog日志,如下:
mysqlbinlog --no-defaults -vv --base64-output=decode-rows --start-datetime='2020-08-18 11:20:00' --stop-datetime='2020-08-18 12:03:00' mysql-bin.000203 >log.sql
3,解析出binlog日志后,用notepad++打开文件,仔细查看运行的SQL日志,分析出SQL,这就是细心活。如果查到具体表,可以用上grep过滤,如下:
1, grep user_0 -A 10 -B 10 >/data/61.txt
2, mysqlbinlog --start-datetime="2019-07-08 9:32:00" --stop-datetime="2019-07-09 11:20:00" -v --base64-output=DECODE-ROWS binlog.000001 | grep -A4 'INSERT' > test.sql
4,结合上面信息,发出SQL,让研发同学去修改业务。
3,记录原始SQL
当时在公司,公司技术VP说要记录执行的原始SQL,这样大数据读取binlog,把这个原始SQL保留起来,日后审计时就可以通过原始SQL发现谁乱改线上业务数据,同时要把研发人员每次业务要改数据的SQL邮件抄送给他。查询发现mysql还有这样的参数: binlog_rows_query_log_events参数
默认配置下,ROW格式二进制日志只记录数据发生的变化,并不会记录什么语句导致数据发生变化,而出于审计或者处理bug的需求,需要了解导致数据变化的SQL语句,MYSQL提供了binlog_rows_query_log_events来控制是否在二进制中存放"原始SQL"。开启后如下:
后来在主库上开启该参数,大数据就记录主库的SQL执行情况,要监控谁有乱修改更新线上业务数据,但后面一直没用这个数据去查,反而大数据说记录的执行SQL数据量太大,不得不缩短数据保留日期。