AWS上MySQL记录锁超时未出现在慢查询日志？求助排查

问题背景 #

【2023.09.11 更新】我们在AWS托管的数据库（含只读副本，关联代码规模约20万行）偶尔出现难以追踪的死锁超时错误，错误提示为SAVEPOINT does not exist。推测是子过程引发的死锁超时，导致主过程丢失用于回滚的保存点。

已执行的排查动作：

• 开启慢查询日志（阈值设为0），未发现异常锁时长（最长仅0.000035秒）
• 无法通过data_locks或data_lock_waits表捕获随机发生的问题
• 后端系统复用数据库连接，当前观测到的最大等待是与只读副本同步的BIN_LOG
• 尝试每5秒监控sys.innodb_lock_waits的事件系统，但死锁发生时未捕获到锁等待，怀疑死锁是立即返回而非超时

使用的监控SQL代码：

SELECT
    JSON_ARRAYAGG(JSON_OBJECT
    (
      'waiting_trx_id',waiting_trx_id,
      'waiting_pid',waiting_pid,
      'waiting_query',waiting_query,
      'blocking_trx_id', blocking_trx_id,
      'blocking_pid', blocking_pid,
      'blocking_query', blocking_query
    ))
INTO
    json_results
FROM 
    sys.innodb_lock_waits;

排查建议 #

• 启用InnoDB死锁日志：在MySQL配置中设置innodb_print_all_deadlocks = ON，每次死锁发生时，详细的事务、锁类型、关联SQL等信息会写入错误日志，这比轮询sys.innodb_lock_waits更可靠，能避免因死锁瞬间触发导致的监控遗漏。
• 跟踪保存点生命周期：在应用代码中添加日志，记录每个保存点的创建、释放、回滚操作，重点覆盖子过程中的保存点操作。当出现SAVEPOINT does not exist错误时，通过日志回溯该连接上的保存点操作序列，确认是否存在保存点被提前释放、事务意外终止的情况。
• 检查连接复用的事务清理逻辑：由于后端复用连接，需确认连接归还池时是否正确清理了未完成的事务或残留保存点，比如执行ROLLBACK或RELEASE SAVEPOINT，避免后续请求复用连接时继承异常事务状态。
• 分析BIN_LOG同步对事务的影响：针对当前最大等待为BIN_LOG同步的情况，检查sync_binlog、innodb_flush_log_at_trx_commit等参数配置，确认是否因主从同步延迟导致事务提交阻塞，进而引发连锁的死锁或保存点问题。
• 用performance_schema跟踪锁事件：启用performance_schema的锁相关事件（如wait/lock/innodb/record_lock），设置合适采样率，通过performance_schema.events_waits_history_long表查看锁事件历史记录，即使死锁瞬间发生，也能捕获到锁操作细节。
• 模拟高并发场景复现问题：根据业务逻辑，模拟主过程与子过程交互的高并发场景，尝试复现SAVEPOINT does not exist错误。复现后通过调试工具跟踪事务和保存点的状态变化，定位根因。

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