[AMQ-8340] Deadlock with JDBC and MySQL 5.7 - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Bug
Status: Open
Priority: Major
Resolution: Unresolved
Affects Version/s: 5.16.2
Fix Version/s: None
Component/s: JDBC
Labels:
None
Environment:

ActiveMQ Version 5.16.2
c3p0 Version 0.9.5.5
mchange-commons Version 0.2.19
mysql-connector 5.1.49

Database Server is Percona Version 5.7.34-37

Description

We experience deadlocks when activemq tries to commit data via JDBC to our MySQL server.
Our ActiveMQ Server runs in active-passiv mode and the active server holds a lock on the database.

This seems to be the relevant logs:

2021-07-18 17:33:15,523 | WARN  | Commit failed: Deadlock found when trying to get lock; try restarting transaction | org.apache.activemq.store.jdbc.JDBCPersistenceAdapter | ActiveMQ Transport: tcp:///10.140.7.1:53898@61616
java.sql.BatchUpdateException: Deadlock found when trying to get lock; 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:403)
        at com.mysql.jdbc.Util.getInstance(Util.java:386)
        at com.mysql.jdbc.SQLError.createBatchUpdateException(SQLError.java:1154)
        at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1829)
        at com.mysql.jdbc.PreparedStatement.executeBatchInternal(PreparedStatement.java:1319)
        at com.mysql.jdbc.StatementImpl.executeBatch(StatementImpl.java:954)
        at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:2544)
        at org.apache.activemq.store.jdbc.TransactionContext.executeBatch(TransactionContext.java:138)
        at org.apache.activemq.store.jdbc.TransactionContext.executeBatch(TransactionContext.java:120)
        at org.apache.activemq.store.jdbc.TransactionContext.commit(TransactionContext.java:203)
        at org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.commitTransaction(JDBCPersistenceAdapter.java:534)
        at org.apache.activemq.store.memory.MemoryTransactionStore$Tx.commit(MemoryTransactionStore.java:110)
        at org.apache.activemq.store.memory.MemoryTransactionStore.commit(MemoryTransactionStore.java:277)
        at org.apache.activemq.transaction.LocalTransaction.commit(LocalTransaction.java:70)
        at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:254)
        at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114)
        at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114)
        at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114)
        at org.apache.activemq.broker.TransportConnection.processCommitTransactionOnePhase(TransportConnection.java:533)
        at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:100)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:331)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:200)
        at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
        at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125)
        at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301)
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
        at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:233)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:215)
        at java.lang.Thread.run(Thread.java:748)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; 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:403)
        at com.mysql.jdbc.Util.getInstance(Util.java:386)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:952)
        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.PreparedStatement.executeInternal(PreparedStatement.java:1915)
        at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2136)
        at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1813)
        ... 25 more
2021-07-18 17:33:15,533 | INFO  | Ignoring SQLException, java.io.IOException: Deadlock found when trying to get lock; try restarting transaction | org.apache.activemq.util.DefaultIOExceptionHandler | ActiveMQ Transport: tcp:///10.140.7.1:53898@61616
java.sql.BatchUpdateException: Deadlock found when trying to get lock; 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:403)
        at com.mysql.jdbc.Util.getInstance(Util.java:386)
        at com.mysql.jdbc.SQLError.createBatchUpdateException(SQLError.java:1154)
        at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1829)
        at com.mysql.jdbc.PreparedStatement.executeBatchInternal(PreparedStatement.java:1319)
        at com.mysql.jdbc.StatementImpl.executeBatch(StatementImpl.java:954)
        at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:2544)
        at org.apache.activemq.store.jdbc.TransactionContext.executeBatch(TransactionContext.java:138)
        at org.apache.activemq.store.jdbc.TransactionContext.executeBatch(TransactionContext.java:120)
        at org.apache.activemq.store.jdbc.TransactionContext.commit(TransactionContext.java:203)
        at org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.commitTransaction(JDBCPersistenceAdapter.java:534)
        at org.apache.activemq.store.memory.MemoryTransactionStore$Tx.commit(MemoryTransactionStore.java:110)
        at org.apache.activemq.store.memory.MemoryTransactionStore.commit(MemoryTransactionStore.java:277)
        at org.apache.activemq.transaction.LocalTransaction.commit(LocalTransaction.java:70)
        at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:254)
        at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114)
        at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114)
        at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114)
        at org.apache.activemq.broker.TransportConnection.processCommitTransactionOnePhase(TransportConnection.java:533)
        at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:100)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:331)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:200)
        at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
        at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125)
        at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301)
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
        at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:233)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:215)
        at java.lang.Thread.run(Thread.java:748)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; 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:403)
        at com.mysql.jdbc.Util.getInstance(Util.java:386)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:952)
        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.PreparedStatement.executeInternal(PreparedStatement.java:1915)
        at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2136)
        at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1813)
        ... 25 more
2021-07-18 17:33:15,538 | WARN  | Store COMMIT FAILED:  | org.apache.activemq.transaction.LocalTransaction | ActiveMQ Transport: tcp:///10.140.7.1:53898@61616
java.io.IOException: Not started.
        at org.apache.activemq.store.jdbc.TransactionContext.rollback(TransactionContext.java:223)
        at org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.rollbackTransaction(JDBCPersistenceAdapter.java:540)
        at org.apache.activemq.store.memory.MemoryTransactionStore$Tx.commit(MemoryTransactionStore.java:113)
        at org.apache.activemq.store.memory.MemoryTransactionStore.commit(MemoryTransactionStore.java:277)
        at org.apache.activemq.transaction.LocalTransaction.commit(LocalTransaction.java:70)
        at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:254)
        at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114)
        at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114)
        at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:114)
        at org.apache.activemq.broker.TransportConnection.processCommitTransactionOnePhase(TransportConnection.java:533)
        at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:100)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:331)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:200)
        at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
        at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125)
        at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301)
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
        at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:233)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:215)
        at java.lang.Thread.run(Thread.java:748)

This is our datasource configuration:

<bean id="activemq-ds" class="com.mchange.v2.c3p0.ComboPooledDataSource" destroy-method="close">
        <property name="driverClass" value="org.gjt.mm.mysql.Driver" />
        <property name="jdbcUrl" value="jdbc:mysql://10.130.11.1/activemq570?useSSL=false" />
        <property name="user" value="XXXX" />
        <property name="password" value="XXXX" />
        <property name="maxPoolSize" value="15" />
        <property name="minPoolSize" value="3" />
        <property name="autoCommitOnClose" value="false" />
        <property name="maxConnectionAge" value="0" />
        <property name="maxIdleTime" value="300" />
</bean>

Attachments

Activity

People

Assignee:: Unassigned

Reporter:: Daniel Niecke

Votes:: 0 Vote for this issue

Watchers:: 1 Start watching this issue

Dates

Created:: 21/Jul/21 09:21

Updated:: 21/Jul/21 09:21