记录一下那天晚上的排查过程。CentOS 7.9 上跑 MariaDB 10.5,long_query_time 设成 1,慢日志里一条 update 记录着 Query_time 8.2 Lock_time 8.1 Rows_examined 1,拿同样的条件手工 explain 只扫一行,可业务那边每隔几分钟就卡一下。

刚开始盯着「慢日志的统计口径把 Lock_time 计进总耗时,只看 Query_time 会误判成语句写得烂」,折腾了半个多小时,排掉了。

真正麻烦的地方在于,几个原因的现象几乎一样。行锁被一个没提交的长事务持有,语句本身很快,排队等锁的时间全被算进了 Query_time。另一种情况是可重复读隔离级别下范围更新会加间隙锁,两条不相干的 update 互相把对方堵住。

不容易想到的是,刷盘和组提交的等待同样计入执行时间,磁盘慢的时候语句看着也慢。

动手时先按总耗时把慢语句排个序

mysqldumpslow -s t -t 10 /var/log/mysql/slow.log

随后看当前有哪些事务开着没提交

mysql -e 'select trx_mysql_thread_id,trx_started,timestampdiff(second,trx_started,now()) as sec from information_schema.innodb_trx order by sec desc limit 5'

然后找出谁在等谁持有的锁

mysql -e 'select * from information_schema.innodb_lock_waits\G'

结束那个开得太久的事务再看恢复情况

mysql -e 'kill 41233'

别只看报错消失,验证要多做一步。慢日志里 Lock_time 超过一秒的条目归零,innodb_trx 中不再有存活超过五秒的事务,接口的 p99 回到两百毫秒以内。

先分清是等锁还是真慢,直接给语句加索引往往白改;长事务多半来自导数据脚本没提交,找到源头比调参有用。这类问题最好一次改到位,反复小改反而容易把原因搅混。

作者 9823189