syncer 同步失败导致的PD 集群synchronize leader error

🪐 TiDB 技术问题 部署&运维管理
21 
[2020/04/17 01:11:52] [error] binlogsyncer.go:843 kill connection 15895729 error ERROR 1094 (HY000): Unknown thread id: 15895729
[2020/04/17 01:11:52] [info] binlogsyncer.go:849 kill last connection id 15895729
[2020/04/17 01:11:53] [info] binlogsyncer.go:776 rotate to (mysql-bin.006835, 4)
[2020/04/17 01:16:48] [error] binlogsyncer.go:656 io.CopyN failed. err EOF, copied 64, expected 197: connection was bad
[2020/04/17 01:16:49] [info] binlogsyncer.go:581 begin to re-sync from 22863285-e03a-11e9-a452-ac1f6b403494:1-8454425,704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025454,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422 (last read GTID=704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025455,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425)
[2020/04/17 01:16:49] [error] binlogsyncer.go:843 kill connection 15895799 error ERROR 1094 (HY000): Unknown thread id: 15895799
[2020/04/17 01:16:49] [info] binlogsyncer.go:849 kill last connection id 15895799
[2020/04/17 01:16:49] [info] binlogsyncer.go:776 rotate to (mysql-bin.006835, 4)

设置为1后，导入可以，但是也会一直在报这个错

22 
[2020/04/16 23:59:33] [error] binlogsyncer.go:656 io.CopyN failed. err EOF, copied 3280, expected 8208: connection was bad
[2020/04/16 23:59:34] [info] binlogsyncer.go:581 begin to re-sync from 704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891023525,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425 (last read GTID=22863285-e03a-11e9-a452-ac1f6b403494:1-8454425,704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891023526,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422)
[2020/04/16 23:59:34] [error] binlogsyncer.go:843 kill connection 15894677 error ERROR 1094 (HY000): Unknown thread id: 15894677
[2020/04/16 23:59:34] [info] binlogsyncer.go:849 kill last connection id 15894677
[2020/04/16 23:59:34] [info] binlogsyncer.go:776 rotate to (mysql-bin.006835, 4)
[2020/04/17 00:28:05] [error] binlogsyncer.go:656 io.CopyN failed. err EOF, copied 10, expected 64: connection was bad
[2020/04/17 00:28:06] [info] binlogsyncer.go:581 begin to re-sync from 704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891024643,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425 (last read GTID=22863285-e03a-11e9-a452-ac1f6b403494:1-8454425,704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891024644,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422)
[2020/04/17 00:28:06] [error] binlogsyncer.go:843 kill connection 15894837 error ERROR 1094 (HY000): Unknown thread id: 15894837
[2020/04/17 00:28:06] [info] binlogsyncer.go:849 kill last connection id 15894837
[2020/04/17 00:28:06] [info] binlogsyncer.go:776 rotate to (mysql-bin.006835, 4)
[2020/04/17 00:46:57] [error] binlogsyncer.go:656 io.CopyN failed. err EOF, copied 6835, expected 8208: connection was bad
[2020/04/17 00:46:58] [info] binlogsyncer.go:581 begin to re-sync from 1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425,704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025392 (last read GTID=704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025393,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425)
[2020/04/17 00:46:58] [error] binlogsyncer.go:843 kill connection 15895215 error ERROR 1094 (HY000): Unknown thread id: 15895215
[2020/04/17 00:46:58] [info] binlogsyncer.go:849 kill last connection id 15895215
[2020/04/17 00:46:59] [info] binlogsyncer.go:776 rotate to (mysql-bin.006835, 4)
[2020/04/17 00:54:13] [error] binlogsyncer.go:656 io.CopyN failed. err EOF, copied 5609, expected 8208: connection was bad
[2020/04/17 00:54:14] [info] binlogsyncer.go:581 begin to re-sync from 1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425,704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025409 (last read GTID=1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425,704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025410)
[2020/04/17 00:54:14] [error] binlogsyncer.go:843 kill connection 15895465 error ERROR 1094 (HY000): Unknown thread id: 15895465
[2020/04/17 00:54:14] [info] binlogsyncer.go:849 kill last connection id 15895465
[2020/04/17 00:54:14] [info] binlogsyncer.go:776 rotate to (mysql-bin.006835, 4)
[2020/04/17 01:01:38] [error] binlogsyncer.go:656 io.CopyN failed. err EOF, copied 10, expected 439: connection was bad
[2020/04/17 01:01:39] [info] binlogsyncer.go:581 begin to re-sync from 22863285-e03a-11e9-a452-ac1f6b403494:1-8454425,704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025422,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422 (last read GTID=1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425,704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025423)
[2020/04/17 01:01:39] [error] binlogsyncer.go:843 kill connection 15895564 error ERROR 1094 (HY000): Unknown thread id: 15895564
[2020/04/17 01:01:39] [info] binlogsyncer.go:849 kill last connection id 15895564
[2020/04/17 01:01:39] [info] binlogsyncer.go:776 rotate to (mysql-bin.006835, 4)
[2020/04/17 01:06:42] [error] binlogsyncer.go:656 io.CopyN failed. err EOF, copied 0, expected 279: connection was bad
[2020/04/17 01:06:43] [info] binlogsyncer.go:581 begin to re-sync from 704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025431,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425 (last read GTID=1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425,704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025432)
[2020/04/17 01:06:43] [error] binlogsyncer.go:843 kill connection 15895659 error ERROR 1094 (HY000): Unknown thread id: 15895659
[2020/04/17 01:06:43] [info] binlogsyncer.go:849 kill last connection id 15895659
[2020/04/17 01:06:44] [info] binlogsyncer.go:776 rotate to (mysql-bin.006835, 4)
[2020/04/17 01:11:51] [error] binlogsyncer.go:656 io.CopyN failed. err EOF, copied 81, expected 117: connection was bad
[2020/04/17 01:11:52] [info] binlogsyncer.go:581 begin to re-sync from 704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025439,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425 (last read GTID=704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025440,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425)
[2020/04/17 01:11:52] [error] binlogsyncer.go:843 kill connection 15895729 error ERROR 1094 (HY000): Unknown thread id: 15895729
[2020/04/17 01:11:52] [info] binlogsyncer.go:849 kill last connection id 15895729
[2020/04/17 01:11:53] [info] binlogsyncer.go:776 rotate to (mysql-bin.006835, 4)
[2020/04/17 01:16:48] [error] binlogsyncer.go:656 io.CopyN failed. err EOF, copied 64, expected 197: connection was bad
[2020/04/17 01:16:49] [info] binlogsyncer.go:581 begin to re-sync from 22863285-e03a-11e9-a452-ac1f6b403494:1-8454425,704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025454,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422 (last read GTID=704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891025455,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425)
[2020/04/17 01:16:49] [error] binlogsyncer.go:843 kill connection 15895799 error ERROR 1094 (HY000): Unknown thread id: 15895799
[2020/04/17 01:16:49] [info] binlogsyncer.go:849 kill last connection id 15895799
[2020/04/17 01:16:49] [info] binlogsyncer.go:776 rotate to (mysql-bin.006835, 4)

