DM同步报错36001-panic error: table checkpoint less than global checkpoint

为提高效率,提问时请提供以下信息,问题描述清晰可优先响应。

对于 relay 处理单元,可通过以下步骤手动恢复:

  1. 在上游确认出错时对应的 binlog 文件的大小超出了 4GB。
  2. 停止 DM-worker。
    stop-task hollycas
  3. 将上游对应的 binlog 文件复制到 relay log 目录作为 relay log 文件。
    scp mysql-bin.005719 10.100.45.4:/data/dm/deploy/relay_log/89b73e86-22ad-11e9-81b6-70c7f218fe45.000001
    scp mysql-bin.005720 10.100.45.4:/data/dm/deploy/relay_log/89b73e86-22ad-11e9-81b6-70c7f218fe45.000001
    scp mysql-bin.005721 10.100.45.4:/data/dm/deploy/relay_log/89b73e86-22ad-11e9-81b6-70c7f218fe45.000001
    scp mysql-bin.005722 10.100.45.4:/data/dm/deploy/relay_log/89b73e86-22ad-11e9-81b6-70c7f218fe45.000001
    scp mysql-bin.005723 10.100.45.4:/data/dm/deploy/relay_log/89b73e86-22ad-11e9-81b6-70c7f218fe45.000001
    scp mysql-bin.005724 10.100.45.4:/data/dm/deploy/relay_log/89b73e86-22ad-11e9-81b6-70c7f218fe45.000001
  4. 更新 relay log 目录内对应的 relay.meta 文件以从下一个 binlog 开始拉取。如果 DM worker 已开启 enable_gtid ,那么在修改 relay.meta 文件时,同样需要修改下一个 binlog 对应的 GTID。如果未开启 enable_gtid 则无需修改 GTID。例如:报错时有 binlog-name = "mysql-bin.004451"binlog-pos = 2453 ,则将其分别更新为 binlog-name = "mysql-bin.004452"binlog-pos = 4 ,同时更新 binlog-gtid = "f0e914ef-54cf-11e7-813d-6c92bf2fa791:1-138218058"
    vi relay.meta
    binlog-name = “mysql-bin.005725”
    binlog-pos = 4
    binlog-gtid = “”
  5. 重启 DM-worker。
    ansible-playbook start.yml --tags=dm-worker

对于 binlog replication 处理单元,可通过以下步骤手动恢复:

  1. 在上游确认出错时对应的 binlog 文件的大小超出了 4GB。
  2. 通过 stop-task 停止同步任务。
    stop-task hollycas
  3. 将下游 dm_meta 数据库中 global checkpoint 与每个 table 的 checkpoint 中的 binlog_name 更新为出错的 binlog 文件,将 binlog_pos 更新为已同步过的一个合法的 position 值,比如 4。例如:出错任务名为 dm_test ,对应的 source-idreplica-1 ,出错时对应的 binlog 文件为 mysql-bin|000001.004451 ,则执行 UPDATE dm_test_syncer_checkpoint SET binlog_name='mysql-bin|000001.004451', binlog_pos = 4 WHERE id='replica-1';
    UPDATE hollycas_syncer_checkpoint SET binlog_name=‘mysql-bin|000001.005720’, binlog_pos = 4 WHERE id=‘mysql-replica-03’;
  4. 在同步任务配置中为 syncers 部分设置 safe-mode: true 以保证可重入执行。
    vi task_hollycas.yaml
    syncers:
    global:
    worker-count: 16
    batch: 100
    safe-mode: true
  5. 通过 start-task 启动同步任务。
    start-task /home/tidb/dm-ansible/conf/task_hollycas.yaml
  6. 通过 query-status 观察同步任务状态,当原造成出错的 relay log 文件同步完成后,即可还原 safe-mode 为原始值并重启同步任务。

操作完运行一段时间后仍然出现如下报错:

