otter源码分析 TODO
想解决一个源码的疑问，需要debug otter node模块。
开启同步任务后，local node 的 mainstem一直 显示：定位中，数据更改后，同步功能不可用。
bug信息如下
pid:8 nid:3 exception:canal:test_cancal_debug:java.lang.NullPointerException
at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.loadBinlogChecksum(MysqlConnection.java:284)
at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:113)
at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:209)
at java.lang.Thread.run(Thread.java:745)
这个问题是当前的1.0.23版本的canal有些问题，参考https://github.com/alibaba/otter/issues/258
我想了个办法： 关联local的canal源码，然后手工修复canal 的bug。
cannal源码链接如下
https://github.com/alibaba/canal
otter源码链接如下
https://github.com/alibaba/otter
第一步 修复源码bug
经过观察，原来是 com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.loadBinlogChecksum 中
columnValues.get(0)没有判空，做如下修改
第二步 update otter main pom.xml
第三步 otter 全部模块 执行 maven update.
经本人验证，好用。
————————————————
版权声明：本文为CSDN博主「iteye_9644」的原创文章，遵循CC 4.0 BY-SA版权协议，转载请附上原文出处链接及本声明。
原文链接：https://blog.csdn.net/iteye_9644/article/details/82679450
TODO:
2020-08-13 20:27:53.302 [pipelineId = 1,taskName = ProcessSelect] ERROR com.alibaba.otter.node.etl.select.SelectTask - [1] selectTask is error! com.alibaba.otter.node.etl.select.exceptions.SelectException: java.lang.NullPointerException at com.alibaba.otter.node.etl.select.selector.MessageParser.parse(MessageParser.java:218) ~[node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.select.selector.canal.CanalEmbedSelector.selector(CanalEmbedSelector.java:278) ~[node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.select.SelectTask.processSelect(SelectTask.java:236) [node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.select.SelectTask.access$300(SelectTask.java:94) [node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.select.SelectTask$1.run(SelectTask.java:208) [node.etl-4.2.18.jar:na] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_181] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_181] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_181] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_181] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181] Caused by: java.lang.NullPointerException: null 2020-08-13 20:27:53.306 [pipelineId = 1,taskName = ProcessSelect] WARN c.a.o.s.a.i.setl.zookeeper.termin.WarningTerminProcess - nid:2[1:setl:com.alibaba.otter.node.etl.select.exceptions.SelectException: java.lang.NullPointerException at com.alibaba.otter.node.etl.select.selector.MessageParser.parse(MessageParser.java:218) at com.alibaba.otter.node.etl.select.selector.canal.CanalEmbedSelector.selector(CanalEmbedSelector.java:278) at com.alibaba.otter.node.etl.select.SelectTask.processSelect(SelectTask.java:236) at com.alibaba.otter.node.etl.select.SelectTask.access$300(SelectTask.java:94) at com.alibaba.otter.node.etl.select.SelectTask$1.run(SelectTask.java:208) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) 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:748) Caused by: java.lang.NullPointerException
tter.canal.parse.inbound.mysql.MysqlEventParser - prepare to find start position just last position {"identity":{"slaveId":-1,"sourceAddress":{"address":"zkh-mysql-uat-cluster-private.rwlb.rds.aliyuncs.com","port":3306}},"postion":{"gtid":"","included":false,"journalName":"m ysql-bin.009670","position":356744510,"serverId":14457169,"timestamp":1606371394000}} 2020-12-09 15:01:00.818 [destination = pathfinderTozafSecurityAdmin2Uat , address = zkh-mysql-uat-cluster-private.rwlb.rds.aliyuncs.com/10.10.3.3:3306 , EventParser] WARN c.a. otter.canal.parse.inbound.mysql.MysqlEventParser - ---> find start position successfully, EntryPosition[included=false,journalName=mysql-bin.009670,position=356744510,serverId= 14457169,gtid=,timestamp=1606371394000] cost : 14ms , the next step is binlog dump 2020-12-09 15:01:01.838 [pipelineId = 5,taskName = LoadWorker] ERROR com.alibaba.otter.node.etl.load.LoadTask - [5] loadWork executor is error! data:EtlEventData[currNid=2,next Nid=2,desc=[MemoryPipeKey[identity=Identity[channelId=6,pipelineId=5,processId=1],time=1607497261255,dataType=DB_BATCH]],processId=1,startTime=1607497261108,endTime=<null>,firs tTime=1606371387000,batchId=2,number=1,size=<null>,exts=<null>,pipelineId=5] com.alibaba.otter.node.etl.load.exception.LoadException: java.util.concurrent.ExecutionException: com.alibaba.otter.node.etl.load.exception.LoadException: com.alibaba.otter.nod e.etl.load.exception.LoadException: org.springframework.jdbc.BadSqlGrammarException: StatementCallback; bad SQL grammar []; nested exception is com.mysql.jdbc.exceptions.jdbc4. MySQLSyntaxErrorException: Key column 'ProductId' doesn't exist in table Caused by: java.util.concurrent.ExecutionException: com.alibaba.otter.node.etl.load.exception.LoadException: com.alibaba.otter.node.etl.load.exception.LoadException: org.spring framework.jdbc.BadSqlGrammarException: StatementCallback; bad SQL grammar []; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Key column 'Product Id' doesn't exist in table at java.util.concurrent.FutureTask.report(FutureTask.java:122) [na:1.8.0_181] at java.util.concurrent.FutureTask.get(FutureTask.java:192) [na:1.8.0_181] at com.alibaba.otter.node.etl.load.loader.db.DataBatchLoader.load(DataBatchLoader.java:107) ~[node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.load.loader.OtterLoaderFactory.load(OtterLoaderFactory.java:50) ~[node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.load.LoadTask$1.run(LoadTask.java:85) ~[node.etl-4.2.18.jar:na] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_181] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_181] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_181] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_181] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181] Caused by: com.alibaba.otter.node.etl.load.exception.LoadException: com.alibaba.otter.node.etl.load.exception.LoadException: org.springframework.jdbc.BadSqlGrammarException: St atementCallback; bad SQL grammar []; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Key column 'ProductId' doesn't exist in table Caused by: com.alibaba.otter.node.etl.load.exception.LoadException: org.springframework.jdbc.BadSqlGrammarException: StatementCallback; bad SQL grammar []; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Key column 'ProductId' doesn't exist in table Caused by: org.springframework.jdbc.BadSqlGrammarException: StatementCallback; bad SQL grammar []; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException : Key column 'ProductId' doesn't exist in table at org.springframework.jdbc.support.SQLStateSQLExceptionTranslator.doTranslate(SQLStateSQLExceptionTranslator.java:98) ~[spring-jdbc-3.1.2.RELEASE.jar:3.1.2.RELEASE] at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72) ~[spring-jdbc-3.1.2.RELEASE.jar:3.1 .2.RELEASE] at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80) ~[spring-jdbc-3.1.2.RELEASE.jar:3.1 .2.RELEASE] at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:407) ~[spring-jdbc-3.1.2.RELEASE.jar:3.1.2.RELEASE] at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction.doDdl(DbLoadAction.java:357) ~[node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction.load(DbLoadAction.java:135) ~[node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$$FastClassByCGLIB$$d932a4cb.invoke(<generated>) ~[cglib-nodep-2.2.jar:na] at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:191) ~[cglib-nodep-2.2.jar:na] at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:618) ~[spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE] at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$$EnhancerByCGLIB$$80fd23c2.load(<generated>) ~[cglib-nodep-2.2.jar:na] at com.alibaba.otter.node.etl.load.loader.db.DataBatchLoader$2.call(DataBatchLoader.java:198) ~[node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.load.loader.db.DataBatchLoader$2.call(DataBatchLoader.java:189) ~[node.etl-4.2.18.jar:na] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_181] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_181] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_181] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_181] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_181] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181] Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Key column 'ProductId' doesn't exist in table at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.8.0_181] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:1.8.0_181] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_181] at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[na:1.8.0_181] at com.mysql.jdbc.Util.handleNewInstance(Util.java:425) ~[mysql-connector-java-5.1.47.jar:5.1.47] at com.mysql.jdbc.Util.getInstance(Util.java:408) ~[mysql-connector-java-5.1.47.jar:5.1.47] at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:944) ~[mysql-connector-java-5.1.47.jar:5.1.47] at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3978) ~[mysql-connector-java-5.1.47.jar:5.1.47] at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3914) ~[mysql-connector-java-5.1.47.jar:5.1.47] at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2530) ~[mysql-connector-java-5.1.47.jar:5.1.47] at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2683) ~[mysql-connector-java-5.1.47.jar:5.1.47] at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2491) ~[mysql-connector-java-5.1.47.jar:5.1.47] at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2449) ~[mysql-connector-java-5.1.47.jar:5.1.47] at com.mysql.jdbc.StatementImpl.executeInternal(StatementImpl.java:845) ~[mysql-connector-java-5.1.47.jar:5.1.47] at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:745) ~[mysql-connector-java-5.1.47.jar:5.1.47] at org.apache.commons.dbcp.DelegatingStatement.execute(DelegatingStatement.java:264) ~[commons-dbcp-1.4.jar:1.4] at org.apache.commons.dbcp.DelegatingStatement.execute(DelegatingStatement.java:264) ~[commons-dbcp-1.4.jar:1.4] at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$1.doInStatement(DbLoadAction.java:369) ~[node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$1.doInStatement(DbLoadAction.java:357) ~[node.etl-4.2.18.jar:na] at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:396) ~[spring-jdbc-3.1.2.RELEASE.jar:3.1.2.RELEASE] ... 14 common frames omitted 2020-12-09 15:01:01.859 [pipelineId = 5,taskName = LoadWorker]
2021-04-08 18:56:46.091 [destination = pathfinderdbPolardbGwProductCenter , address = rm-bp1lc206u47icpvi5.mysql.rds.aliyuncs.com/10.10.0.238:3306 , EventParser] WARN c.a.otte r.canal.parse.inbound.mysql.MysqlEventParser - ---> begin to find start position, it will be long time for reset or first position 2021-04-08 18:56:46.103 [destination = pathfinderdbPolardbGwProductCenter , address = rm-bp1lc206u47icpvi5.mysql.rds.aliyuncs.com/10.10.0.238:3306 , EventParser] WARN c.a.otte r.canal.parse.inbound.mysql.MysqlEventParser - prepare to find start position mysql-bin.012183:50116568:null 2021-04-08 18:56:46.104 [destination = pathfinderdbPolardbGwProductCenter , address = rm-bp1lc206u47icpvi5.mysql.rds.aliyuncs.com/10.10.0.238:3306 , EventParser] WARN c.a.otte r.canal.parse.inbound.mysql.MysqlEventParser - ---> find start position successfully, EntryPosition[included=false,journalName=mysql-bin.012183,position=50116568,serverId=<null >,gtid=<null>,timestamp=<null>] cost : 13ms , the next step is binlog dump 2021-04-08 19:28:17.312 [DbLoadAction] WARN com.alibaba.otter.node.etl.load.loader.db.DbLoadAction - ##load phase one failed! java.util.concurrent.ExecutionException: com.alibaba.otter.node.etl.load.exception.LoadException: org.springframework.dao.CannotAcquireLockException: PreparedStatementCallback; SQL [update `gw_product_center`.`productsaleorgext` set `ModifiedOn` = ? where ( `Id` = ? )]; Lock wait timeout exceeded; try restarting transaction; nested exception is jav a.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:261) at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72) at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:603) at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:615) at org.springframework.jdbc.core.JdbcTemplate.batchUpdate(JdbcTemplate.java:884) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$DbLoadWorker$1.doInTransaction(DbLoadAction.java:591) at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$DbLoadWorker.doCall(DbLoadAction.java:582) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$DbLoadWorker.call(DbLoadAction.java:545) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$DbLoadWorker.call(DbLoadAction.java:517) 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:748) Caused by: java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) 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.createBatchUpdateException(SQLError.java:1163) at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1823) at com.mysql.jdbc.PreparedStatement.executeBatchInternal(PreparedStatement.java:1307) at com.mysql.jdbc.StatementImpl.executeBatch(StatementImpl.java:970) at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297) at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297) at org.springframework.jdbc.core.JdbcTemplate$4.doInPreparedStatement(JdbcTemplate.java:899) at org.springframework.jdbc.core.JdbcTemplate$4.doInPreparedStatement(JdbcTemplate.java:1) at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:587) ... 11 more Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) 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:952) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3978) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3914) at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2530) at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2683) at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2495) at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1903) at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2124) at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1801) ... 18 more :----------------- - PairId: 48 , TableId: 76 , EventType : U , Time : 1617881246000 - Consistency : , Mode : ----------------- ---Pks EventColumn[index=7,columnType=-5,columnName=Id,columnValue=9389486,isNull=false,isKey=true,isUpdate=true] ---oldPks ---Columns EventColumn[index=4,columnType=93,columnName=ModifiedOn,columnValue=2021-04-08 19:27:26,isNull=false,isKey=false,isUpdate=true] ---Sql update `gw_product_center`.`productsaleorgext` set `ModifiedOn` = ? where ( `Id` = ? ) at java.util.concurrent.FutureTask.report(FutureTask.java:122) [na:1.8.0_181] at java.util.concurrent.FutureTask.get(FutureTask.java:192) [na:1.8.0_181] at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction.doTwoPhase(DbLoadAction.java:410) [node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction.doLoad(DbLoadAction.java:275) [node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction.load(DbLoadAction.java:161) [node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$$FastClassByCGLIB$$d932a4cb.invoke(<generated>) [cglib-nodep-2.2.jar:na] at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:191) [cglib-nodep-2.2.jar:na] at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:618) [spring-aop-3.1.2.RELEASE.jar:3.1.2.RELEASE] at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$$EnhancerByCGLIB$$80fd23c2.load(<generated>) [cglib-nodep-2.2.jar:na] at com.alibaba.otter.node.etl.load.loader.db.DataBatchLoader$2.call(DataBatchLoader.java:198) [node.etl-4.2.18.jar:na] at com.alibaba.otter.node.etl.load.loader.db.DataBatchLoader$2.call(DataBatchLoader.java:189) [node.etl-4.2.18.jar:na] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_181] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_181] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_181] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_181] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_181] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181] Caused by: com.alibaba.otter.node.etl.load.exception.LoadException: org.springframework.dao.CannotAcquireLockException: PreparedStatementCallback; SQL [update `gw_product_cente r`.`productsaleorgext` set `ModifiedOn` = ? where ( `Id` = ? )]; Lock wait timeout exceeded; try restarting transaction; nested exception is java.sql.BatchUpdateException: Lo ck wait timeout exceeded; try restarting transaction at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:261) at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72) at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:603) at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:615) at org.springframework.jdbc.core.JdbcTemplate.batchUpdate(JdbcTemplate.java:884) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$DbLoadWorker$1.doInTransaction(DbLoadAction.java:591) at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$DbLoadWorker.doCall(DbLoadAction.java:582) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$DbLoadWorker.call(DbLoadAction.java:545) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$DbLoadWorker.call(DbLoadAction.java:517) 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:748) Caused by: java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) 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.createBatchUpdateException(SQLError.java:1163) at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1823) at com.mysql.jdbc.PreparedStatement.executeBatchInternal(PreparedStatement.java:1307) at com.mysql.jdbc.StatementImpl.executeBatch(StatementImpl.java:970) at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297) at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297) at org.springframework.jdbc.core.JdbcTemplate$4.doInPreparedStatement(JdbcTemplate.java:899) at org.springframework.jdbc.core.JdbcTemplate$4.doInPreparedStatement(JdbcTemplate.java:1) at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:587) ... 11 more Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) 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:952) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3978) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3914) at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2530) at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2683) at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2495) at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1903) at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2124) at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1801) ... 18 more :----------------- - PairId: 48 , TableId: 76 , EventType : U , Time : 1617881246000 - Consistency : , Mode : ----------------- ---Pks EventColumn[index=7,columnType=-5,columnName=Id,columnValue=9389486,isNull=false,isKey=true,isUpdate=true] ---oldPks ---Columns EventColumn[index=4,columnType=93,columnName=ModifiedOn,columnValue=2021-04-08 19:27:26,isNull=false,isKey=false,isUpdate=true] ---Sql update `gw_product_center`.`productsaleorgext` set `ModifiedOn` = ? where ( `Id` = ? ) 2021-04-08 19:29:09.160 [DbLoadAction] WARN com.alibaba.otter.node.etl.load.loader.db.DbLoadAction - skip exception for data : EventData[tableId=76,tableName=productsaleorgext ,schemaName=gw_product_center,eventType=UPDATE,executeTime=1617881246000,oldKeys=[],keys=[EventColumn[index=7,columnType=-5,columnName=Id,columnValue=9389486,isNull=false,isKey =true,isUpdate=true]],columns=[EventColumn[index=4,columnType=93,columnName=ModifiedOn,columnValue=2021-04-08 19:27:26,isNull=false,isKey=false,isUpdate=true]],size=318,pairId= 48,sql=update `gw_product_center`.`productsaleorgext` set `ModifiedOn` = ? where ( `Id` = ? ),ddlSchemaName=<null>,syncMode=<null>,syncConsistency=<null>,remedy=false,hint=<n ull>,withoutSchema=false] , caused by com.alibaba.otter.node.etl.load.exception.LoadException: org.springframework.dao.CannotAcquireLockException: PreparedStatementCallback; SQ L [update `gw_product_center`.`productsaleorgext` set `ModifiedOn` = ? where ( `Id` = ? )]; Lock wait timeout exceeded; try restarting transaction; nested exception is com.my sql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:261) at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72) at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:603) at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:812) at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:868) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$DbLoadWorker$2.doInTransaction(DbLoadAction.java:625) at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$DbLoadWorker.doCall(DbLoadAction.java:617) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$DbLoadWorker.call(DbLoadAction.java:545) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction.doTwoPhase(DbLoadAction.java:444) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction.doLoad(DbLoadAction.java:275) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction.load(DbLoadAction.java:161) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$$FastClassByCGLIB$$d932a4cb.invoke(<generated>) at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:191) at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:618) at com.alibaba.otter.node.etl.load.loader.db.DbLoadAction$$EnhancerByCGLIB$$80fd23c2.load(<generated>) at com.alibaba.otter.node.etl.load.loader.db.DataBatchLoader$2.call(DataBatchLoader.java:198) at com.alibaba.otter.node.etl.load.loader.db.DataBatchLoader$2.call(DataBatchLoader.java:189) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) 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:748) Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) 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:952) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3978) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3914) at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2530) at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2683) at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2495) at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1903) at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2124) at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2058) at com.mysql.jdbc.PreparedStatement.executeLargeUpdate(PreparedStatement.java:5158) at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2043) at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105) at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105) at org.springframework.jdbc.core.JdbcTemplate$2.doInPreparedStatement(JdbcTemplate.java:818) at org.springframework.jdbc.core.JdbcTemplate$2.doInPreparedStatement(JdbcTemplate.java:1) at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:587) ... 21 more :----------------- - PairId: 48 , TableId: 76 , EventType : U , Time : 1617881246000 - Consistency : , Mode : ----------------- ---Pks EventColumn[index=7,columnType=-5,columnName=Id,columnValue=9389486,isNull=false,isKey=true,isUpdate=true] ---oldPks ---Columns EventColumn[index=4,columnType=93,columnName=ModifiedOn,columnValue=2021-04-08 19:27:26,isNull=false,isKey=false,isUpdate=true] ---Sql update `gw_product_center`.`productsaleorgext` set `ModifiedOn` = ? where ( `Id` = ? ) 2021-04-08 20:18:05.880 [pipelineId = 9,taskName = SelectTask] WARN c.a.o.shared.arbitrate.impl.setl.monitor.MainstemMonitor - mainstem check is interrupt 2021-04-08 20:28:37.291 [pipelineId = 9,taskName = SelectTask] WARN c.a.o.shared.arbitrate.impl.setl.monitor.MainstemMonitor - mainstem is not run any in node
