activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Ed (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (AMQ-2534) Broker gets stuck with an error about using a closed JDBC statement
Date Fri, 21 Feb 2014 16:10:31 GMT

    [ https://issues.apache.org/jira/browse/AMQ-2534?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13908460#comment-13908460
] 

Ed commented on AMQ-2534:
-------------------------

Hello,

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

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.


> Broker gets stuck with an error about using a closed JDBC statement
> -------------------------------------------------------------------
>
>                 Key: AMQ-2534
>                 URL: https://issues.apache.org/jira/browse/AMQ-2534
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Message Store
>    Affects Versions: 5.3.0
>         Environment: Linux
> Sun JDK 6, several different update versions
> Mysql
>            Reporter: Marshall Pierce
>             Fix For: 5.x
>
>
> 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&amp;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



--
This message was sent by Atlassian JIRA
(v6.1.5#6160)

Mime
View raw message