You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Tom Purcell (JIRA)" <ji...@apache.org> on 2011/02/21 19:59:39 UTC

[jira] Commented: (AMQ-1376) Improperly closed connections preventing message redelivery

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

Tom Purcell commented on AMQ-1376:
----------------------------------

We have been in production with a ruby on rails app using Stomp to put messages in queues in AMQ 5.3.0 for 6 months. We never saw these messages. We are now in the process of testing an upgrade to AMQ 5.4.2 and we started to get the following:
2011-02-21 13:13:23,464 | DEBUG | Transport failed: java.io.EOFException | org.apache.activemq.broker.TransportConnection.Transport | ActiveMQ Transport: tcp:///172.20.10.127:43880
java.io.EOFException
        at java.io.DataInputStream.readByte(DataInputStream.java:250)
        at org.apache.activemq.transport.stomp.StompWireFormat.readLine(StompWireFormat.java:146)
        at org.apache.activemq.transport.stomp.StompWireFormat.parseAction(StompWireFormat.java:162)
        at org.apache.activemq.transport.stomp.StompWireFormat.unmarshal(StompWireFormat.java:92)
        at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:227)
        at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:219)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:202)
        at java.lang.Thread.run(Thread.java:619)
2011-02-21 13:13:23,470 | DEBUG | Stopping connection: /172.20.10.127:43880 | org.apache.activemq.broker.TransportConnection | ActiveMQ Task
2011-02-21 13:13:23,470 | DEBUG | Stopping transport tcp:///172.20.10.127:43880 | org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ Task
2011-02-21 13:13:23,477 | DEBUG | Stopped transport: /172.20.10.127:43880 | org.apache.activemq.broker.TransportConnection | ActiveMQ Task

The only change in the environment is the AMQ upgrade.

In our testing we are pushing load and not seeing any lost messages. I have seen comments like this in various places (http://activemq.2283324.n4.nabble.com/Continuous-Transport-Failures-Moments-Before-STOMP-Connections-Close-tp2952079p2953913.html):

this log just indicate that connection is lost, it's no indication of
an error. We recently raised the level of these messages to catch some
other situations, so they now shows with the INFO level in standard
logs

This sounds reasonable but Can I really just ignore this? At any rate it looks like the issue still exists.


> Improperly closed connections preventing message redelivery
> -----------------------------------------------------------
>
>                 Key: AMQ-1376
>                 URL: https://issues.apache.org/jira/browse/AMQ-1376
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Transport
>    Affects Versions: 5.0.0
>            Reporter: Jacob Burkhart
>            Assignee: Hiram Chirino
>             Fix For: AGING_TO_DIE
>
>
> This is a reproducible case of a DEAD Consumer that never gets cleaned up.
> I am using telnet to manually test STOMP message consumption.
> First I put a message into the queue
> I then connect and subscribe to that queue and get the message:
> CONNECT
> login: test
> passcode: test
> ^@
> CONNECTED
> session:ID:jacob-64807-1188509209664-4:3
> SUBSCRIBE
> destination: /queue/Prescriptions
> ack: client
> ^@
> This works and I receive the queued messages.
> They remain in the Q because I am not send ACK
> If I use the DISCONNECT command. I am properly disconnected and I can repeat this process to get the same message again. Good.
> If I disconnect by killing the telnet process I see the following stack trace in MQ. AND I can still repeat the same process of re-retrieving the un-acknowledged messages:
> 	DEBUG Transport                      - Transport failed: java.io.EOFException
> 	java.io.EOFException
> 	        at java.io.DataInputStream.readByte(DataInputStream.java:243)
> 	        at org.apache.activemq.transport.stomp.StompWireFormat.readLine(StompWireFormat.java:186)
> 	        at org.apache.activemq.transport.stomp.StompWireFormat.unmarshal(StompWireFormat.java:94)
> 	        at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:196)
> 	        at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:188)
> 	        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:176)
> 	        at java.lang.Thread.run(Thread.java:613)
> 	DEBUG TransportConnection            - Stopping connection: /XXXXXXXXXXXXXX:4880
> 	DEBUG TcpTransport                   - Stopping transport tcp:///XXXXXXXXXXXXXX:4880
> 	DEBUG TransportConnection            - Stopped connection: /XXXXXXXXXXXXXX:4880
> 	DEBUG TransportConnection            - Cleaning up connection resources: /XXXXXXXXXXXXXX:4880
> 	DEBUG AMQPersistenceAdapter          - Checkpoint started.
> 	DEBUG AMQPersistenceAdapter          - Checkpoint done.
> HOWEVER,
> If I disconnect by repeatedly typing Control-C to close the telnet program I see the following stack trace:
> 	DEBUG Transport                      - Transport failed: org.apache.activemq.transport.stomp.ProtocolException: Unable to parser header line [????????????]
> 	org.apache.activemq.transport.stomp.ProtocolException: Unable to parser header line [????????????]
> 	        at org.apache.activemq.transport.stomp.StompWireFormat.unmarshal(StompWireFormat.java:121)
> 	        at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:196)
> 	        at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:188)
> 	        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:176)
> 	        at java.lang.Thread.run(Thread.java:613)
> 	DEBUG TransportConnection            - Stopping connection: /XXXXXXXXXXXXXX:64820
> 	DEBUG TcpTransport                   - Stopping transport tcp:///XXXXXXXXXXXXXX:64820
> 	DEBUG AMQPersistenceAdapter          - Checkpoint started.
> 	DEBUG AMQPersistenceAdapter          - Checkpoint done.
> AND, I am no longer able to retrieve the queued up messages.  Looking at the admin console I see  Number Of Consumers  = 1, leading me to believe that ActiveMQ didn't properly handle the disconnection.  In the other 2 cases (DISCONNECT and kill) the "Number Of Consumers" drops to zero on connection termination.
> I believe the correct behavior should be to properly handle and clean-up the connection on bad data.  Or perhaps periodically check each of the supposed "Consumers" to make sure that they are still alive.  This is clearly a reproducible case of a DEAD Consumer that never gets cleaned up.
> Comparing the DEBUG output the follows the 2 stack traces, it is clear in the second case that ActiveMQ fails to clean up the connections resources for the unexpectedly disconnected consumer.

-- 
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira