MySQL8.0.11向TiDBv3.0.4同步问题：item not ack

[liuhuanHappyStudy]

我再使用Gravity测试MySQL8.0.11向TiDBv3.0.4数据同步。使用Gravity版本为：0.9.61.
同步过程中输出如下日志：（日志中并没有输出警告，错误）

{"level":"warning","msg":"[sliding_window] item not ack after 95.908530 seconds. core.Msg{ mysqlstream-502587 dml insert map[id:2611651] }","time":"2019-11-23T10:26:54+08:00"}
{"level":"warning","msg":"[sliding_window] item not ack after 96.908549 seconds. core.Msg{ mysqlstream-502587 dml insert map[id:2611651] }","time":"2019-11-23T10:26:55+08:00"}
{"level":"warning","msg":"[sliding_window] item not ack after 97.908528 seconds. core.Msg{ mysqlstream-502587 dml insert map[id:2611651] }","time":"2019-11-23T10:26:56+08:00"}
{"level":"warning","msg":"[sliding_window] item not ack after 98.908548 seconds. core.Msg{ mysqlstream-502587 dml insert map[id:2611651] }","time":"2019-11-23T10:26:57+08:00"}
{"level":"warning","msg":"[sliding_window] item not ack after 99.908528 seconds. core.Msg{ mysqlstream-502587 dml insert map[id:2611651] }","time":"2019-11-23T10:26:58+08:00"}
{"level":"warning","msg":"[sliding_window] item not ack after 100.908550 seconds. core.Msg{ mysqlstream-502587 dml insert map[id:2611651] }","time":"2019-11-23T10:26:59+08:00"}
{"level":"warning","msg":"[sliding_window] item not ack after 101.908552 seconds. core.Msg{ mysqlstream-502587 dml insert map[id:2611651] }","time":"2019-11-23T10:27:00+08:00"}
{"level":"warning","msg":"[sliding_window] item not ack after 102.908539 seconds. core.Msg{ mysqlstream-502587 dml insert map[id:2611651] }","time":"2019-11-23T10:27:01+08:00"}
{"level":"warning","msg":"[sliding_window] item not ack after 103.908541 seconds. core.Msg{ mysqlstream-502587 dml insert map[id:2611651] }","time":"2019-11-23T10:27:02+08:00"}
{"level":"warning","msg":"[sliding_window] item not ack after 104.908537 seconds. core.Msg{ mysqlstream-502587 dml insert map[id:2611651] }","time":"2019-11-23T10:27:03+08:00"}
{"level":"warning","msg":"[sliding_window] item not ack after 105.908548 seconds. core.Msg{ mysqlstream-502587 dml insert map[id:2611651] }","time":"2019-11-23T10:27:04+08:00"}
{"level":"warning","msg":"[sliding_window] item not ack after 106.908536 seconds. core.Msg{ mysqlstream-502587 dml insert map[id:2611651] }","time":"2019-11-23T10:27:05+08:00"}
{"level":"warning","msg":"[sliding_window] item not ack after 107.908533 seconds. core.Msg{ mysqlstream-502587 dml insert map[id:2611651] }","time":"2019-11-23T10:27:06+08:00"}

item not ack after后边的时间一直增长，同时没有数据同步到TiDB，MySQL中gravity_positions表记录的同步位置也不再跟新。

gravity的同步配置文件如下：
[root@tidb02 gravity-0.9.61]# cat toml_lh/mysql2tidb_product.toml

name = "mysql2tidb_test"

internal-db-name = "_gravity"

[input]
type = "mysql"
mode = "stream"
[input.config.source]
host = "123.123.123.123"
username = "user"
password = "password"
port = 3306

[[input.config.table-configs]]
schema = "db_test"
table = "*"

[input.config.start-position]
binlog-gtid = "123131-123131-12131-123-123131313213:1-5903819"

[[filters]]
type = "reject"
[filters.config]
match-schema = "db_test"
match-table = "BATCH_*"

#[[filters]]
#type = "reject"
#[filters.config]
#match-schema = "db_test"
#match-table = "batch_*"

[output]
type = "mysql"
[output.config.target]
host = "127.0.0.1"
username = "user"
password = "password"
port = 4000

[output.config]
enable-ddl = true

[[output.config.routes]]
match-schema = "db_test"
match-table = ""
target-schema = "db_test"
target-table = ""

