alibaba / canal

阿里巴巴 MySQL binlog 增量订阅&消费组件
Apache License 2.0
28.33k stars 7.58k forks source link

canal deploy重启后,binlog position的位置不对,位置提前 #5177

Open czxin788 opened 2 months ago

czxin788 commented 2 months ago

我用canal 1.1.7 deploy监控mysql 8.0,用canal 1.1.7 adapter做为客户端消费服务端deploy。

当我重启deploy后,发现adapter日志一直报连不上deploy,于是我再将adapter重启后,发现adapter的日志报重复消费binlog里面的events了,也就是先前执行过的sql,又执行了一遍,这岂不是表明adapter的binlog位置不准了,并且日志位置提前了,请问这是为什么,应该怎么处理。

adapter的日志如下:

2024-06-18 09:55:21.805 [Thread-4] ERROR c.a.otter.canal.adapter.launcher.loader.AdapterProcessor - Outer adapter sync failed!  Error sync and rollback, execute times: 65857
2024-06-18 09:55:22.807 [pool-8-thread-1] INFO  c.a.o.canal.client.adapter.logger.LoggerAdapterExample - DML: {"data":null,"database":"czx","destination":"example","es":1718608891000,"groupId":"g1","isDdl":true,"old":null,"pkNames":null,"sql":"create table t3 like t2","table":"t3","ts":1718675722807,"type":"CREATE"}
2024-06-18 09:55:22.807 [pool-8-thread-1] INFO  c.a.o.canal.client.adapter.logger.LoggerAdapterExample - DML: {"data":null,"database":"","destination":"example","es":1718608934000,"groupId":"g1","isDdl":false,"old":null,"pkNames":[],"sql":"insert into t3 values (1,'aa',44,'shanghai')","table":"t3","ts":1718675722807,"type":"QUERY"}
2024-06-18 09:55:22.807 [pool-8-thread-1] INFO  c.a.o.canal.client.adapter.logger.LoggerAdapterExample - DML: {"data":[{"id":1,"name":"aa","age":44,"address":"shanghai"}],"database":"czx","destination":"example","es":1718608934000,"groupId":"g1","isDdl":false,"old":null,"pkNames":["id"],"sql":"","table":"t3","ts":1718675722807,"type":"INSERT"}
2024-06-18 09:55:22.807 [pool-8-thread-1] INFO  c.a.o.canal.client.adapter.logger.LoggerAdapterExample - DML: {"data":null,"database":"","destination":"example","es":1718608942000,"groupId":"g1","isDdl":false,"old":null,"pkNames":[],"sql":"insert into t3 values (2,'aa',44,'shanghai')","table":"t3","ts":1718675722807,"type":"QUERY"}
2024-06-18 09:55:22.807 [pool-8-thread-1] INFO  c.a.o.canal.client.adapter.logger.LoggerAdapterExample - DML: {"data":[{"id":2,"name":"aa","age":44,"address":"shanghai"}],"database":"czx","destination":"example","es":1718608942000,"groupId":"g1","isDdl":false,"old":null,"pkNames":["id"],"sql":"","table":"t3","ts":1718675722807,"type":"INSERT"}
2024-06-18 09:55:22.807 [pool-8-thread-1] INFO  c.a.o.canal.client.adapter.logger.LoggerAdapterExample - DML: {"data":null,"database":"","destination":"example","es":1718608970000,"groupId":"g1","isDdl":false,"old":null,"pkNames":[],"sql":"delete from t3 where id=1","table":"t3","ts":1718675722807,"type":"QUERY"}
2024-06-18 09:55:22.807 [pool-8-thread-1] INFO  c.a.o.canal.client.adapter.logger.LoggerAdapterExample - DML: {"data":null,"database":"","destination":"example","es":1718609206000,"groupId":"g1","isDdl":false,"old":null,"pkNames":[],"sql":"insert into t3 values (3,'aa',44,'shanghai')","table":"t3","ts":1718675722807,"type":"QUERY"}
2024-06-18 09:55:22.807 [pool-8-thread-1] INFO  c.a.o.canal.client.adapter.logger.LoggerAdapterExample - DML: {"data":[{"id":3,"name":"aa","age":44,"address":"shanghai"}],"database":"czx","destination":"example","es":1718609206000,"groupId":"g1","isDdl":false,"old":null,"pkNames":["id"],"sql":"","table":"t3","ts":1718675722807,"type":"INSERT"}
2024-06-18 09:55:22.807 [pool-8-thread-1] INFO  c.a.o.canal.client.adapter.logger.LoggerAdapterExample - DML: {"data":null,"database":"","destination":"example","es":1718609498000,"groupId":"g1","isDdl":false,"old":null,"pkNames":[],"sql":"insert into t3 values (4,'aa',44,'shanghai')","table":"t3","ts":1718675722807,"type":"QUERY"}
2024-06-18 09:55:22.807 [pool-8-thread-1] INFO  c.a.o.canal.client.adapter.logger.LoggerAdapterExample - DML: {"data":[{"id":4,"name":"aa","age":44,"address":"shanghai"}],"database":"czx","destination":"example","es":1718609498000,"groupId":"g1","isDdl":false,"old":null,"pkNames":["id"],"sql":"","table":"t3","ts":1718675722807,"type":"INSERT"}
2024-06-18 09:55:22.807 [pool-8-thread-1] INFO  c.a.o.canal.client.adapter.logger.LoggerAdapterExample - DML: {"data":null,"database":"","destination":"example","es":1718609807000,"groupId":"g1","isDdl":false,"old":null,"pkNames":[],"sql":"insert into t3 values (5,'aa',44,'shanghai')","table":"t3","ts":1718675722807,"type":"QUERY"}
2024-06-18 09:55:22.807 [pool-8-thread-1] INFO  c.a.o.canal.client.adapter.logger.LoggerAdapterExample - DML: {"data":[{"id":5,"name":"aa","age":44,"address":"shanghai"}],"database":"czx","destination":"example","es":1718609807000,"groupId":"g1","isDdl":false,"old":null,"pkNames":["id"],"sql":"","table":"t3","ts":1718675722807,"type":"INSERT"}
2024-06-18 09:55:22.807 [pool-8-thread-1] DEBUG c.a.o.c.c.adapter.rdb.service.RdbMirrorDbSyncService - DDL: {"data":null,"database":"czx","destination":"example","es":1718608891000,"groupId":"g1","isDdl":true,"old":null,"pkNames":null,"sql":"create table t3 like t2","table":"t3","ts":1718675722807,"type":"CREATE"}
2024-06-18 09:55:22.808 [pool-8-thread-1] ERROR c.a.otter.canal.adapter.launcher.loader.AdapterProcessor - java.lang.RuntimeException: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Table 't3' already exists
java.lang.RuntimeException: java.lang.RuntimeException: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Table 't3' already exists
        at com.alibaba.otter.canal.client.adapter.rdb.RdbAdapter.sync(RdbAdapter.java:157)
        at com.alibaba.otter.canal.client.adapter.ProxyOuterAdapter.sync(ProxyOuterAdapter.java:42)
        at com.alibaba.otter.canal.adapter.launcher.loader.AdapterProcessor.batchSync(AdapterProcessor.java:139)
        at com.alibaba.otter.canal.adapter.launcher.loader.AdapterProcessor.lambda$null$1(AdapterProcessor.java:97)
        at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:895)
        at com.alibaba.otter.canal.adapter.launcher.loader.AdapterProcessor.lambda$null$2(AdapterProcessor.java:94)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:750)
