c2cr2k2knb1c2cr2k2knb1.jpg 凌晨收到主从同步异常的报警,发现从库Slave_SQL_Running: No,SQL线程已经挂掉,第一时间切换从库域名到主库,保证数据抽取任务正常,接下来开始排查具体原因。 通过show slave status\G看到如下报错(库名和表名已修改):

Last_Error: Worker 4 failed executing transaction 'b32eb7b9-70d0-11ea-87d7-b496914fe6b8:38660024669' at master log mysql-bin.046359, end_log_pos 992049602; Could not execute Update_rows event on table xxx.xxx; Can't find record in 'xxx', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.046359, end_log_pos 992049602

很明显,从库在做update时候,发现有一条记录没有找到。接下来我们对主库和从库binlog进行解析。 根据报错中的GTID和position信息,对主从binlog进行解析,发现在20:03时候主库进行insert,主库和从库binlog都已经写入。 主库: 图片.png 从库: 图片.png

但是从库查不到对应id的这条记录。 主库: 图片.png 从库: 图片.png id为98825687的数据没有insert成功。

比较巧合的是,20:03这个时间点这个实例发生了重启,接下来我们去error log里边找一些信息。

2023-03-06 20:03:47 83960 [Note] Starting crash recovery...
2023-03-06 20:03:47 7f0e33785720  InnoDB: Starting recovery for XA transactions...
2023-03-06 20:03:47 7f0e33785720  InnoDB: Transaction 183293885769 in prepared state after recovery
2023-03-06 20:03:47 7f0e33785720  InnoDB: Transaction contains changes to 527745 rows
2023-03-06 20:03:47 7f0e33785720  InnoDB: 1 transactions in prepared state after recovery
2023-03-06 20:03:47 83960 [Note] Found 1 prepared transaction(s) in InnoDB
2023-03-06 20:03:47 83960 [Note] Crash recovery finished.

可以看到这个实例确实发生了重启。 那么问题来了,正常情况下,在双一设置前提下,数据库异常重启不可能丢失数据的。binlog写入正常,数据丢失,出现这种情况很大可能是redo log没有落盘成功,redo log没有落盘成功也就意味着innodb_flush_log_at_trx_commit设置不是1。 接下来我们查一下前一周的自动巡检报告: 图片.png 双一参数确实被修改过。 经过和其他同事核实,这个从库负载过高时候,为了解决延迟问题,曾经修改过innodb_flush_log_at_trx_commit和sync_binlog。 排查到此,同步异常原因已找到。由于innodb_flush_log_at_trx_commit设置为0,所以不确定丢失多少条数据,只能重新搭建从库了。