#match-table = ""和target-table = ""等于"星号"，提交问题后，没显示出来。
多次出现这种情况，
情况一：有时候只是同步延迟比较高，item not ack after后边的时间也会增长，但是数据还在慢慢同步，同步过批处理产生的大量数据后，所有指标趋于正常。
情况二：同步进程还在运行，但是数据不再同步，item not ack after后边的时间一直增长，MySQL中gravity_positions表记录的同步位置也不再跟新。

请多指教，非常感谢！

[Ryan-Git]

• 贴一下 grafana 监控
• tidb show process list 看看在做什么，有没有长时间执行的任务
• debug/pprof/goroutine 看下堆栈
• mysql binlog 里看看这个消息前后都在做什么

[liuhuanHappyStudy]

@Ryan-Git 非常感谢你的回复！

1. grafana 监控
   出现问题处的监控图片如下
   https://github.com/liuhuanHappyStudy/hello-world/tree/master/image
2. tidb show process list 看看在做什么，有没有长时间执行的任务
   目前tidb中 SHOW FULL PROCESSLIST;没有执行的任务。目前同步状态是：gravity进程还在，数据不同步，数据库_gravity中gravity_positions表中记录的同步位置，一直保持不变，不再跟新。

3.mysql binlog 里看看这个消息前后都在做什么
同步停在位置："binlog-gtid":"86d43294-987d-22e8-12af-00763e098714:1-5903819"
当前位置的事务为：向表checking_tf中插入大概10000行的数据，一条一条的插入。binlog信息如下：
事务中大概有10000条这样的sql
191123 10:25:13 server id 1 end_log_pos 273352770 CRC32 0x8a3d7947 Write_rows: table id 511 flags: STMT_END_F
INSERT INTO db_test.checking_tf
SET
@1=2611320 /* INT meta=0 nullable=0 is_null=0 /
@2=1574549054 / TIMESTAMP(0) meta=0 nullable=0 is_null=0 /
@3=1574420062 / TIMESTAMP(0) meta=0 nullable=1 is_null=0 /
@4='86371isen90joi1574419054' / VARSTRING(1020) meta=1020 nullable=1 is_null=0 /
@5='1119112218373440068' / VARSTRING(1020) meta=1020 nullable=1 is_null=0 /
@6='' / VARSTRING(1020) meta=1020 nullable=1 is_null=0 /
@7='6000087559' / VARSTRING(1020) meta=1020 nullable=1 is_null=0 /
@8='消费' / VARSTRING(1020) meta=1020 nullable=1 is_null=0 /
@9=100 / LONGINT meta=0 nullable=1 is_null=0 /
@10='收入' / VARSTRING(1020) meta=1020 nullable=1 is_null=0 /
@11=12751 / LONGINT meta=0 nullable=1 is_null=0 /
@12=1574475914 / TIMESTAMP(0) meta=0 nullable=1 is_null=0 /
@13='2019-11-22 00:00:00' / DATETIME(0) meta=0 nullable=1 is_null=0 /
@14='6000011904' / VARSTRING(200) meta=200 nullable=1 is_null=0 /
@15='WECHAT_MP' / VARSTRING(1020) meta=1020 nullable=1 is_null=0 /
@16=22 / DOUBLE meta=8 nullable=1 is_null=0 /
@17=21 / INT meta=0 nullable=1 is_null=0 /
@18=49 / DOUBLE meta=8 nullable=1 is_null=0 /
@19=38 / INT meta=0 nullable=1 is_null=0 */

"binlog-gtid":"86d43294-987d-22e8-12af-00763e098714:1-5903819"这个位置的下一条事务，还是向这个表插入10000行左右的数据，虽然，gravity_positions记录的位置停在了:"binlog-gtid":"86d43294-987d-22e8-12af-00763e098714:1-5903819"，，但是下一个事务的部分数据，已同步一部分。
该位置的上一个事务是，向订单表中插入一行数据。

4.debug/pprof/goroutine 看下堆栈
这个目前不了解，往后会尝试，调试一下。

感谢您提供的解决问题的思路，以上提供的信息，不知够不够您分析，还望等您有空时，麻烦您看一下。

[Ryan-Git]

先并发开高点试一下。

[output.config.target]
max-open = 200
max-idle = 200

[scheduler]
type = "batch-table-scheduler"
[scheduler.config]
nr-worker = 200

debug/pprof/goroutine 是我想看下卡在哪里了

[liuhuanHappyStudy]

好的，非常感谢！

[Ryan-Git]

最近修复了一个可能相关的问题，可以更新一下看看 #238

[Ryan-Git]

先关了，还有问题再开吧。