Caused by: java.lang.RuntimeException: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Table 't3' already exists
        at com.alibaba.otter.canal.client.adapter.rdb.service.RdbMirrorDbSyncService.executeDdl(RdbMirrorDbSyncService.java:167)
        at com.alibaba.otter.canal.client.adapter.rdb.service.RdbMirrorDbSyncService.sync(RdbMirrorDbSyncService.java:77)
        at com.alibaba.otter.canal.client.adapter.rdb.RdbAdapter.sync(RdbAdapter.java:155)
        ... 9 common frames omitted
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Table 't3' already exists
        at sun.reflect.GeneratedConstructorAccessor37.newInstance(Unknown Source)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
        at com.mysql.jdbc.Util.getInstance(Util.java:408)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:944)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3933)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3869)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2524)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2675)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2465)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2439)
        at com.mysql.jdbc.StatementImpl.executeInternal(StatementImpl.java:829)
        at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:729)
        at com.alibaba.druid.pool.DruidPooledStatement.execute(DruidPooledStatement.java:635)
        at com.alibaba.otter.canal.client.adapter.rdb.service.RdbMirrorDbSyncService.executeDdl(RdbMirrorDbSyncService.java:160)
        ... 11 common frames omitted
2024-06-18 09:55:22.809 [Thread-4] ERROR c.a.otter.canal.adapter.launcher.loader.AdapterProcessor - Outer adapter sync failed!  Error sync and rollback, execute times: 65858
agapple commented 1 month ago

正常的,会有重复消费