ActiveMQ
  1. ActiveMQ
  2. AMQ-2534

Broker gets stuck with an error about using a closed JDBC statement

    Details

    • Type: Bug Bug
    • Status: Open
    • Priority: Major Major
    • Resolution: Unresolved
    • Affects Version/s: 5.3.0
    • Fix Version/s: 5.x
    • Component/s: Message Store
    • Labels:
      None
    • Environment:

      Linux
      Sun JDK 6, several different update versions
      Mysql

      Description

      This seems to happen after a period of several hours of inactivity. One symptom of the problem is that in the web UI you can see that a queue has a non-zero message count, but clicking on the queue to see the actual messages shows nothing.

      Config:
      <persistenceAdapter>
      <jdbcPersistenceAdapter dataSource="#mysql-ds"/>
      </persistenceAdapter>

      <bean id="mysql-ds" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
      <property name="driverClassName" value="com.mysql.jdbc.Driver"/>
      <property name="url" value="jdbc:mysql://dbserver/activeMQ?relaxAutoCommit=true&autoReconnect=true"/>
      <property name="username" value="user"/>
      <property name="password" value="pass"/>
      <property name="maxActive" value="200"/>
      <property name="poolPreparedStatements" value="true"/>
      </bean>

      Log:
      2009-11-27 07:40:25,026 | WARN | Close failed: Already closed. | org.apache.activemq.store.jdbc.TransactionContext | QueueThread:queue://(queue name)
      java.sql.SQLException: Already closed.
      at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:84)
      at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:181)
      at org.apache.activemq.store.jdbc.TransactionContext.close(TransactionContext.java:135)
      at org.apache.activemq.store.jdbc.JDBCMessageStore.getMessageCount(JDBCMessageStore.java:198)
      at org.apache.activemq.store.ProxyMessageStore.getMessageCount(ProxyMessageStore.java:83)
      at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.getStoreSize(QueueStorePrefetch.java:63)
      at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.remove(AbstractStoreCursor.java:185)
      at org.apache.activemq.broker.region.cursors.StoreQueueCursor.remove(StoreQueueCursor.java:141)
      at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1367)
      at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1503)
      at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1178)
      at org.apache.activemq.thread.DeterministicTaskRunner.runTask(DeterministicTaskRunner.java:84)
      at org.apache.activemq.thread.DeterministicTaskRunner$1.run(DeterministicTaskRunner.java:41)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      at java.lang.Thread.run(Unknown Source)
      2009-11-27 07:40:25,027 | ERROR | Failed to get message count | org.apache.activemq.broker.region.cursors.QueueStorePrefetch | QueueThread:queue://(queue name)
      java.io.IOException: Failed to get Message Count: queue://(queue name). Reason: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed.
      at org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:33)
      at org.apache.activemq.store.jdbc.JDBCMessageStore.getMessageCount(JDBCMessageStore.java:196)
      at org.apache.activemq.store.ProxyMessageStore.getMessageCount(ProxyMessageStore.java:83)
      at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.getStoreSize(QueueStorePrefetch.java:63)
      at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.remove(AbstractStoreCursor.java:185)
      at org.apache.activemq.broker.region.cursors.StoreQueueCursor.remove(StoreQueueCursor.java:141)
      at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1367)
      at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1503)
      at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1178)
      at org.apache.activemq.thread.DeterministicTaskRunner.runTask(DeterministicTaskRunner.java:84)
      at org.apache.activemq.thread.DeterministicTaskRunner$1.run(DeterministicTaskRunner.java:41)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      at java.lang.Thread.run(Unknown Source)
      Caused by: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed.
      at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:888)
      at com.mysql.jdbc.Statement.checkClosed(Statement.java:380)
      at com.mysql.jdbc.PreparedStatement.setString(PreparedStatement.java:3374)
      at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:132)
      at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:132)
      at org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.doGetMessageCount(DefaultJDBCAdapter.java:700)
      at org.apache.activemq.store.jdbc.JDBCMessageStore.getMessageCount(JDBCMessageStore.java:192)
      ... 12 more
      2009-11-27 07:40:25,028 | ERROR | Failed to page in more queue messages | org.apache.activemq.broker.region.Queue | QueueThread:queue://(queue name)
      java.lang.RuntimeException: java.io.IOException: Failed to get Message Count: queue://(queue name). Reason: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed.
      at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.getStoreSize(QueueStorePrefetch.java:66)
      at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.remove(AbstractStoreCursor.java:185)
      at org.apache.activemq.broker.region.cursors.StoreQueueCursor.remove(StoreQueueCursor.java:141)
      at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1367)
      at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1503)
      at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1178)
      at org.apache.activemq.thread.DeterministicTaskRunner.runTask(DeterministicTaskRunner.java:84)
      at org.apache.activemq.thread.DeterministicTaskRunner$1.run(DeterministicTaskRunner.java:41)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      at java.lang.Thread.run(Unknown Source)
      Caused by: java.io.IOException: Failed to get Message Count: queue://(queue name). Reason: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed.
      at org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:33)
      at org.apache.activemq.store.jdbc.JDBCMessageStore.getMessageCount(JDBCMessageStore.java:196)
      at org.apache.activemq.store.ProxyMessageStore.getMessageCount(ProxyMessageStore.java:83)
      at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.getStoreSize(QueueStorePrefetch.java:63)
      ... 10 more
      Caused by: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed.
      at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:888)
      at com.mysql.jdbc.Statement.checkClosed(Statement.java:380)
      at com.mysql.jdbc.PreparedStatement.setString(PreparedStatement.java:3374)
      at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:132)
      at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:132)
      at org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.doGetMessageCount(DefaultJDBCAdapter.java:700)
      at org.apache.activemq.store.jdbc.JDBCMessageStore.getMessageCount(JDBCMessageStore.java:192)
      ... 12 more
      2009-11-27 07:40:25,086 | WARN | Close failed: Already closed. | org.apache.activemq.store.jdbc.TransactionContext | QueueThread:queue://(queue name)
      java.sql.SQLException: Already closed.
      at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:84)
      at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:181)
      at org.apache.activemq.store.jdbc.TransactionContext.close(TransactionContext.java:135)
      at org.apache.activemq.store.jdbc.JDBCMessageStore.getMessageCount(JDBCMessageStore.java:198)
      at org.apache.activemq.store.ProxyMessageStore.getMessageCount(ProxyMessageStore.java:83)
      at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.getStoreSize(QueueStorePrefetch.java:63)
      at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.remove(AbstractStoreCursor.java:185)
      at org.apache.activemq.broker.region.cursors.StoreQueueCursor.remove(StoreQueueCursor.java:141)
      at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1367)
      at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1503)
      at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1178)
      at org.apache.activemq.thread.DeterministicTaskRunner.runTask(DeterministicTaskRunner.java:84)
      at org.apache.activemq.thread.DeterministicTaskRunner$1.run(DeterministicTaskRunner.java:41)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      at java.lang.Thread.run(Unknown Source)
      2009-11-27 07:40:25,088 | ERROR | Failed to get message count | org.apache.activemq.broker.region.cursors.QueueStorePrefetch | QueueThread:queue://(queue name)
      java.io.IOException: Failed to get Message Count: queue://(queue name). Reason: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed.
      at org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:33)
      at org.apache.activemq.store.jdbc.JDBCMessageStore.getMessageCount(JDBCMessageStore.java:196)
      at org.apache.activemq.store.ProxyMessageStore.getMessageCount(ProxyMessageStore.java:83)
      at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.getStoreSize(QueueStorePrefetch.java:63)
      at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.remove(AbstractStoreCursor.java:185)
      at org.apache.activemq.broker.region.cursors.StoreQueueCursor.remove(StoreQueueCursor.java:141)
      at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1367)
      at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1503)
      at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1178)
      at org.apache.activemq.thread.DeterministicTaskRunner.runTask(DeterministicTaskRunner.java:84)
      at org.apache.activemq.thread.DeterministicTaskRunner$1.run(DeterministicTaskRunner.java:41)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      at java.lang.Thread.run(Unknown Source)
      Caused by: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed.
      at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:888)
      at com.mysql.jdbc.Statement.checkClosed(Statement.java:380)
      at com.mysql.jdbc.PreparedStatement.setString(PreparedStatement.java:3374)
      at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:132)
      at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:132)
      at org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.doGetMessageCount(DefaultJDBCAdapter.java:700)
      at org.apache.activemq.store.jdbc.JDBCMessageStore.getMessageCount(JDBCMessageStore.java:192)
      ... 12 more
      2009-11-27 07:40:25,088 | ERROR | Failed to page in more queue messages | org.apache.activemq.broker.region.Queue | QueueThread:queue://(queue name)
      java.lang.RuntimeException: java.io.IOException: Failed to get Message Count: queue://(queue name). Reason: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed.
      at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.getStoreSize(QueueStorePrefetch.java:66)
      at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.remove(AbstractStoreCursor.java:185)
      at org.apache.activemq.broker.region.cursors.StoreQueueCursor.remove(StoreQueueCursor.java:141)
      at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1367)
      at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1503)
      at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1178)
      at org.apache.activemq.thread.DeterministicTaskRunner.runTask(DeterministicTaskRunner.java:84)
      at org.apache.activemq.thread.DeterministicTaskRunner$1.run(DeterministicTaskRunner.java:41)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
      at java.lang.Thread.run(Unknown Source)
      Caused by: java.io.IOException: Failed to get Message Count: queue://(queue name). Reason: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed.
      at org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:33)
      at org.apache.activemq.store.jdbc.JDBCMessageStore.getMessageCount(JDBCMessageStore.java:196)
      at org.apache.activemq.store.ProxyMessageStore.getMessageCount(ProxyMessageStore.java:83)
      at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.getStoreSize(QueueStorePrefetch.java:63)
      ... 10 more
      Caused by: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed.
      at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:888)
      at com.mysql.jdbc.Statement.checkClosed(Statement.java:380)
      at com.mysql.jdbc.PreparedStatement.setString(PreparedStatement.java:3374)
      at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:132)
      at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:132)
      at org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.doGetMessageCount(DefaultJDBCAdapter.java:700)
      at org.apache.activemq.store.jdbc.JDBCMessageStore.getMessageCount(JDBCMessageStore.java:192)
      ... 12 more

        Activity

        Hide
        Ed added a comment - - edited

        Hello,

        My environment:
        Activemq 5.9
        Debian 7.2
        Java 1.7_045
        Protocol openwire

        activemq.xml (part of it)
        ....
        <persistenceAdapter>
        <jdbcPersistenceAdapter dataDirectory="$

        {activemq.base}

        /activemq-data" dataSource="#mysql-ds"/>
        </persistenceAdapter>
        ......

        <transportConnectors>
        <!-- DOS protection, limit concurrent connections to 1000 and frame size to 100MB -->
        <transportConnector name="openwire" uri="tcp://0.0.0.0:61616?maximumConnections=1000&wireFormat.maxFrameSize=104857600"/>

        </transportConnectors>
        ......

        <bean id="mysql-ds" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
        <property name="driverClassName" value="com.mysql.jdbc.Driver"/>
        <property name="url" value="jdbc:mysql://localhost:3306/activemq?relaxAutoCommit=true"/>
        <property name="username" value="activemq"/>
        <property name="password" value="xyz"/>
        <property name="poolPreparedStatements" value="true"/>
        </bean>
        ......

        We work fine during the day, but when we start working next morning, we realize that the first message gets stuck with the following error (same as above post):

        2014-02-21 08:50:03,045 | WARN | JDBC Failure: No operations allowed after statement closed. | org.apache.activemq.store.jdbc.JDBCPersistenceAdapter | ActiveMQ Transport: tcp:///<IP ADDRESS>:60004@61616
        com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after statement closed.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
        at com.mysql.jdbc.Util.getInstance(Util.java:386)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1015)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:989)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:975)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:920)
        at com.mysql.jdbc.StatementImpl.checkClosed(StatementImpl.java:461)
        at com.mysql.jdbc.PreparedStatement.setString(PreparedStatement.java:4453)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:135)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:135)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:135)
        at org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.getStoreSequenceId(DefaultJDBCAdapter.java:291)
        at org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.getStoreSequenceIdForMessageId(JDBCPersistenceAdapter.java:840)
        at org.apache.activemq.store.jdbc.JDBCMessageStore.removeMessage(JDBCMessageStore.java:194)
        at org.apache.activemq.store.memory.MemoryTransactionStore$4.run(MemoryTransactionStore.java:348)
        at org.apache.activemq.store.jdbc.JdbcMemoryTransactionStore.prepare(JdbcMemoryTransactionStore.java:77)
        at org.apache.activemq.transaction.XATransaction.prepare(XATransaction.java:192)
        at org.apache.activemq.broker.TransactionBroker.prepareTransaction(TransactionBroker.java:248)
        at org.apache.activemq.broker.MutableBrokerFilter.prepareTransaction(MutableBrokerFilter.java:127)
        at org.apache.activemq.broker.TransportConnection.processPrepareTransaction(TransportConnection.java:405)
        at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:98)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:149)
        at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
        at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
        at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:270)
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
        at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
        at java.lang.Thread.run(Thread.java:744)
        2014-02-21 08:50:03,047 | WARN | Close failed: Already closed. | org.apache.activemq.store.jdbc.TransactionContext | ActiveMQ Transport: tcp:///<IP ADDRESS>:60004@61616
        java.sql.SQLException: Already closed.
        at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:114)
        at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:191)
        at org.apache.activemq.store.jdbc.TransactionContext.close(TransactionContext.java:147)
        at org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.getStoreSequenceIdForMessageId(JDBCPersistenceAdapter.java:845)
        at org.apache.activemq.store.jdbc.JDBCMessageStore.removeMessage(JDBCMessageStore.java:194)
        at org.apache.activemq.store.memory.MemoryTransactionStore$4.run(MemoryTransactionStore.java:348)
        at org.apache.activemq.store.jdbc.JdbcMemoryTransactionStore.prepare(JdbcMemoryTransactionStore.java:77)
        at org.apache.activemq.transaction.XATransaction.prepare(XATransaction.java:192)
        at org.apache.activemq.broker.TransactionBroker.prepareTransaction(TransactionBroker.java:248)
        at org.apache.activemq.broker.MutableBrokerFilter.prepareTransaction(MutableBrokerFilter.java:127)
        at org.apache.activemq.broker.TransportConnection.processPrepareTransaction(TransportConnection.java:405)
        at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:98)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:149)
        at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
        at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
        at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:270)
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
        at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
        at java.lang.Thread.run(Thread.java:744)

        Any workaround/resolution would be appreciated.

        Thanks in advance.

        Show
        Ed added a comment - - edited Hello, My environment: Activemq 5.9 Debian 7.2 Java 1.7_045 Protocol openwire activemq.xml (part of it) .... <persistenceAdapter> <jdbcPersistenceAdapter dataDirectory="$ {activemq.base} /activemq-data" dataSource="#mysql-ds"/> </persistenceAdapter> ...... <transportConnectors> <!-- DOS protection, limit concurrent connections to 1000 and frame size to 100MB --> <transportConnector name="openwire" uri="tcp://0.0.0.0:61616?maximumConnections=1000&wireFormat.maxFrameSize=104857600"/> </transportConnectors> ...... <bean id="mysql-ds" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close"> <property name="driverClassName" value="com.mysql.jdbc.Driver"/> <property name="url" value="jdbc:mysql://localhost:3306/activemq?relaxAutoCommit=true"/> <property name="username" value="activemq"/> <property name="password" value="xyz"/> <property name="poolPreparedStatements" value="true"/> </bean> ...... We work fine during the day, but when we start working next morning, we realize that the first message gets stuck with the following error (same as above post): 2014-02-21 08:50:03,045 | WARN | JDBC Failure: No operations allowed after statement closed. | org.apache.activemq.store.jdbc.JDBCPersistenceAdapter | ActiveMQ Transport: tcp:///<IP ADDRESS>:60004@61616 com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after statement closed. at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:526) at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) at com.mysql.jdbc.Util.getInstance(Util.java:386) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1015) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:989) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:975) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:920) at com.mysql.jdbc.StatementImpl.checkClosed(StatementImpl.java:461) at com.mysql.jdbc.PreparedStatement.setString(PreparedStatement.java:4453) at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:135) at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:135) at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:135) at org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.getStoreSequenceId(DefaultJDBCAdapter.java:291) at org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.getStoreSequenceIdForMessageId(JDBCPersistenceAdapter.java:840) at org.apache.activemq.store.jdbc.JDBCMessageStore.removeMessage(JDBCMessageStore.java:194) at org.apache.activemq.store.memory.MemoryTransactionStore$4.run(MemoryTransactionStore.java:348) at org.apache.activemq.store.jdbc.JdbcMemoryTransactionStore.prepare(JdbcMemoryTransactionStore.java:77) at org.apache.activemq.transaction.XATransaction.prepare(XATransaction.java:192) at org.apache.activemq.broker.TransactionBroker.prepareTransaction(TransactionBroker.java:248) at org.apache.activemq.broker.MutableBrokerFilter.prepareTransaction(MutableBrokerFilter.java:127) at org.apache.activemq.broker.TransportConnection.processPrepareTransaction(TransportConnection.java:405) at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:98) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:149) at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113) at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:270) at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214) at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196) at java.lang.Thread.run(Thread.java:744) 2014-02-21 08:50:03,047 | WARN | Close failed: Already closed. | org.apache.activemq.store.jdbc.TransactionContext | ActiveMQ Transport: tcp:///<IP ADDRESS>:60004@61616 java.sql.SQLException: Already closed. at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:114) at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:191) at org.apache.activemq.store.jdbc.TransactionContext.close(TransactionContext.java:147) at org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.getStoreSequenceIdForMessageId(JDBCPersistenceAdapter.java:845) at org.apache.activemq.store.jdbc.JDBCMessageStore.removeMessage(JDBCMessageStore.java:194) at org.apache.activemq.store.memory.MemoryTransactionStore$4.run(MemoryTransactionStore.java:348) at org.apache.activemq.store.jdbc.JdbcMemoryTransactionStore.prepare(JdbcMemoryTransactionStore.java:77) at org.apache.activemq.transaction.XATransaction.prepare(XATransaction.java:192) at org.apache.activemq.broker.TransactionBroker.prepareTransaction(TransactionBroker.java:248) at org.apache.activemq.broker.MutableBrokerFilter.prepareTransaction(MutableBrokerFilter.java:127) at org.apache.activemq.broker.TransportConnection.processPrepareTransaction(TransportConnection.java:405) at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:98) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:149) at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113) at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:270) at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214) at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196) at java.lang.Thread.run(Thread.java:744) Any workaround/resolution would be appreciated. Thanks in advance.
        Hide
        Marcelo Flores added a comment -

        So, this was a non resolved issue for activemq version 5.3, but fixed since 5.4, is that it?

        Show
        Marcelo Flores added a comment - So, this was a non resolved issue for activemq version 5.3, but fixed since 5.4, is that it?
        Hide
        Claus Ibsen added a comment -

        Connection pools or JDBC drivers sometime have functionality to re-connect and test connections to ensure they are valid before they are handed out to the client (= amq in this case).

        Show
        Claus Ibsen added a comment - Connection pools or JDBC drivers sometime have functionality to re-connect and test connections to ensure they are valid before they are handed out to the client (= amq in this case).
        Hide
        SuoNayi added a comment -

        You can disable poolPreparedStatements to avoid caching statements.
        Alternatively you can try the following configuration.

        <bean id="mysql-ds" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
        <property name="driverClassName" value="com.mysql.jdbc.Driver"/>
        <property name="url" value="jdbc:mysql://dbserver/activeMQ?relaxAutoCommit=true&autoReconnect=true"/>
        <property name="username" value="user"/>
        <property name="password" value="pass"/>
        <property name="maxActive" value="250"/>
        <property name="maxIdle" value="10"/>
        <property name="minIdle" value="5"/>
        <property name="testOnBorrow" value="true"/>
        <property name="validationQuery" value="select 1"/>
        <property name="poolPreparedStatements" value="true"/>
        <property name="maxOpenPreparedStatements" value="20"/>
        </bean>

        Show
        SuoNayi added a comment - You can disable poolPreparedStatements to avoid caching statements. Alternatively you can try the following configuration. <bean id="mysql-ds" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close"> <property name="driverClassName" value="com.mysql.jdbc.Driver"/> <property name="url" value="jdbc:mysql://dbserver/activeMQ?relaxAutoCommit=true&autoReconnect=true"/> <property name="username" value="user"/> <property name="password" value="pass"/> <property name="maxActive" value="250"/> <property name="maxIdle" value="10"/> <property name="minIdle" value="5"/> <property name="testOnBorrow" value="true"/> <property name="validationQuery" value="select 1"/> <property name="poolPreparedStatements" value="true"/> <property name="maxOpenPreparedStatements" value="20"/> </bean>
        Hide
        Lucio Tarantino added a comment -

        Hi,
        I'have the same error? Any news or workaround?
        It append sometimes on hight workload and the problem is that the processed message is duplicated.

        My environment is:
        1. ActiveMQ (apache-activemq-5.4.3) with mysql 5.0.77 as storage.

        This is my error trace:

        [12-29 23:28:14] ERROR org.mule.exception.DefaultSystemExceptionStrategy [ActiveMQ Session Task-6864]:
        ********************************************************************************
        Message : Transaction commit failed
        Type : org.mule.api.transaction.TransactionException
        Code : MULE_ERROR-90097
        JavaDoc : http://www.mulesoft.org/docs/site/current3/apidocs/org/mule/api/transaction/TransactionException.html
        JMS Code : null
        ********************************************************************************
        Exception stack is:
        1. com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed. (java.lang.Throwable)
        com.mysql.jdbc.SQLError:888 (null)
        2. Failed to get store sequenceId for messageId: ID:cordoba.jakala.com-52552-1324648464349-0:1:8306:1:1, on: queue://enel.sap.esiti. Reason: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed. (java.io.IOException)
        org.apache.activemq.util.IOExceptionSupport:33 (null)
        3. STORE COMMIT FAILED: Transaction rolled back. (javax.transaction.xa.XAException)
        org.apache.activemq.transaction.LocalTransaction:77 (http://java.sun.com/j2ee/sdk_1.3/techdocs/api/javax/transaction/xa/XAException.html)
        4. STORE COMMIT FAILED: Transaction rolled back.(JMS Code: null) (javax.jms.JMSException)
        org.apache.activemq.util.JMSExceptionSupport:49 (http://java.sun.com/j2ee/sdk_1.3/techdocs/api/javax/jms/JMSException.html)
        5. Transaction commit failed (org.mule.api.transaction.TransactionException)
        org.mule.transport.jms.JmsTransaction:80 (http://www.mulesoft.org/docs/site/current3/apidocs/org/mule/api/transaction/TransactionException.html)
        ********************************************************************************
        Root Exception stack trace:
        java.lang.Throwable: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed.
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:888)
        at com.mysql.jdbc.Statement.checkClosed(Statement.java:385)
        at com.mysql.jdbc.PreparedStatement.setString(PreparedStatement.java:3455)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:132)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:132)
        at org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.getStoreSequenceId(DefaultJDBCAdapter.java:272)
        at org.apache.activemq.store.jdbc.JDBCMessageStore.getStoreSequenceIdForMessageId(JDBCMessageStore.java:293)
        at org.apache.activemq.store.jdbc.JDBCMessageStore.removeMessage(JDBCMessageStore.java:148)
        at org.apache.activemq.store.memory.MemoryTransactionStore$4.run(MemoryTransactionStore.java:302)
        at org.apache.activemq.store.memory.MemoryTransactionStore$Tx.commit(MemoryTransactionStore.java:102)
        at org.apache.activemq.store.memory.MemoryTransactionStore.commit(MemoryTransactionStore.java:222)
        at org.apache.activemq.transaction.LocalTransaction.commit(LocalTransaction.java:72)
        at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:173)
        at org.apache.activemq.broker.MutableBrokerFilter.commitTransaction(MutableBrokerFilter.java:103)
        at org.apache.activemq.broker.TransportConnection.processCommitTransactionOnePhase(TransportConnection.java:424)
        at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:100)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:311)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:185)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69)
        at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
        at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:228)
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
        at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:220)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:202)
        at java.lang.Thread.run(Thread.java:662)

        ********************************************************************************

        [12-29 23:28:14] ERROR org.mule.transport.jms.MultiConsumerJmsMessageReceiver [ActiveMQ Session Task-6864]: javax.jms.IllegalStateException: This session is transacted

        Show
        Lucio Tarantino added a comment - Hi, I'have the same error? Any news or workaround? It append sometimes on hight workload and the problem is that the processed message is duplicated. My environment is: 1. ActiveMQ (apache-activemq-5.4.3) with mysql 5.0.77 as storage. This is my error trace: [12-29 23:28:14] ERROR org.mule.exception.DefaultSystemExceptionStrategy [ActiveMQ Session Task-6864] : ******************************************************************************** Message : Transaction commit failed Type : org.mule.api.transaction.TransactionException Code : MULE_ERROR-90097 JavaDoc : http://www.mulesoft.org/docs/site/current3/apidocs/org/mule/api/transaction/TransactionException.html JMS Code : null ******************************************************************************** Exception stack is: 1. com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed. (java.lang.Throwable) com.mysql.jdbc.SQLError:888 (null) 2. Failed to get store sequenceId for messageId: ID:cordoba.jakala.com-52552-1324648464349-0:1:8306:1:1, on: queue://enel.sap.esiti. Reason: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed. (java.io.IOException) org.apache.activemq.util.IOExceptionSupport:33 (null) 3. STORE COMMIT FAILED: Transaction rolled back. (javax.transaction.xa.XAException) org.apache.activemq.transaction.LocalTransaction:77 ( http://java.sun.com/j2ee/sdk_1.3/techdocs/api/javax/transaction/xa/XAException.html ) 4. STORE COMMIT FAILED: Transaction rolled back.(JMS Code: null) (javax.jms.JMSException) org.apache.activemq.util.JMSExceptionSupport:49 ( http://java.sun.com/j2ee/sdk_1.3/techdocs/api/javax/jms/JMSException.html ) 5. Transaction commit failed (org.mule.api.transaction.TransactionException) org.mule.transport.jms.JmsTransaction:80 ( http://www.mulesoft.org/docs/site/current3/apidocs/org/mule/api/transaction/TransactionException.html ) ******************************************************************************** Root Exception stack trace: java.lang.Throwable: com.mysql.jdbc.exceptions.MySQLNonTransientConnectionException: No operations allowed after statement closed. at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:888) at com.mysql.jdbc.Statement.checkClosed(Statement.java:385) at com.mysql.jdbc.PreparedStatement.setString(PreparedStatement.java:3455) at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:132) at org.apache.commons.dbcp.DelegatingPreparedStatement.setString(DelegatingPreparedStatement.java:132) at org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.getStoreSequenceId(DefaultJDBCAdapter.java:272) at org.apache.activemq.store.jdbc.JDBCMessageStore.getStoreSequenceIdForMessageId(JDBCMessageStore.java:293) at org.apache.activemq.store.jdbc.JDBCMessageStore.removeMessage(JDBCMessageStore.java:148) at org.apache.activemq.store.memory.MemoryTransactionStore$4.run(MemoryTransactionStore.java:302) at org.apache.activemq.store.memory.MemoryTransactionStore$Tx.commit(MemoryTransactionStore.java:102) at org.apache.activemq.store.memory.MemoryTransactionStore.commit(MemoryTransactionStore.java:222) at org.apache.activemq.transaction.LocalTransaction.commit(LocalTransaction.java:72) at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:173) at org.apache.activemq.broker.MutableBrokerFilter.commitTransaction(MutableBrokerFilter.java:103) at org.apache.activemq.broker.TransportConnection.processCommitTransactionOnePhase(TransportConnection.java:424) at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:100) at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:311) at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:185) at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:69) at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113) at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:228) at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:220) at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:202) at java.lang.Thread.run(Thread.java:662) ******************************************************************************** [12-29 23:28:14] ERROR org.mule.transport.jms.MultiConsumerJmsMessageReceiver [ActiveMQ Session Task-6864] : javax.jms.IllegalStateException: This session is transacted
        Hide
        Emiliano Mettini added a comment -

        Exactly the same problem with same configuration.

        I also figured that if I increase maxActive connections the problems rarely appear .. but that's not an scalable workaround ..

        Show
        Emiliano Mettini added a comment - Exactly the same problem with same configuration. I also figured that if I increase maxActive connections the problems rarely appear .. but that's not an scalable workaround ..

          People

          • Assignee:
            Unassigned
            Reporter:
            Marshall Pierce
          • Votes:
            8 Vote for this issue
            Watchers:
            12 Start watching this issue

            Dates

            • Created:
              Updated:

              Development