MySQL 一则慢日志监控误报的问题分析与解决

之前因为各种原因，有些报警没有引起重视，最近放假马上排除了一些潜在的人为原因，发现数据库的慢日志报警有些奇怪，主要表现是慢日志报警不属实，收到报警的即时通信提醒后，隔一会去数据库里面去排查，发现慢日志的性能似乎没有那么差（我设置的一个阈值是60）。

排查过几次代码层面的逻辑，没有发现明显的问题，几次下来，问题依旧，这可激发了修正的念头，决定认真看看到底是什么原因。

后端使用的是基于ORM的模式，数据都存储在模型MySQL_slowlog_sql_history对应的表中。

代码层面是类似如下的逻辑：

MySQL_slowlog_sql_history.objects.filter(create_time__gt='2020-01-29 11:00:00',Query_time_pct_95__gt=60)

传入的时间是动态的，然后阈值取60秒，按照预期如果报警出来就肯定是有问题的。

为了进一步验证，我把阈值时间修改为600，竟然还是报出错误，执行7~8秒的慢查询照样会报出来。

我使用debug的方式得到了ORM解析得到的SQL:

SELECT...`mysql_slowlog_sql_history`.`create_time`, `mysql_slowlog_sql_history`.`memo` FROM `mysql_slowlog_sql_history` WHERE (`mysql_slowlog_sql_history`.`create_time` > '2020-01-29 11:00:00' AND `mysql_slowlog_sql_history`.`Query_time_pct_95` > '600') LIMIT 21; args=(u'2020-01-29 11:00:00', u'600')

我自己在客户端执行，确实是好好的，只过滤出了600秒以上的结果。

select ip_addr,db_port from mysql_slowlog_sql_history where create_time>'2020-01-29 00:00:00' and Query_time_pct_95 > 600;

我看着模型的字段定义开始有所悟，然后快速验证了一番。

为了方便说明，我创建了一个测试表test_dummy.

create table test_dummy(id int primary key auto_increment,Query_time_pct_95 varchar(100));

insert into test_dummy(Query_time_pct_95 ) values('8.83736'),('7.70056'),('5.09871'),('4.32582');+----+-------------------+| id | Query_time_pct_95 |+----+-------------------+| 1 | 8.83736      || 4 | 7.70056      || 7 | 5.09871      || 10 | 4.32582      |+----+-------------------+4 rows in set (0.00 sec)

mysql> select *from test_dummy where Query_time_pct_95>600;Empty set (0.00 sec)

所以这个问题的快速修复方式就是在数据库层面修改数据表的类型为float,而在精度损失方面这块的影响是可以忽略不计的。

再次验证，这个问题就没有再次出现。

更多相关文章

随机推荐