You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by jliezers <jo...@metoffice.gov.uk> on 2013/02/12 11:20:26 UTC
Successfully delivered message ends up on DLQ
Hi,
I'm running ActiveMQ version 5.6.0 on linux.
Very occasionaly a message ends up on a DLQ even though consumer logs give
every indication that the message has been successfully delivered and
processed.
The consumer Spring jms listener acknowledge attribute is set to "client"
I can't find any errors or warnings logged that relate directly to these DLQ
events but I have found a few JDBC warnings in the log.
Here's an example.
WARN o.a.a.s.jdbc.JDBCPersistenceAdapter - JDBC Failure: Io exception:
Connection reset java.sql.SQLRecoverableException: Io exception: Connection
reset
at
oracle.jdbc.driver.SQLStateMapping.newSQLException(SQLStateMapping.java:101)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.DatabaseError.newSQLException(DatabaseError.java:133)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:199)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBCDriver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:263)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBCDriver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:521)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBCDriver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:969)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:897)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1186)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3387)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3431)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery(OraclePreparedStatementWrapper.java:1491)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
~[commons-dbcp-1.4.jar:1.4]
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
~[commons-dbcp-1.4.jar:1.4]
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
~[commons-dbcp-1.4.jar:1.4]
at
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.getStoreSequenceId(DefaultJDBCAdapter.java:278)
~[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.store.jdbc.JDBCMessageStore.getStoreSequenceIdForMessageId(JDBCMessageStore.java:335)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.store.jdbc.JDBCMessageStore.removeMessage(JDBCMessageStore.java:190)
[activemq-core-5.6.0.jar:5.6.0]
Could a JDBC exception be forcing a message onto the DLQ after delivery has
been acknowledged?
Thanks,
John
--
View this message in context: http://activemq.2283324.n4.nabble.com/Successfully-delivered-message-ends-up-on-DLQ-tp4663232.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re:Re: Successfully delivered message ends up on DLQ
Posted by SuoNayi <su...@163.com>.
Hi,slave shoud continue trying to require the database row lock every x ms, here default value for x is 1000ms.
Every try it just obtains a jdbc connection and close it finally, so it won't consumes many connections(sessions in the database).
If there is connection leak problem then slave will consume many sessions(connects) to require the row lock.
There are some relative jiras:
https://issues.apache.org/jira/browse/AMQ-3654
https://issues.apache.org/jira/browse/AMQ-3681
At 2013-02-13 19:01:04,jliezers <jo...@metoffice.gov.uk> wrote:
>I now believe the root cause is an our enthusiastic slave activemq consuming
>sessions attempting to acquire the lock on the ACTIVEMQ_LOCK table. We have
>a large number (100+) of unexpected sessions issuing UPDATE LOCK queries and
>then waiting. These are probably triggering the underlying connection resets
>as the max active sessions is only set to 200.
>
>
>
>--
>View this message in context: http://activemq.2283324.n4.nabble.com/Successfully-delivered-message-ends-up-on-DLQ-tp4663232p4663321.html
>Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Re:Re: Successfully delivered message ends up on DLQ
Posted by jliezers <jo...@metoffice.gov.uk>.
>From the console the DLQ message 'Redelivered' flag is set false
--
View this message in context: http://activemq.2283324.n4.nabble.com/Successfully-delivered-message-ends-up-on-DLQ-tp4663232p4664184.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Re:Re: Successfully delivered message ends up on DLQ
Posted by jliezers <jo...@metoffice.gov.uk>.
In one example I checked the DLQ message sent at 03:30 was not redelievered
and it had not expired, it had expiry set to 06:30.
The only significant ActiveMQ log entry at that time is the JDBC connection
failure logged during the ACK processing for this message.
--
View this message in context: http://activemq.2283324.n4.nabble.com/Successfully-delivered-message-ends-up-on-DLQ-tp4663232p4664185.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re:Re: Successfully delivered message ends up on DLQ
Posted by SuoNayi <su...@163.com>.
Just want to know the root cause about this and after digging the source code I find even if a message ack is processed unsuccessfully by broker the message is not moved to the dql directly.Does I miss something?AFAIK,A message can only be moved to the dql if it's expired,or it's redelivered and exceeds the max redelivery counter.So I'm very strange about your experience.Is the message in the dlq redelivered?Do you change the default redelivery policy?you can see the properties of the message in the dql via web console.
At 2013-02-13 19:01:04,jliezers <jo...@metoffice.gov.uk> wrote:
>I now believe the root cause is an our enthusiastic slave activemq consuming
>sessions attempting to acquire the lock on the ACTIVEMQ_LOCK table. We have
>a large number (100+) of unexpected sessions issuing UPDATE LOCK queries and
>then waiting. These are probably triggering the underlying connection resets
>as the max active sessions is only set to 200.
>
>
>
>--
>View this message in context: http://activemq.2283324.n4.nabble.com/Successfully-delivered-message-ends-up-on-DLQ-tp4663232p4663321.html
>Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re:Re: Successfully delivered message ends up on DLQ
Posted by SuoNayi <su...@163.com>.
Just want to know the root cause about this and after digging the source code I find
even if a message ack is processed unsuccessfully by broker the consumer will not
know that.So I'm very strange about your experience.Is the message in the dlq redelivered?
you can see the properties of the message in the dql via web console.
Do you change the default redelivery policy?
At 2013-02-13 19:01:04,jliezers <jo...@metoffice.gov.uk> wrote:
>I now believe the root cause is an our enthusiastic slave activemq consuming
>sessions attempting to acquire the lock on the ACTIVEMQ_LOCK table. We have
>a large number (100+) of unexpected sessions issuing UPDATE LOCK queries and
>then waiting. These are probably triggering the underlying connection resets
>as the max active sessions is only set to 200.
>
>
>
>--
>View this message in context: http://activemq.2283324.n4.nabble.com/Successfully-delivered-message-ends-up-on-DLQ-tp4663232p4663321.html
>Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Successfully delivered message ends up on DLQ
Posted by jliezers <jo...@metoffice.gov.uk>.
I now believe the root cause is an our enthusiastic slave activemq consuming
sessions attempting to acquire the lock on the ACTIVEMQ_LOCK table. We have
a large number (100+) of unexpected sessions issuing UPDATE LOCK queries and
then waiting. These are probably triggering the underlying connection resets
as the max active sessions is only set to 200.
--
View this message in context: http://activemq.2283324.n4.nabble.com/Successfully-delivered-message-ends-up-on-DLQ-tp4663232p4663321.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Successfully delivered message ends up on DLQ
Posted by jliezers <jo...@metoffice.gov.uk>.
I've had one new DLQ occurrence in the last 24 hours, again the message was
consumed successfully and acknowledged.
This time I have been able to tie the JDBC failure directly to the DLQ
message event using the time and more importantly the message id in the
stack trace.
While handling the Ack the JDBC failure results in the message being put
onto the DLQ.
The root cause is a JDBC/database issue and not an ActiveMQ problem, when
this is resolved the problem should go away.
I'm not qualified to say whether ActiveMQ should be creating a DLQ entry in
response to this exception.
19:30:01.131 [MessageService] x.x.x.x. [ActiveMQ Transport:
tcp:///x.x.x.x:50668] WARN o.a.a.s.jdbc.JDBCPersistenceAdapter - JDBC
Failure: Io exception: Connection reset java.sql.SQLRecoverableException: Io
exception: Connection reset
at
oracle.jdbc.driver.SQLStateMapping.newSQLException(SQLStateMapping.java:101)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.DatabaseError.newSQLException(DatabaseError.java:133)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:199)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBCDriver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:263)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBCDriver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:521)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBCDriver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:969)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:897)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1186)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3387)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3431)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery(OraclePreparedStatementWrapper.java:1491)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
~[commons-dbcp-1.4.jar:1.4]
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
~[commons-dbcp-1.4.jar:1.4]
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
~[commons-dbcp-1.4.jar:1.4]
at
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.getStoreSequenceId(DefaultJDBCAdapter.java:278)
~[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.store.jdbc.JDBCMessageStore.getStoreSequenceIdForMessageId(JDBCMessageStore.java:335)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.store.jdbc.JDBCMessageStore.removeMessage(JDBCMessageStore.java:190)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.store.memory.MemoryTransactionStore.removeMessage(MemoryTransactionStore.java:332)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.store.memory.MemoryTransactionStore$1.removeAsyncMessage(MemoryTransactionStore.java:161)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.region.Queue.acknowledge(Queue.java:850)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.region.Queue.removeMessage(Queue.java:1604)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.region.QueueSubscription.acknowledge(QueueSubscription.java:59)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:225)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:427)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:529)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:276)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:87)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:461)
[activemq-core-5.6.0.jar:5.6.0]
at org.apache.activemq.command.MessageAck.visit(MessageAck.java:236)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:150)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:229)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:222)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:204)
[activemq-core-5.6.0.jar:5.6.0]
at java.lang.Thread.run(Thread.java:619) [na:1.6.0_21]
Caused by: java.net.SocketException: Connection reset
at
java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:96)
~[na:1.6.0_21]
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
~[na:1.6.0_21]
at oracle.net.ns.DataPacket.send(DataPacket.java:150)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at oracle.net.ns.NetOutputStream.flush(NetOutputStream.java:180)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:169)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driverversion -
"11.1.0.7.0-Production"]
at oracle.net.ns.NetInputStream.read(NetInputStream.java:117)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at oracle.net.ns.NetInputStream.read(NetInputStream.java:92)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version
-"11.1.0.7.0-Production"]
at oracle.net.ns.NetInputStream.read(NetInputStream.java:77)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version
-"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1034)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1010)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:588)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:194)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
at
oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:953)
~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
"11.1.0.7.0-Production"]
... 35 common frames omitted
19:30:01.132 [MessageService] x.x.x.x [ActiveMQ Transport:
tcp:///x.x.x.x:50668] WARN o.a.a.store.jdbc.TransactionContext - Close
failed: Already closed. java.sql.SQLException: Already closed.
at
org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:114)
~[commons-dbcp-1.4.jar:1.4]
at
org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:191)
~[commons-dbcp-1.4.jar:1.4]
at
org.apache.activemq.store.jdbc.TransactionContext.close(TransactionContext.java:142)
~[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.store.jdbc.JDBCMessageStore.getStoreSequenceIdForMessageId(JDBCMessageStore.java:340)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.store.jdbc.JDBCMessageStore.removeMessage(JDBCMessageStore.java:190)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.store.memory.MemoryTransactionStore.removeMessage(MemoryTransactionStore.java:332)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.store.memory.MemoryTransactionStore$1.removeAsyncMessage(MemoryTransactionStore.java:161)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.region.Queue.acknowledge(Queue.java:850)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.region.Queue.removeMessage(Queue.java:1604)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.region.QueueSubscription.acknowledge(QueueSubscription.java:59)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:225)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:427)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:529)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:276)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:87)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:461)
[activemq-core-5.6.0.jar:5.6.0]
at org.apache.activemq.command.MessageAck.visit(MessageAck.java:236)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:150)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:229)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:222)
[activemq-core-5.6.0.jar:5.6.0]
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:204)
[activemq-core-5.6.0.jar:5.6.0]
at java.lang.Thread.run(Thread.java:619) [na:1.6.0_21]
19:30:01.132 [MessageService] x.x.x.x [ActiveMQ Transport:
tcp:///x.x.x.x:50668] WARN o.a.a.b.T.Transport -
Transport Connection to: tcp://x.x.x.x:50668 failed: java.io.IOException:
Failed to get store sequenceId for messageId:
ID:server.x.x.x-48625-1360250400164-0:1832:1:1:2, on: queue://MyQueue.
Reason: java.sql.SQLRecoverableException: Io exception: Connection reset
--
View this message in context: http://activemq.2283324.n4.nabble.com/Successfully-delivered-message-ends-up-on-DLQ-tp4663232p4663320.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Successfully delivered message ends up on DLQ
Posted by jliezers <jo...@metoffice.gov.uk>.
No luck reproducing the error in a test environment yet but if I can
reproduce this with a test case I will raise a JIRA as requested.
--
View this message in context: http://activemq.2283324.n4.nabble.com/Successfully-delivered-message-ends-up-on-DLQ-tp4663232p4663319.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Successfully delivered message ends up on DLQ
Posted by Christian Posta <ch...@gmail.com>.
Tough to say without a test case, but just by looking at the exception
handling, maybe it can happen. Can you open a JIRA and attach a test that
reproduces this?
On Tue, Feb 12, 2013 at 3:20 AM, jliezers <jo...@metoffice.gov.uk>wrote:
> Hi,
>
> I'm running ActiveMQ version 5.6.0 on linux.
>
> Very occasionaly a message ends up on a DLQ even though consumer logs give
> every indication that the message has been successfully delivered and
> processed.
>
> The consumer Spring jms listener acknowledge attribute is set to "client"
>
> I can't find any errors or warnings logged that relate directly to these
> DLQ
> events but I have found a few JDBC warnings in the log.
>
> Here's an example.
>
> WARN o.a.a.s.jdbc.JDBCPersistenceAdapter - JDBC Failure: Io exception:
> Connection reset java.sql.SQLRecoverableException: Io exception: Connection
> reset
> at
>
> oracle.jdbc.driver.SQLStateMapping.newSQLException(SQLStateMapping.java:101)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
> oracle.jdbc.driver.DatabaseError.newSQLException(DatabaseError.java:133)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
> oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:199)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBCDriver version -
> "11.1.0.7.0-Production"]
> at
> oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:263)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBCDriver version -
> "11.1.0.7.0-Production"]
> at
> oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:521)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBCDriver version -
> "11.1.0.7.0-Production"]
> at
>
> oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:969)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
>
> oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:897)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
>
> oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1186)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
>
> oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3387)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
>
> oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3431)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
>
> oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery(OraclePreparedStatementWrapper.java:1491)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
>
> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> ~[commons-dbcp-1.4.jar:1.4]
> at
>
> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> ~[commons-dbcp-1.4.jar:1.4]
> at
>
> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> ~[commons-dbcp-1.4.jar:1.4]
> at
>
> org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.getStoreSequenceId(DefaultJDBCAdapter.java:278)
> ~[activemq-core-5.6.0.jar:5.6.0]
> at
>
> org.apache.activemq.store.jdbc.JDBCMessageStore.getStoreSequenceIdForMessageId(JDBCMessageStore.java:335)
> [activemq-core-5.6.0.jar:5.6.0]
> at
>
> org.apache.activemq.store.jdbc.JDBCMessageStore.removeMessage(JDBCMessageStore.java:190)
> [activemq-core-5.6.0.jar:5.6.0]
>
> Could a JDBC exception be forcing a message onto the DLQ after delivery has
> been acknowledged?
>
> Thanks,
>
> John
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/Successfully-delivered-message-ends-up-on-DLQ-tp4663232.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
--
*Christian Posta*
http://www.christianposta.com/blog
twitter: @christianposta
Re: Successfully delivered message ends up on DLQ
Posted by jliezers <jo...@metoffice.gov.uk>.
Not using transacted consumers, the dlqDeliveryFailureCause is null
--
View this message in context: http://activemq.2283324.n4.nabble.com/Successfully-delivered-message-ends-up-on-DLQ-tp4663232p4663318.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Re: Successfully delivered message ends up on DLQ
Posted by Gary Tully <ga...@gmail.com>.
if you are using transacted consumers it can happen if you get a duplicate
deliver after a failover. but in that case there should be a string
property called dlqDeliveryFailureCause on the message in the dlq
On 12 February 2013 10:20, jliezers <jo...@metoffice.gov.uk> wrote:
> Hi,
>
> I'm running ActiveMQ version 5.6.0 on linux.
>
> Very occasionaly a message ends up on a DLQ even though consumer logs give
> every indication that the message has been successfully delivered and
> processed.
>
> The consumer Spring jms listener acknowledge attribute is set to "client"
>
> I can't find any errors or warnings logged that relate directly to these
> DLQ
> events but I have found a few JDBC warnings in the log.
>
> Here's an example.
>
> WARN o.a.a.s.jdbc.JDBCPersistenceAdapter - JDBC Failure: Io exception:
> Connection reset java.sql.SQLRecoverableException: Io exception: Connection
> reset
> at
>
> oracle.jdbc.driver.SQLStateMapping.newSQLException(SQLStateMapping.java:101)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
> oracle.jdbc.driver.DatabaseError.newSQLException(DatabaseError.java:133)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
> oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:199)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBCDriver version -
> "11.1.0.7.0-Production"]
> at
> oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:263)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBCDriver version -
> "11.1.0.7.0-Production"]
> at
> oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:521)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBCDriver version -
> "11.1.0.7.0-Production"]
> at
>
> oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:969)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
>
> oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:897)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
>
> oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1186)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
>
> oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3387)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
>
> oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3431)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
>
> oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery(OraclePreparedStatementWrapper.java:1491)
> ~[ojdbc6-11.1.0.7.0-Production.jar:Oracle JDBC Driver version -
> "11.1.0.7.0-Production"]
> at
>
> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> ~[commons-dbcp-1.4.jar:1.4]
> at
>
> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> ~[commons-dbcp-1.4.jar:1.4]
> at
>
> org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> ~[commons-dbcp-1.4.jar:1.4]
> at
>
> org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.getStoreSequenceId(DefaultJDBCAdapter.java:278)
> ~[activemq-core-5.6.0.jar:5.6.0]
> at
>
> org.apache.activemq.store.jdbc.JDBCMessageStore.getStoreSequenceIdForMessageId(JDBCMessageStore.java:335)
> [activemq-core-5.6.0.jar:5.6.0]
> at
>
> org.apache.activemq.store.jdbc.JDBCMessageStore.removeMessage(JDBCMessageStore.java:190)
> [activemq-core-5.6.0.jar:5.6.0]
>
> Could a JDBC exception be forcing a message onto the DLQ after delivery has
> been acknowledged?
>
> Thanks,
>
> John
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/Successfully-delivered-message-ends-up-on-DLQ-tp4663232.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
--
http://redhat.com
http://blog.garytully.com