MySQL|主从延迟问题排查(一)

一、案例分享

1.1 问题描述

大查询长时间执行无法释放DML读锁，后续同步主库的DDL操作获取DML写锁资源被阻塞等待，导致后续同步主库的操作堆积，主从延迟增长严重。从同步延迟的监控来看，延迟从17:11开始，17:51:59进行kill大查询操作，直到17:53建议业务方将大查询kill掉后才结束。

1.2 处理流程

1、当接收到只读实例的同步延迟告警后，登录到RDS的管理控制台查看实例当前会话执行情况，判断只读实例当前负载压力。从当前会话截图可以看到，会话并无明显堆积，但是有两个执行时间很久的大查询操作。

点击添加图片描述（最多60个字）编辑

2、17:11延迟开始，17:51 kill大查询，17:53主从延迟恢复。我们仍需要排查这个期间主实例和只读实例的运行情况，分析造成主从延迟的具体原因

3、对主实例的排查

1）查看延迟期间主库是否有一些批处理/大事务操作，主库业务业务请求上涨或者有批量的更新操作。对此，我们主要观察主实例的QPS/TPS监控、MySQL_COMDML和日志读写的监控指标。

点击添加图片描述（最多60个字）编辑

点击添加图片描述（最多60个字）编辑

点击添加图片描述（最多60个字）编辑

从以上截图中可以看到，主库TPS在主从延迟期间并没有明显的上涨，说明期间主库业务压力正常；主库MySQL_COMDML和日志读写在主从延迟期间也没有明显的上涨，说明期间主库也没有执行一些批量更新的大事务操作。

2）查看延迟期间主库是否有执行消耗较大的DDL操作。在RDS中若开启了审计日志，我们可以通过时间以及操作类型进行过滤排查

点击添加图片描述（最多60个字）编辑

点击添加图片描述（最多60个字）编辑

通过对审计日志的搜索，我们搜查到一条对视图定义进行alter的操作，该alter操作仅仅执行了2.32ms，其资源消耗本身并不大。

4、对只读实例的排查

1）查看延迟期间只读实例是否有较大负载压力，从只读实例延迟期间的会话执行情况以及资源消耗可以知道，延迟期间只读实例并无较大负载压力

2）从只读实例的QPS/TPS监控中可以看到，17:51kill掉大查询后只读实例的TPS异常上涨，17:53TPS恢复正常，延迟恢复。说明17:51～17:53期间只读实例在大量应用主库传输过来的binlog日志，恢复主从复制延迟。

点击添加图片描述（最多60个字）编辑

5、捕捉延迟期间会话中的异常现象，大查询长时间执行未结束，执行explain操作显示为MDL锁等待，结合我们在主库审计日志中搜索到的alter操作，我们可以推断造成主从延迟的原因可能是只读实例大查询阻塞了从主库传输过来的Alter操作，导致后续延迟一直上涨，并在我们kill掉大查询后恢复。

6、为了印证我们的猜想，我们通过审计日志把相关操作的时间线进行梳理

• 只读实例view_order_logistics_new相关的大查询执行了3602s还未执行完，一直持有表的DML读锁，不影响表的正常读写操作
• 17:10 主库执行了ALTER ALGORITHM=UNDEFINED DEFINER=super_sha_prd_db@% SQL SECURITY DEFINER VIEW view_order_logistics_new 的操作
• 只读实例view_order_logistics_new的大查询仍在执行中，此时主库执行alter操作传输到只读实例，alter操作需要的DML写锁与大查询持有的DML读锁冲突
• alter操作无法获取到DML写锁从而开始等待锁资源，从主控传输过来的binlog也被阻塞，主从延迟开始上涨
• 17:51:59 只读实例kill掉了view_order_logistics_new的大查询，只读实例TPS上涨，只读实例开始应用alter操作之后的所有binlog日志
• 17:53:08 只读实例TPS恢复，应用延迟期间的binlog完毕，主从复制恢复正常

更多技术信息请查看云掣官网https://www.dtstack.com/dtsmart/wy