search

alibaba / otter

阿里巴巴分布式数据库同步系统(解决中美异地机房)
Apache License 2.0
8.07k stars 2.49k forks source link

对应的channel load日志中总报这个错 #682

Open eason0420 opened 5 years ago

eason0420 commented 5 years ago

2018-12-19 11:57:36.184 [communication-async-1] ERROR c.a.o.s.c.core.impl.DefaultCommunicationClientImpl - call[116.62.24.128:1099] , retry[1] com.alibaba.otter.shared.communication.core.exception.CommunicationException: method_invoke_error:onTableStat Caused by: java.lang.reflect.InvocationTargetException: null at sun.reflect.GeneratedMethodAccessor249.invoke(Unknown Source) ~[na:na] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_191] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_191] at com.alibaba.otter.shared.communication.core.impl.AbstractCommunicationEndpoint.acceptEvent(AbstractCommunicationEndpoint.java:72) ~[shared.communication-4.2.17.jar:na] at com.alibaba.dubbo.common.bytecode.Wrapper0.invokeMethod(Wrapper0.java) ~[na:2.5.3] at com.alibaba.dubbo.rpc.proxy.javassist.JavassistProxyFactory$1.doInvoke(JavassistProxyFactory.java:46) ~[dubbo-2.5.3.jar:2.5.3] at com.alibaba.dubbo.rpc.proxy.AbstractProxyInvoker.invoke(AbstractProxyInvoker.java:72) ~[dubbo-2.5.3.jar:2.5.3] at com.alibaba.dubbo.rpc.protocol.dubbo.DubboProtocol$1.reply(DubboProtocol.java:108) ~[dubbo-2.5.3.jar:2.5.3] at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.handleRequest(HeaderExchangeHandler.java:84) ~[dubbo-2.5.3.jar:2.5.3] at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.received(HeaderExchangeHandler.java:170) ~[dubbo-2.5.3.jar:2.5.3] at com.alibaba.dubbo.remoting.transport.DecodeHandler.received(DecodeHandler.java:52) ~[dubbo-2.5.3.jar:2.5.3] at com.alibaba.dubbo.remoting.transport.dispatcher.ChannelEventRunnable.run(ChannelEventRunnable.java:82) ~[dubbo-2.5.3.jar:2.5.3] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_191] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_191] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_191] Caused by: org.springframework.dao.CannotAcquireLockException: SqlMapClient operation; SQL [];
--- The error occurred in sqlmap/sqlmap-mapping-tableStat.xml.
--- The error occurred while applying a parameter map.
--- Check the modifyTableStat-InlineParameterMap.
--- Check the statement (update failed).
--- Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction; nested exception is com.ibatis.common.jdbc.exception.NestedSQLException:
--- The error occurred in sqlmap/sqlmap-mapping-tableStat.xml.
--- The error occurred while applying a parameter map.
--- Check the modifyTableStat-InlineParameterMap.
--- Check the statement (update failed).
--- Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:261) ~[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.orm.ibatis.SqlMapClientTemplate.execute(SqlMapClientTemplate.java:203) ~[spring-orm-3.2.18.RELEASE.jar:3.2.18.RELEASE] at org.springframework.orm.ibatis.SqlMapClientTemplate.update(SqlMapClientTemplate.java:378) ~[spring-orm-3.2.18.RELEASE.jar:3.2.18.RELEASE] at com.alibaba.otter.manager.biz.statistics.table.dal.ibatis.IbatisTableStatDAO.modifyTableStat(IbatisTableStatDAO.java:45) ~[na:na] at com.alibaba.otter.manager.biz.statistics.table.impl.TableStatServiceImpl.updateTableStat(TableStatServiceImpl.java:61) ~[na:na] at com.alibaba.otter.manager.biz.remote.impl.StatsRemoteServiceImpl.onTableStat(StatsRemoteServiceImpl.java:169) ~[na:na] ... 15 common frames omitted Caused by: com.ibatis.common.jdbc.exception.NestedSQLException:
--- The error occurred in sqlmap/sqlmap-mapping-tableStat.xml.
--- The error occurred while applying a parameter map.
--- Check the modifyTableStat-InlineParameterMap.
--- Check the statement (update failed).
--- Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.executeUpdate(MappedStatement.java:107) ~[ibatis-sqlmap-2.3.4.726.jar:na] at com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.update(SqlMapExecutorDelegate.java:457) ~[ibatis-sqlmap-2.3.4.726.jar:na] at com.ibatis.sqlmap.engine.impl.SqlMapSessionImpl.update(SqlMapSessionImpl.java:90) ~[ibatis-sqlmap-2.3.4.726.jar:na] at org.springframework.orm.ibatis.SqlMapClientTemplate$9.doInSqlMapClient(SqlMapClientTemplate.java:380) ~[spring-orm-3.2.18.RELEASE.jar:3.2.18.RELEASE] at org.springframework.orm.ibatis.SqlMapClientTemplate$9.doInSqlMapClient(SqlMapClientTemplate.java:1) ~[spring-orm-3.2.18.RELEASE.jar:3.2.18.RELEASE] at org.springframework.orm.ibatis.SqlMapClientTemplate.execute(SqlMapClientTemplate.java:200) ~[spring-orm-3.2.18.RELEASE.jar:3.2.18.RELEASE] ... 19 common frames omitted Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction at sun.reflect.GeneratedConstructorAccessor64.newInstance(Unknown Source) ~[na:na] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_191] at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[na:1.8.0_191] at com.mysql.jdbc.Util.handleNewInstance(Util.java:425) ~[mysql-connector-java-5.1.40.jar:5.1.40] at com.mysql.jdbc.Util.getInstance(Util.java:408) ~[mysql-connector-java-5.1.40.jar:5.1.40] at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:951) ~[mysql-connector-java-5.1.40.jar:5.1.40] at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3970) ~[mysql-connector-java-5.1.40.jar:5.1.40] at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3906) ~[mysql-connector-java-5.1.40.jar:5.1.40] at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2524) ~[mysql-connector-java-5.1.40.jar:5.1.40] at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2677) ~[mysql-connector-java-5.1.40.jar:5.1.40] at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2549) ~[mysql-connector-java-5.1.40.jar:5.1.40] at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861) ~[mysql-connector-java-5.1.40.jar:5.1.40] at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:1192) ~[mysql-connector-java-5.1.40.jar:5.1.40] at org.apache.commons.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:172) ~[commons-dbcp-1.4.jar:1.4] at org.apache.commons.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:172) ~[commons-dbcp-1.4.jar:1.4] at com.ibatis.sqlmap.engine.execution.SqlExecutor.executeUpdate(SqlExecutor.java:80) ~[ibatis-sqlmap-2.3.4.726.jar:na] at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.sqlExecuteUpdate(MappedStatement.java:216) ~[ibatis-sqlmap-2.3.4.726.jar:na] at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.executeUpdate(MappedStatement.java:94) ~[ibatis-sqlmap-2.3.4.726.jar:na] ... 24 common frames omitted

