一次MySQL主从同步因大事务延迟导致订单数据不一致的排查实录

问题背景

周一早上 9 点 17 分,我刚端着咖啡走到工位,客服总监的电话就打了过来:”有客户投诉,昨天凌晨下的订单到现在还显示’待付款’,但钱已经扣了。再这样下去要上 12315 了。”

我们做的是 B2B 商城系统,订单链路是标准的”主库写入 → 从库读取”分离架构。业务侧前端订单查询全部走从库,结算、支付回调走主库。按理说,正常的几条订单写入,从库延迟顶多几百毫秒。

但这次不一样——运维群里同事反馈,从库 Seconds_Behind_Master 指标在凌晨 2 点之后就开始飘红,目前还在 40 分钟以上。也就是说,用户今天看到的订单状态,其实是凌晨 2 点之前的老数据

影响范围:所有 C 端订单查询接口(订单列表、订单详情、物流状态)。涉及用户:约 1.2 万。紧急程度:P1(业务受损,尚未扩散到资损,但已接到投诉)。

故障现象

登录 Zabbix 监控大屏,几个关键指标同时告警:

1. 从库延迟(Seconds_Behind_Master

从凌晨 2:00 开始延迟曲线从 0.5s 拉升,到 9:00 仍是 2400s(40 分钟),曲线呈”阶梯式上升”:

1
2
3
4
5
6
7
02:00  delay=0.8s
02:10 delay=45s
02:30 delay=320s
03:00 delay=980s
05:00 delay=2100s
07:00 delay=2350s
09:00 delay=2412s

2. 主库写入流量

Com_update 计数显示凌晨 1:55 - 2:35 之间有 2.3 亿行 UPDATE 操作集中在主库执行,binlog 产生量约 8.6 GB。

3. 错误日志

从库的 mysqld.log 里有大量 Multi-statement transaction required more than 'max_binlog_cache_size' bytes of storage 警告——这说明从库尝试一次性应用一个超大事务时,binlog cache 不够用。

4. 业务报错

部分订单详情接口偶发返回 ERROR 1213 (40001): Deadlock found when trying to get lock,但这是次要现象,主要问题还是延迟。

排查过程

第一步:确认从库状态

登录从库查看复制状态:

1
2
3
4
5
6
7
8
9
mysql> SHOW SLAVE STATUS\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Log_File: mysql-bin.000128
Read_Master_Log_Pos: 523847212
Relay_Log_File: relay-bin.000089
Relay_Log_Pos: 480123441
Seconds_Behind_Master: 2412
Slave_SQL_Running_State: Reading event from the relay log

Seconds_Behind_Master 还在涨,但 Slave_SQL_Running_State 显示”Reading event from the relay log”——意味着 SQL 线程并没有卡死,是在持续追。这是典型的”大事务回放慢”症状。

第二步:定位主库上的大事务

登录主库,用 mysqlbinlog 工具扫 binlog 找最长的几个事务:

1
2
3
4
5
mysqlbinlog --no-defaults -v -v \
--base64-output=DECODE-ROWS \
--start-datetime="2026-06-22 01:55:00" \
--stop-datetime="2026-06-22 02:35:00" \
mysql-bin.000127 mysql-bin.000128 | head -200

很快就看到了一段超长事务——一个跑批任务(订单超时自动关闭)在 1:57 开始,到 2:28 结束,持续 31 分钟,涉及 800 万行订单的 UPDATE:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
# at 12345678
#260622 1:57:14 server id 1 end_log_pos 12345890 CRC32 0xabcdef Query thread_id=123456
SET TIMESTAMP=1761119834
BEGIN
...
# at 12345900
#260622 1:57:14 server id 1 end_log_pos 12346100 Table_map: `order`.`t_order` mapped to number 123
#260622 1:57:14 server id 1 end_log_pos 12346200 Update_rows: table id 123 flags: STMT_END_F
### UPDATE `order`.`t_order`
### WHERE
### @1=1000001
### @2='PENDING_PAY'
### @3='2026-06-21 10:23:11'
### ...
### SET
### @1=1000001
### @2='CLOSED_TIMEOUT'
### @3='2026-06-22 01:57:14'
... (此处省略约 800 万行类似的 UPDATE)

主库这一个事务生成的 binlog 就有 6.2 GB

第三步:分析大事务为何慢

MySQL 主从复制的原理是:从库 SQL 线程拿到主库的 binlog event 后,单线程回放(默认配置下,MySQL 5.7 没有开启 MTS 多线程回放)。一个事务从主库传到从库,从库必须按顺序完整回放完才能进入下一个事务。

主库上,800 万行 UPDATE 因为聚簇索引和锁的原因花 31 分钟;从库上同样要 800 万行 UPDATE,但因为:

  1. 从库硬件配置略低(IOPS 只有主库的 60%);
  2. sync_binlog=1innodb_flush_log_at_trx_commit=1 的双 1 配置让每行都强制刷盘;
  3. SQL 线程是单线程,无法并行回放。

所以从库回放速度大约是主库的 1/3 —— 自然就形成了 40 分钟的延迟。

第四步:分析这个事务的合理性

继续看那段 binlog,发现这个”订单超时关闭”任务的 SQL 模式是:

1
2
3
4
5
-- 伪代码
BEGIN;
UPDATE t_order SET status='CLOSED_TIMEOUT', close_time=NOW()
WHERE status='PENDING_PAY' AND create_time < DATE_SUB(NOW(), INTERVAL 30 MINUTE);
COMMIT;

单条 SQL 一次更新 800 万行。问题就出在这里——开发同学为了图省事,用一条大 SQL 完成全表批量更新。

解决方案

紧急止血

1. 业务切流:把订单查询从从库切回主库(虽然主库压力大,但此刻一致性更重要):

1
2
3
4
5
6
# 在 Nginx upstream 中临时调整
upstream order_query {
# 临时注释从库
# server 10.0.10.22:3306;
server 10.0.10.21:3306 max_fails=2 fail_timeout=10s;
}

2. 强制让从库跳过这个大事务(不推荐为常规操作,但紧急情况下可以):

1
2
3
4
5
-- 评估一致性影响后,决定让从库直接跳过该超大事务
-- 因为这个事务是"超时关闭",本身就是幂等操作,重新跑批会再处理一次
mysql> STOP SLAVE;
mysql> SET GLOBAL sql_slave_skip_counter = 1;
mysql> START SLAVE;

SET GLOBAL sql_slave_skip_counter = 1 只能跳一个 event。我这里大事务跨多个文件,最终选择的是:让从库慢慢追回(保守但安全)。

3. 临时调大从库相关参数,提升回放速度:

1
2
3
4
5
# my.cnf
innodb_flush_log_at_trx_commit = 2
sync_binlog = 0
slave_parallel_workers = 8
slave_parallel_type = LOGICAL_CLOCK

重启从库后,回放速度从 5000 行/秒提升到 18000 行/秒,2 小时内追平延迟。

长期修复

1. 业务侧:大事务拆小

推动开发同学把”订单超时关闭”改为分批 + 循环

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
// 优化后的跑批代码
int batchSize = 1000;
int affected;
do {
// 每次只更新 1000 行
affected = jdbcTemplate.update(
"UPDATE t_order " +
"SET status='CLOSED_TIMEOUT', close_time=NOW() " +
"WHERE status='PENDING_PAY' " +
"AND create_time < ? " +
"LIMIT " + batchSize,
expireTime
);
// 每批之间 sleep 100ms,给从库喘息
Thread.sleep(100);
} while (affected > 0);

这样每个事务只更新 1000 行,单事务 binlog 不到 1 MB,从库回放几乎无感知。

2. MySQL 配置:开启多线程复制

从库永久开启 MTS:

1
2
3
slave_parallel_workers = 16
slave_parallel_type = LOGICAL_CLOCK
slave_preserve_commit_order = ON

3. 监控告警

添加 Seconds_Behind_Master > 60s 的告警,避免延迟 40 分钟才发现。

4. 架构优化

考虑订单读多写少、且对一致性要求高的特点,引入 ProxySQL 做读写分离,并支持强制走主库的功能(针对订单详情这种对一致性敏感的场景)。

根因分析

这个问题的根本原因是业务开发同学没有”主从复制延迟”的意识,把单实例 MySQL 时代的”一条大 SQL 搞定一切”的习惯带到了主从架构下。

具体三个直接原因:

  1. 单条 UPDATE 影响 800 万行 —— 远超单事务合理大小(经验值:单事务 1 万行以内);
  2. 从库默认单线程回放 —— MySQL 5.7 默认 slave_parallel_workers=0,大事务没有并行能力;
  3. 未配置主从延迟告警 —— 凌晨 2:00 延迟就开始累积,但 7 小时后才被业务反馈发现。

预防措施

1. 编码规范:禁止大事务

在 Code Review Checklist 中加入:单事务 DML 行数 ≤ 5000,binlog 大小 ≤ 10 MB。可以加 SQL 拦截器:

1
2
3
4
-- 生产环境拒绝大事务的拦截逻辑(伪代码)
-- 当 row_examined > 10000 时直接 kill
SET @max_rows = 10000;
-- 通过 Performance Schema 或审计插件实现

2. 主从延迟全链路监控

Seconds_Behind_Master 只是粗略值。更准确的方案是使用 pt-heartbeat 工具在主库每秒写一个时间戳,从库对比时间差得到精确延迟:

1
2
3
4
# 主库
pt-heartbeat -D test --update -h 10.0.10.21
# 从库
pt-heartbeat -D test --monitor -h 10.0.10.22

3. 跑批任务错峰执行

把”订单超时关闭”这种大跑批放在业务低峰(比如凌晨 3:30 - 5:00),并且增加单批 sleep,避免集中打主库。

4. 关键业务强制走主库

对一致性要求极高的接口(订单详情、支付结果、账户余额),在 ProxySQL 规则里强制 mysql-default_session_target_host=master,不走从库。

5. 定期演练

每季度做一次”主库宕机,从库强制提升”演练,验证从库是否能快速接管;同时也验证大事务场景下从库的恢复能力。

总结

这次故障的教训可以总结成三句话:

第一,MySQL 主从架构下,”单条大 SQL”是定时炸弹。开发同学需要从单实例思维切换到”主从延迟敏感”思维,养成”分批 + 循环”的习惯。

**第二,监控不能只看”服务是否在线”**。Slave_IO_Running=YesSlave_SQL_Running=Yes 都是 Yes,但延迟可能已经几小时。Seconds_Behind_Master 告警必须配置,且阈值要合理。

第三,对一致性敏感的业务,不要无脑走读写分离。订单详情、支付结果这类场景,宁可让主库扛一部分读流量,也要保证数据一致性。读写分离的规则要细化到表/接口级别,不能一刀切。

最后,事后我和开发 leader 约法三章:所有大表 DML 必须经过 DBA Review,所有新上线的定时任务必须压测确认 binlog 体积。规则定下来了,但更重要的是执行。这次故障的客户投诉虽然已经处理完毕,但给了我们一个深刻的提醒:主从架构不是”装上就完事”的银弹,它是需要业务、运维、DBA 一起维护的契约