这个时间是UTC时间

23

看报错应该是 syncer 与上游的 MySQL 的链接有问题导致的，麻烦检查下上游 MySQL 的日志以及 syncer 的机器与 MySQL 之间的网络是否出现抖动。

24

网络没没问题，就是一直报这个binlog 文件的这个问题

25
  1. 麻烦重启 syncer 看下能否恢复。
  2. 如果没有恢复麻烦上传下 syncer 的日志文件以及上游 MySQL 的日志文件用于分析。
27

同步任务重新执行了，然后发现虚拟列会出问题导致任务失败，日志上传到附件上了，麻烦帮忙看一下，谢谢sync.log.txt (33.1 KB) tidb.log .txt (8.2 KB)
表结构和更新语句.txt (1.0 KB) t) (3.3 KB)
mysql日志.txt (3.3 KB)

28 
上游mysql 的日志传过来了，帮忙看一下，现在有两个问题，

一个是虚拟列更新不进来导致任务失败。

另一个是一直报错：

[2020/04/16 23:59:33] [error] binlogsyncer.go:656 io.CopyN failed. err EOF, copied 3280, expected 8208: connection was bad
[2020/04/16 23:59:34] [info] binlogsyncer.go:581 begin to re-sync from 704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891023525,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422,22863285-e03a-11e9-a452-ac1f6b403494:1-8454425 (last read GTID=22863285-e03a-11e9-a452-ac1f6b403494:1-8454425,704aa4cd-eaab-11e9-a391-ac1f6b41525a:1-891023526,1961de6e-db49-11e9-9eb7-ac1f6b41525a:1-2639441422)
[2020/04/16 23:59:34] [error] binlogsyncer.go:843 kill connection 15894677 error ERROR 1094 (HY000): Unknown thread id: 15894677
[2020/04/16 23:59:34] [info] binlogsyncer.go:849 kill last connection id 15894677
[2020/04/16 23:59:34] [info] binlogsyncer.go:776 rotate to (mysql-bin.006835, 4)
29

Syncer 不支持虚拟列的同步，另外 Syncer 已经被集成到 DM 中了，后续考虑不维护了。 建议这边使用 DM 进行同步试下，DM 支持虚拟列的同步。

30

那上面链接断开网络的问题呢

31

网络的问题，我们再看下，稍等

32

麻烦在上游使用 mysqlbinlog 工具解析一下 mysql-bin.006834 和 mysql-bin.006835 文件，看是否能正常解析。 排除一下 binlog 文件损坏的可能。