eason0420 commented 5 years ago

发现有时会同时出现多条一样的SQL修改同一条纪录，是不是这个原因造成死锁超时的 update TABLE_STAT set FILE_SIZE=FILE_SIZE+0, FILE_COUNT=FILE_COUNT+0, DELETE_COUNT=DELETE_COUNT+0, UPDATE_COUNT=UPDATE_COUNT+0, INSERT_COUNT=INSERT_COUNT+1, GMT_MODIFIED=now() WHERE PIPELINE_ID=5 and DATA_MEDIA_PAIR_ID=547 update TABLE_STAT set FILE_SIZE=FILE_SIZE+0, FILE_COUNT=FILE_COUNT+0, DELETE_COUNT=DELETE_COUNT+0, UPDATE_COUNT=UPDATE_COUNT+0, INSERT_COUNT=INSERT_COUNT+1, GMT_MODIFIED=now() WHERE PIPELINE_ID=5 and DATA_MEDIA_PAIR_ID=547 update TABLE_STAT set FILE_SIZE=FILE_SIZE+0, FILE_COUNT=FILE_COUNT+0, DELETE_COUNT=DELETE_COUNT+0, UPDATE_COUNT=UPDATE_COUNT+0, INSERT_COUNT=INSERT_COUNT+1, GMT_MODIFIED=now() WHERE PIPELINE_ID=5 and DATA_MEDIA_PAIR_ID=547 update TABLE_STAT set FILE_SIZE=FILE_SIZE+0, FILE_COUNT=FILE_COUNT+0, DELETE_COUNT=DELETE_COUNT+0, UPDATE_COUNT=UPDATE_COUNT+0, INSERT_COUNT=INSERT_COUNT+1, GMT_MODIFIED=now() WHERE PIPELINE_ID=5 and DATA_MEDIA_PAIR_ID=547