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

          People

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

            Dates

            • Created:
              Updated:

              Development