[code=36001:class=sync-unit:scope=internal:level=high] panic error: table checkpoint (mysql-bin|000001.005720, 474860631) less than global checkpoint (mysql-bin|000001.005720, 2567754926)(flushed (mysql-bin|000001.005720, 2567754926))
github.com/pingcap/dm/pkg/terror.(*Error).Generate
\t/home/jenkins/agent/workspace/build_dm_master/go/src/github.com/pingcap/dm/pkg/terror/terror.go:232
github.com/pingcap/dm/syncer.(*Syncer).Run.func5
\t/home/jenkins/agent/workspace/build_dm_master/go/src/github.com/pingcap/dm/syncer/syncer.go:1138
runtime.gopanic
\t/usr/local/go/src/runtime/panic.go:679
github.com/pingcap/dm/syncer.(*RemoteCheckPoint).saveTablePoint
\t/home/jenkins/agent/workspace/build_dm_master/go/src/github.com/pingcap/dm/syncer/checkpoint.go:283
github.com/pingcap/dm/syncer.(*RemoteCheckPoint).SaveTablePoint
\t/home/jenkins/agent/workspace/build_dm_master/go/src/github.com/pingcap/dm/syncer/checkpoint.go:277
github.com/pingcap/dm/syncer.(*Syncer).addJob
\t/home/jenkins/agent/workspace/build_dm_master/go/src/github.com/pingcap/dm/syncer/syncer.go:827
github.com/pingcap/dm/syncer.(*Syncer).commitJob
\t/home/jenkins/agent/workspace/build_dm_master/go/src/github.com/pingcap/dm/syncer/syncer.go:1984
github.com/pingcap/dm/syncer.(*Syncer).handleRowsEvent
\t/home/jenkins/agent/workspace/build_dm_master/go/src/github.com/pingcap/dm/syncer/syncer.go:1580
github.com/pingcap/dm/syncer.(*Syncer).Run
\t/home/jenkins/agent/workspace/build_dm_master/go/src/github.com/pingcap/dm/syncer/syncer.go:1334
github.com/pingcap/dm/syncer.(*Syncer).Process
\t/home/jenkins/agent/workspace/build_dm_master/go/src/github.com/pingcap/dm/syncer/syncer.go:599
github.com/pingcap/dm/syncer.(*Syncer).Resume
\t/home/jenkins/agent/workspace/build_dm_master/go/src/github.com/pingcap/dm/syncer/syncer.go:2361
runtime.goexit
\t/usr/local/go/src/runtime/asm_amd64.s:1357

若提问为性能优化、故障排查类问题,请下载脚本运行。终端输出的打印结果,请务必全选并复制粘贴上传。

请问点dm-worker 完整日志大吗?麻烦上传下,多谢

dm-worker.zip (456.7 KB) 日志从开始报错时截取,中间涉及具体插入记录做了一定模糊处理

在这个步骤中,你只更新了 global checkpoint 并没有更新每个 table 的 checkpoint

UPDATE hollycas_syncer_checkpoint SET binlog_name=‘mysql-bin|000001.005720’, binlog_pos = 4 WHERE id=‘mysql-replica-03’;

这个update语句也会更新每个table的checkpoint的,见下图:

麻烦把从启动任务到报错时的这一段时间的相关日志发一下吧

xxx.xxx.xxx.4-root_2020-07-03_15-17-31.log (1.3 MB)

这是我今天重跑的日志,binlog文件回放到4294965658这个位置,需要保存global checkpoint的时候又报错了。这个时候写入数据库的global checkpoint至少应该大于4294965658,但从报错日志来看,它提交的global checkpoint是474860631,远小于之前保存的global checkpoint:2567754926。还有,我观察发现,如果一直更新同一张表,global checkpoint是不会发生变化的。

我发现这还是一个概率问题,第3次从2567754926这个checkpoint重跑后,到了之前的那个点有报错,但最后自己过了。另外附上第三次重跑的完整日志,供分析:
xxx.xxx.xxx.4-root_2020-07-03_17-19-06.log (488.2 KB)

问题还在跟进分析,有信息会回复。

mysql-bin|000001.005720
麻烦确认下这个文件有没有超过 4G

-rw-r----- 1 tidb tidb 4769838584 Jul 2 01:22 mysql-bin.005720

https://docs.pingcap.com/zh/tidb-data-migration/stable/error-handling