MySQL慢查询日志异常记录快查询，是否存在Bug？

首先可以明确：这种情况几乎不可能是MySQL的Bug，而是有几个容易被忽略的运行时因素，导致了手动测试和慢日志记录的耗时差异。咱们一步步拆解：

先理清楚核心矛盾 #

你的慢查询配置是：

slow-query-log = 1
slow-query-log-file = /var/lib/mysql/mysql-slow.log
long_query_time = 1

日志里记录的REPLACE INTO语句，手动执行仅需60ms左右，但慢日志显示耗时1.19秒，且固定间隔30分钟在夜间出现。

可能的原因分析 #

1. 夜间系统资源被抢占（最可能） #

你提到语句在夜间无用户活动时定时出现，间隔30分钟——这很可能是定时维护任务（比如数据库备份、表优化、日志归档、数据同步）在运行。这类任务会占用大量磁盘IO、CPU或内存资源：

• 比如mysqldump备份时会全表扫描，导致磁盘IO队列变长；
• 或者OPTIMIZE TABLE、ANALYZE TABLE这类操作会占用InnoDB的缓冲池资源。
  此时即使是简单的REPLACE语句，也会因为等待IO资源而大幅变慢，而你手动测试时是在资源空闲的时段，所以耗时差异巨大。

2. 外键关联的隐性开销 #

你的core_model_img表有外键关联到lib_img：

CONSTRAINT `core_model_img_ibfk_1` FOREIGN KEY (`id_img`) REFERENCES `lib_img` (`id`) ON DELETE CASCADE ON UPDATE CASCADE

执行REPLACE时，MySQL需要为每条记录检查id_img是否在lib_img中存在：

• 如果lib_img当时被其他事务锁定（比如备份时的读锁），外键检查会等待锁释放；
• 如果lib_img的id索引有碎片、统计信息过时，外键检查的效率会下降，进而拉长总耗时。

3. MySQL慢查询的计时逻辑 #

要注意：慢日志里的Query_time是从MySQL接收语句开始，到执行完成并准备好结果的总时间，包含了：

• 等待资源（IO、锁、缓冲池）的时间；
• 语句实际执行的时间。
  而你手动执行时，这些等待时间几乎为0，所以总耗时远低于日志记录。

排查建议 #

• 检查夜间系统负载：查看操作系统的历史监控数据（比如iostat、vmstat、sar的日志），确认对应时间段的IO利用率、CPU负载是否异常升高；
• 查看关联表状态：检查lib_img表在对应时段是否有锁等待或长事务，可以通过SHOW ENGINE INNODB STATUS（如果能回溯历史状态）或开启general log记录当时的所有操作；
• 模拟高负载测试：手动模拟磁盘IO占用（比如用dd if=/dev/zero of=/tmp/test bs=1G count=1），然后执行该REPLACE语句，看耗时是否会显著增加；
• 优化关联表：对lib_img表执行ANALYZE TABLE更新统计信息，或者OPTIMIZE TABLE整理索引碎片（注意锁表风险）。

内容的提问来源于stack exchange，提问作者kasimir