MySQL无开通SQL全审计下的故障分析方法
几年前MySQL数据库出现突然的从库延迟故障和CPU爆高时，如何排查具体原因，可能说已在腾讯云的MySQL库里开启了SQL全审计，记录了全部执行的SQL，再通过下面的方法就可以很容易找到原因：1，实用QPS和TPS高的高效分析方法
但如果没有开通SQL全审计，如何去找原因。当然说可以看慢SQL日志，如果是只简单的CPU冲高，慢SQL日志查就可以，但如遇到复杂一点情况，看慢SQL的信息就不够，就不好判断分析出具体是什么原因，哪些SQL引起的。
如何在非开通SQL全审计的MySQL数据库（因实例不可能都开SQL审计，自建MySQL开还不方便存储查看等），有什么办法? 有更多信息来分析出原因！
当时接手公司数据库运维时，研发已经写了一个Shell，每10秒保存一下当前的：show full processlist ，保留当前执行SQL情况到文件中，后来发现这些还不够，后来加上长事务和表锁，可能更好，Shell脚本如下：
1，CPU爆高：
监控shell：
每10秒执行一次保留当前查询的监控到txt文本中
#!/bin/bashcd $(dirname $0)echo $log_filesql=" show full processlist"ip=172.16.0.15start_time=$(date +%s)let "check_time=start_time+60";now=$start_timewhile [ $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) runsqlfrom information_schema.innodb_trx a left joininformation_schema.PROCESSLIST b on a.trx_mysql_thread_id=b.IDwhere timestampdiff(SECOND,trx_started,now()) >=1order 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，让研发同学去修改业务。
注意binlog：
1，主库开启gtid后，pos位置点，每个binlog日志文件开始的pos都是从1开始计算
2，binlog的replace，会转成对应的idelete和insert，或者update等
3，binlog： 执行的SQL都是带有库名 --base64-output参数用来控制binlog部分是否显示出来的，指定为decode-rows表示不显示binglog部分
加-v与加-vv的区别
加-vv
### UPDATE `online`.`ol_teacher_inversion_rate_list` ### WHERE ### @1=595135615 /* INT meta=0 nullable=0 is_null=0 */
加-v
### UPDATE `online`.`ol_teacher_inversion_rate_list` ### WHERE ### @1=595135615
少一个v，少后面的字段类型信息
加--base64-output=DECODE-ROWS与不加的区别：
加：--base64-output=DECODE-ROWS
不显示原始binlog的二进制信息 ：如 BINLOG ' JV7gWg8QJwAAdwAA.......'
4，binlog批量删除 如：DELETE FROM `online`.`ol_task_agents_fixed` WHERE `record_date` = '2021-04-21'
在binlog会一条一条记录，删除5000条，会有5000条delete语句，而且是同一个事务。
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数据量太大，不得不缩短数据保留日期。
页:
[1]