ActiveMQ
  1. ActiveMQ
  2. AMQ-2280

stomp: Transport failed: java.io.IOException: Unexpected error occured

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 5.3.0
    • Fix Version/s: 5.3.0
    • Component/s: Broker, Connector
    • Labels:
      None
    • Environment:

      Description

      This does not happen in 5.2.0, only in 5.3..SNAPSHOT

      I'm getting the above exception with the following STOMP session

      > telnet localhost 61613
      Trying 127.0.0.1...
      Connected to localhost.
      Escape character is '^]'.
      CONNECT
      passcode:password
      login:login

      ^@
      CONNECTED
      session:ID:alex-60773-1244124360289-2:2

      SUBSCRIBE
      activemq.prefetchSize:1
      ack:client
      destination:/queue/COMMAND.HOST.alex
      activemq.exclusive:true

      ^@
      BEGIN
      destination:/queue/COMMANDREPLY.HOST.alex
      transaction:ID:alex-58262-1244123488785-2:1-1
      persistent:true

      ^@
      SEND
      destination:/queue/COMMANDREPLY.HOST.alex
      transaction:ID:alex-58262-1244123488785-2:1-1
      receipt:ID:alex-58262-1244123488785-2:1-2
      persistent:true

      replytext
      ^@
      RECEIPT
      receipt-id:ID:alex-58262-1244123488785-2:1-2

      COMMIT
      destination:/queue/COMMANDREPLY.HOST.alex
      transaction:ID:alex-58262-1244123488785-2:1-1

      ^@
      Connection closed by foreign host.

      at this point AMQ closses the TCP connection and I see the following in the log (DEBUG root log level):

      DEBUG TransportConnection - Setting up new connection: /127.0.0.1:44692
      DEBUG AMQPersistenceAdapter - dataFilesInProgress.values: (0) []
      DEBUG AMQPersistenceAdapter - lastDataFile: 1
      DEBUG AsyncDataManager - lastFileId=0, purgeList: (0) []
      DEBUG AbstractRegion - localhost adding consumer: ID:alex-60773-1244124360289-2:2:-1:1 for destination: queue://COMMAND.HOST.alex
      DEBUG AMQPersistenceAdapter - Checkpoint started.
      DEBUG AMQPersistenceAdapter - Checkpoint done.
      DEBUG AMQPersistenceAdapter - Checkpoint started.
      DEBUG AMQPersistenceAdapter - Checkpoint done.
      DEBUG AMQPersistenceAdapter - dataFilesInProgress.values: (0) []
      DEBUG AMQPersistenceAdapter - lastDataFile: 1
      DEBUG AsyncDataManager - lastFileId=0, purgeList: (0) []
      DEBUG AMQPersistenceAdapter - Checkpoint started.
      DEBUG AMQPersistenceAdapter - Checkpoint done.
      DEBUG AMQMessageStore - Journalled transacted message add for: ID:alex-60773-1244124360289-2:2:-1:1:1, at: offset = 10973, file = 1, size = 375, type = 1
      DEBUG AMQPersistenceAdapter - dataFilesInProgress.values: (0) []
      DEBUG AMQPersistenceAdapter - lastDataFile: 1
      DEBUG AsyncDataManager - lastFileId=0, purgeList: (0) []
      DEBUG AMQPersistenceAdapter - Checkpoint started.
      DEBUG AMQPersistenceAdapter - Checkpoint done.
      DEBUG Transport - Transport failed: java.io.IOException: Unexpected error occured
      java.io.IOException: Unexpected error occured
      at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:192)
      at java.lang.Thread.run(Thread.java:619)
      Caused by: java.util.NoSuchElementException
      at java.util.LinkedList.getFirst(LinkedList.java:109)
      at org.apache.activemq.transport.stomp.StompSubscription.onStompCommit(StompSubscription.java:130)
      at org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommit(ProtocolConverter.java:337)
      at org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommand(ProtocolConverter.java:179)
      at org.apache.activemq.transport.stomp.StompTransportFilter.onCommand(StompTransportFilter.java:67)
      at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
      at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:203)
      at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:185)
      ... 1 more
      DEBUG TransportConnection - Stopping connection: /127.0.0.1:44692
      DEBUG TcpTransport - Stopping transport tcp:///127.0.0.1:44692
      DEBUG TransportConnection - Stopped transport: /127.0.0.1:44692
      DEBUG TransportConnection - Cleaning up connection resources: /127.0.0.1:44692
      DEBUG AbstractRegion - localhost removing consumer: ID:alex-60773-1244124360289-2:2:-1:1 for destination: queue://COMMAND.HOST.alex
      DEBUG LocalTransaction - rollback: TX:ID:alex-60773-1244124360289-2:2:1 syncCount: 3
      DEBUG AMQMessageStore - Transacted message add rollback for: ID:alex-60773-1244124360289-2:2:-1:1:1, at: offset = 10973, file = 1, size = 375, type = 1
      DEBUG TransportConnection - Connection Stopped: /127.0.0.1:44692

      1. AMQ-2280.patch
        1 kB
        Giovani Seben

        Activity

        Hide
        Giovani Seben added a comment -

        I was reviewing this report and I found the problem that generates this exception.

        In the particular case shown here, when commiting a transaction the broker will attempt to commit messages received by the subscriber created before the transaction.

        SUBSCRIBE
        activemq.prefetchSize:1
        ack:client
        destination:/queue/COMMAND.HOST.alex
        activemq.exclusive:true
        

        Since there are no messages there to be commited it fails when doing a lookup on the message subscription linked list.

        Stomp transactions are based only on the transaction ID. The sample here assumes that the transaction is tied to the destination which is not the case. In this case the destination parameter passed in the BEGIN and COMMIT statements is simply ignored by the stomp transport. They are not part of the protocol specification AFAIK. Since mixing multiple transacted and non-transacted destinations within the same stomp connection will cause problems I added a simple check that will warn the user about this issue.

        Show
        Giovani Seben added a comment - I was reviewing this report and I found the problem that generates this exception. In the particular case shown here, when commiting a transaction the broker will attempt to commit messages received by the subscriber created before the transaction. SUBSCRIBE activemq.prefetchSize:1 ack:client destination:/queue/COMMAND.HOST.alex activemq.exclusive: true Since there are no messages there to be commited it fails when doing a lookup on the message subscription linked list. Stomp transactions are based only on the transaction ID. The sample here assumes that the transaction is tied to the destination which is not the case. In this case the destination parameter passed in the BEGIN and COMMIT statements is simply ignored by the stomp transport. They are not part of the protocol specification AFAIK. Since mixing multiple transacted and non-transacted destinations within the same stomp connection will cause problems I added a simple check that will warn the user about this issue.
        Hide
        Aleksandar Ivanisevic added a comment -

        Hi,

        Many thanks for the patch, I'll try to test as soon as it gets comitted or i find the time to build amq myself, whichever comes first

        Sending destination in BEGIN frame was an error, I have since corrected that.

        However I'm intrigued by your statement that "Mixing multiple transacted and non-transacted destinations within the same stomp connection will cause problems"

        Can you elaborate on this? What is a "transacted destination" if, as you said, transactions are not dependent on the destinations?

        What kind of problems can I expect? Can you point me to some documentation? I thought that, like in SQL, i can BEGIN, send MESSAGEs and then either COMMIT or ABORT and all the messages in between will either be sent or discarded.

        Many thanks for your insights.

        Show
        Aleksandar Ivanisevic added a comment - Hi, Many thanks for the patch, I'll try to test as soon as it gets comitted or i find the time to build amq myself, whichever comes first Sending destination in BEGIN frame was an error, I have since corrected that. However I'm intrigued by your statement that "Mixing multiple transacted and non-transacted destinations within the same stomp connection will cause problems" Can you elaborate on this? What is a "transacted destination" if, as you said, transactions are not dependent on the destinations? What kind of problems can I expect? Can you point me to some documentation? I thought that, like in SQL, i can BEGIN, send MESSAGEs and then either COMMIT or ABORT and all the messages in between will either be sent or discarded. Many thanks for your insights.
        Hide
        Giovani Seben added a comment -

        Hi,

        The patch that I'm suggesting is a simple check on the code to try to avoid this situation since in my opinion without a more fine grained definition of transactions with Stomp would be required.

        Let me try to explain this a bit better.
        The particular problem with the snippet of stomp code that you attached to this report is that it first subscribes to destination "/queue/COMMAND.HOST.alex" and then you tries to send transacted messages to "/queue/COMMANDREPLY.HOST.alex". Since stomp transactions are bound only by the transactionID the logic in the code needs to check all destinations used in a connection for messages to commit. In this case the exception happens because there is nothing to be commited at "/queue/COMMAND.HOST.alex".

        The bottom line is that since BEGIN doesn't take a destination as a parameter there is no way to identify for which destination you are starting a transaction and that's the reason why all destinations for the current connection have to be checked for messages to be commited.

        My recommendation is that if you use transactions, don't use more than one destination per connection. This way you avoid the confusion of which destination the transaction is actually supposed to be for.

        Hope that this clarifies some of your questions.

        Show
        Giovani Seben added a comment - Hi, The patch that I'm suggesting is a simple check on the code to try to avoid this situation since in my opinion without a more fine grained definition of transactions with Stomp would be required. Let me try to explain this a bit better. The particular problem with the snippet of stomp code that you attached to this report is that it first subscribes to destination "/queue/COMMAND.HOST.alex" and then you tries to send transacted messages to "/queue/COMMANDREPLY.HOST.alex". Since stomp transactions are bound only by the transactionID the logic in the code needs to check all destinations used in a connection for messages to commit. In this case the exception happens because there is nothing to be commited at "/queue/COMMAND.HOST.alex". The bottom line is that since BEGIN doesn't take a destination as a parameter there is no way to identify for which destination you are starting a transaction and that's the reason why all destinations for the current connection have to be checked for messages to be commited. My recommendation is that if you use transactions, don't use more than one destination per connection. This way you avoid the confusion of which destination the transaction is actually supposed to be for. Hope that this clarifies some of your questions.
        Hide
        Aleksandar Ivanisevic added a comment -

        Just to confirm that I have split the sending and receiving part of my client into separate connections and that appears to have "fixed" the problem.

        I still don't see anything both in the STOMP spec and common sense that would be against mixing transacted and non-transacted statements in one connection, so IMO this is a bug in AMQ STOMP, not in my usage (if we don't count sending a destination in BEGIN frame which is clearly an error).

        Show
        Aleksandar Ivanisevic added a comment - Just to confirm that I have split the sending and receiving part of my client into separate connections and that appears to have "fixed" the problem. I still don't see anything both in the STOMP spec and common sense that would be against mixing transacted and non-transacted statements in one connection, so IMO this is a bug in AMQ STOMP, not in my usage (if we don't count sending a destination in BEGIN frame which is clearly an error).
        Hide
        Dejan Bosanac added a comment -

        Fixed in SVN revision 801916, by checking if the subscriber has some messages in the tx, before sending ack. Please check it out by building the current trunk (or trying the next nightly build).

        Show
        Dejan Bosanac added a comment - Fixed in SVN revision 801916, by checking if the subscriber has some messages in the tx, before sending ack. Please check it out by building the current trunk (or trying the next nightly build).

          People

          • Assignee:
            Dejan Bosanac
            Reporter:
            Aleksandar Ivanisevic
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development