Alex Rudyy created QPID-6776:
--------------------------------
Summary: [Java Client] Timeout on connection close might cause NPE
being thrown on receiving of message from a broker for closed session
Key: QPID-6776
URL: https://issues.apache.org/jira/browse/QPID-6776
Project: Qpid
Issue Type: Bug
Components: Java Client
Affects Versions: qpid-java-6.0
Reporter: Alex Rudyy
The issue occurred when broker was running under stress (heap memory was
consumed by messages and new connections were repeatedly open/closed). Broker
was performing Full GC multiple times in a row:
As result, client failed to receive session close response in time. Thus,
timeout is not surprising. NPE followed timeout should not occur.
Here are the client logs for the issue:
{noformat}
2015-10-06 15:47:33,962 ERROR [main] o.a.q.c.AMQConnection Error
closing session: javax.jms.JMSException: Error closing session:
org.apache.qpid.AMQTimeoutException: Server did not respond in a timely fashion
[error code 408: Request Timeout]
2015-10-06 15:47:33,969 ERROR [main] o.a.q.c.AMQConnection Error
closing connection
javax.jms.JMSException: Error closing session:
org.apache.qpid.AMQTimeoutException: Server did not respond in a timely fashion
[error code 408: Request Timeout]
at org.apache.qpid.client.AMQSession.close(AMQSession.java:770)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at org.apache.qpid.client.AMQSession.close(AMQSession.java:732)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQConnection.closeAllSessions(AMQConnection.java:1186)
[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:1113)
[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:1098)
[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:1081)
[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:1062)
[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.tools.StressTestClient.runTest(StressTestClient.java:374)
[qpid-tools-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.tools.StressTestClient.main(StressTestClient.java:122)
[qpid-tools-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
Caused by: org.apache.qpid.AMQTimeoutException: Server did not respond in a
timely fashion
at
org.apache.qpid.client.util.BlockingWaiter.block(BlockingWaiter.java:170)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.protocol.BlockingMethodFrameListener.blockForFrame(BlockingMethodFrameListener.java:115)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQProtocolHandler.writeCommandFrameAndWaitForReply(AMQProtocolHandler.java:685)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQProtocolHandler.syncWrite(AMQProtocolHandler.java:706)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQSession_0_8.sendClose(AMQSession_0_8.java:249)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at org.apache.qpid.client.AMQSession.close(AMQSession.java:764)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
... 8 common frames omitted
2015-10-06 15:47:34,038 ERROR [IoRcvr-localhost/127.0.0.1:5672]
o.a.q.c.AMQProtocolHandler Exception processing frame
java.lang.NullPointerException: null
at
org.apache.qpid.client.protocol.AMQProtocolSession.deliverMessageToAMQSession(AMQProtocolSession.java:298)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.protocol.AMQProtocolSession.contentBodyReceived(AMQProtocolSession.java:280)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at org.apache.qpid.framing.ContentBody.handle(ContentBody.java:71)
~[qpid-common-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQProtocolHandler.received(AMQProtocolHandler.java:477)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQConnectionDelegate_8_0$ReceiverClosedWaiter.received(AMQConnectionDelegate_8_0.java:544)
[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:162)
[qpid-common-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at java.lang.Thread.run(Thread.java:745) [na:1.7.0_67]
2015-10-06 15:47:34,039 WARN [main] o.a.q.c.AMQConnection Error
closing underlying protocol connection
org.apache.qpid.QpidException: Woken up due to class
java.lang.NullPointerException
at
org.apache.qpid.client.util.BlockingWaiter.block(BlockingWaiter.java:195)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.protocol.BlockingMethodFrameListener.blockForFrame(BlockingMethodFrameListener.java:115)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQProtocolHandler.writeCommandFrameAndWaitForReply(AMQProtocolHandler.java:685)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQProtocolHandler.syncWrite(AMQProtocolHandler.java:706)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQProtocolHandler.closeConnection(AMQProtocolHandler.java:740)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQConnectionDelegate_8_0.closeConnection(AMQConnectionDelegate_8_0.java:85)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:1129)
[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQConnection.doClose(AMQConnection.java:1098)
[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:1081)
[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at org.apache.qpid.client.AMQConnection.close(AMQConnection.java:1062)
[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.tools.StressTestClient.runTest(StressTestClient.java:374)
[qpid-tools-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.tools.StressTestClient.main(StressTestClient.java:122)
[qpid-tools-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
Caused by: java.lang.NullPointerException: null
at
org.apache.qpid.client.protocol.AMQProtocolSession.deliverMessageToAMQSession(AMQProtocolSession.java:298)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.protocol.AMQProtocolSession.contentBodyReceived(AMQProtocolSession.java:280)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at org.apache.qpid.framing.ContentBody.handle(ContentBody.java:71)
~[qpid-common-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQProtocolHandler.received(AMQProtocolHandler.java:477)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQConnectionDelegate_8_0$ReceiverClosedWaiter.received(AMQConnectionDelegate_8_0.java:544)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:162)
~[qpid-common-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at java.lang.Thread.run(Thread.java:745) ~[na:1.7.0_67]
2015-10-06 15:47:34,055 ERROR [IoRcvr-localhost/127.0.0.1:5672]
o.a.q.c.AMQProtocolHandler Exception processing frame
java.lang.UnsupportedOperationException: null
at java.util.AbstractList.add(AbstractList.java:148) ~[na:1.7.0_67]
at java.util.AbstractList.add(AbstractList.java:108) ~[na:1.7.0_67]
at
org.apache.qpid.client.message.UnprocessedMessage_0_8.receiveBody(UnprocessedMessage_0_8.java:109)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.protocol.AMQProtocolSession.contentBodyReceived(AMQProtocolSession.java:276)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at org.apache.qpid.framing.ContentBody.handle(ContentBody.java:71)
~[qpid-common-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQProtocolHandler.received(AMQProtocolHandler.java:477)
~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.client.AMQConnectionDelegate_8_0$ReceiverClosedWaiter.received(AMQConnectionDelegate_8_0.java:544)
[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at
org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:162)
[qpid-common-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
at java.lang.Thread.run(Thread.java:745) [na:1.7.0_67]
{noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
