ActiveMQ
  1. ActiveMQ
  2. AMQ-1078

Messages consumed with the Resource Adapter are intermittently not delivered

    Details

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

      Description

      The cause is that the ActiveMQSessionExecutor was starting and using it's dispatch thread instead of the Thread managed by the resource adapter.

      1. AMQ-1078.patch
        1 kB
        Christopher G. Stach II

        Activity

        Hiram Chirino created issue -
        Hide
        Hiram Chirino added a comment -

        Fixed in trunk revision 480717

        Show
        Hiram Chirino added a comment - Fixed in trunk revision 480717
        Hide
        Hiram Chirino added a comment -

        fix in 4.1 branch rev 480862

        Show
        Hiram Chirino added a comment - fix in 4.1 branch rev 480862
        Hide
        Christopher G. Stach II added a comment -

        Is this "fixed, but not closed" or "not really fixed"?

        Show
        Christopher G. Stach II added a comment - Is this "fixed, but not closed" or "not really fixed"?
        Hide
        Christopher G. Stach II added a comment -

        Well, I pulled out the patch and applied it to 4.1.0 and it fixed the problem.

        Show
        Christopher G. Stach II added a comment - Well, I pulled out the patch and applied it to 4.1.0 and it fixed the problem.
        Christopher G. Stach II made changes -
        Field Original Value New Value
        Attachment AMQ-1078.patch [ 15304 ]
        james strachan made changes -
        Resolution Fixed [ 1 ]
        Status Open [ 1 ] Resolved [ 5 ]
        Hide
        John Stalker added a comment -

        Hi,
        It appears that there is still a bug some place in the rar.
        Here's the scenario:
        I recently (ie, a couple days ago) downloaded and built the 4.1 branch, set up JBoss 4.0.5.GA with a slightly modified activemq-ra.rar (ra.xml modified to communicate with an external instance of the broker via tcp and setting of UseInboundSession is set to true...not sure what this does really, but I tried it as false and the same behavior happens).

        Via a persistent queue (oracle backing) I'm consuming messages in an MDB via the JCA message datasource using XA.

        Here's the problem I'm seeing: if I shut down the JMS server, I see the appropriate EOF exception and subsequent reconnection attempts by the rar in JBoss. When I startup the external activemq broker again, the connection appears to get reestablished and work is accepted, started, and completed...EXCEPT there's no mention of XA and thus the message is never actually accepted and consumed.

        Here's some debug output from the JCA:

        PRE shutdown of external broker:
        2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionPoolImpl] ServerSession requested.
        2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionPoolImpl] Using idle session: ServerSessionImpl:1
        2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Starting run.
        2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Work accepted: javax.resource.spi.work.WorkEvent[source=org.jboss.resource.work.JBossWorkManager@1461b5b]
        2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Work started: javax.resource.spi.work.WorkEvent[source=org.jboss.resource.work.JBossWorkManager@1461b5b]
        2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Running
        2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] run loop start
        2007-03-09 11:43:02,884 DEBUG [org.apache.activemq.TransactionContext] Start: XidImpl[FormatId=257, GlobalId=node118/114, BranchQual=1, localId=114]
        2007-03-09 11:43:02,884 DEBUG [org.apache.activemq.TransactionContext] Started XA transaction: XID:257:6e6f64653131382f313134:31

        – snip – output of a resulting consumption of message

        2007-03-09 11:43:04,447 DEBUG [org.apache.activemq.TransactionContext] End: XidImpl[FormatId=257, GlobalId=node118/114, BranchQual=1, localId=114]
        2007-03-09 11:43:04,447 DEBUG [org.apache.activemq.TransactionContext] Ended XA transaction: XID:257:6e6f64653131382f313134:31
        2007-03-09 11:43:04,448 DEBUG [org.apache.activemq.TransactionContext] Prepare: XidImpl[FormatId=257, GlobalId=node118/114, BranchQual=1, localId=114]
        2007-03-09 11:43:04,454 DEBUG [org.apache.activemq.TransactionContext] Commit: XidImpl[FormatId=257, GlobalId=node118/114, BranchQual=1, localId=114]
        2007-03-09 11:43:05,150 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] run loop end
        2007-03-09 11:43:05,178 DEBUG [org.apache.activemq.ra.ServerSessionPoolImpl] Session returned to pool: ServerSessionImpl:1
        2007-03-09 11:43:05,178 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Run finished
        2007-03-09 11:43:05,178 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Work completed: javax.resource.spi.work.WorkEvent[source=org.jboss.resource.work.JBossWorkManager@1461b5b]

        POST shutdown and restart of external broker

        2007-03-09 11:46:33,077 DEBUG [org.apache.activemq.transport.WireFormatNegotiator] Sending: WireFormatInfo { version=2, properties=

        {TightEncodingEnabled=true, CacheSize=1024, TcpNoDelayEnabled=true, SizePrefixDisabled=false, StackTraceEnabled=true, MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
        2007-03-09 11:46:33,126 DEBUG [org.apache.activemq.transport.WireFormatNegotiator] Received WireFormat: WireFormatInfo { version=2, properties={TightEncodingEnabled=true, CacheSize=1024, TcpNoDelayEnabled=true, SizePrefixDisabled=false, StackTraceEnabled=true, MaxInactivityDuration=30000, CacheEnabled=true}

        , magic=[A,c,t,i,v,e,M,Q]}
        2007-03-09 11:46:33,126 DEBUG [org.apache.activemq.transport.WireFormatNegotiator] tcp://seqlims.broad.mit.edu/18.103.10.168:61616 before negotiation: OpenWireFormat

        {version=2, cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false, sizePrefixDisabled=false}

        2007-03-09 11:46:33,126 DEBUG [org.apache.activemq.transport.WireFormatNegotiator] tcp://seqlims.broad.mit.edu/18.103.10.168:61616 after negotiation: OpenWireFormat

        {version=2, cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false}

        2007-03-09 11:53:15,196 DEBUG [org.apache.activemq.ra.ServerSessionPoolImpl] ServerSession requested.
        2007-03-09 11:53:15,196 DEBUG [org.apache.activemq.ra.ServerSessionPoolImpl] Using idle session: ServerSessionImpl:1
        2007-03-09 11:53:15,196 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Starting run.
        2007-03-09 11:53:15,196 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Work accepted: javax.resource.spi.work.WorkEvent[source=org.jboss.resource.work.JBossWorkManager@1461b5b]
        2007-03-09 11:53:15,196 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Work started: javax.resource.spi.work.WorkEvent[source=org.jboss.resource.work.JBossWorkManager@1461b5b]
        2007-03-09 11:53:15,197 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Running

        – as you can see, no XA here

        2007-03-09 11:53:15,197 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] run loop start
        2007-03-09 11:53:15,197 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] run loop end
        2007-03-09 11:53:15,197 DEBUG [org.apache.activemq.ra.ServerSessionPoolImpl] Session returned to pool: ServerSessionImpl:1
        2007-03-09 11:53:15,197 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Run finished
        2007-03-09 11:53:15,197 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Work completed: javax.resource.spi.work.WorkEvent[source=org.jboss.resource.work.JBossWorkManager@1461b5b]

        Thanks for your help!
        John

        Show
        John Stalker added a comment - Hi, It appears that there is still a bug some place in the rar. Here's the scenario: I recently (ie, a couple days ago) downloaded and built the 4.1 branch, set up JBoss 4.0.5.GA with a slightly modified activemq-ra.rar (ra.xml modified to communicate with an external instance of the broker via tcp and setting of UseInboundSession is set to true...not sure what this does really, but I tried it as false and the same behavior happens). Via a persistent queue (oracle backing) I'm consuming messages in an MDB via the JCA message datasource using XA. Here's the problem I'm seeing: if I shut down the JMS server, I see the appropriate EOF exception and subsequent reconnection attempts by the rar in JBoss. When I startup the external activemq broker again, the connection appears to get reestablished and work is accepted, started, and completed...EXCEPT there's no mention of XA and thus the message is never actually accepted and consumed. Here's some debug output from the JCA: PRE shutdown of external broker: 2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionPoolImpl] ServerSession requested. 2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionPoolImpl] Using idle session: ServerSessionImpl:1 2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Starting run. 2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Work accepted: javax.resource.spi.work.WorkEvent [source=org.jboss.resource.work.JBossWorkManager@1461b5b] 2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Work started: javax.resource.spi.work.WorkEvent [source=org.jboss.resource.work.JBossWorkManager@1461b5b] 2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Running 2007-03-09 11:43:02,883 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] run loop start 2007-03-09 11:43:02,884 DEBUG [org.apache.activemq.TransactionContext] Start: XidImpl [FormatId=257, GlobalId=node118/114, BranchQual=1, localId=114] 2007-03-09 11:43:02,884 DEBUG [org.apache.activemq.TransactionContext] Started XA transaction: XID:257:6e6f64653131382f313134:31 – snip – output of a resulting consumption of message 2007-03-09 11:43:04,447 DEBUG [org.apache.activemq.TransactionContext] End: XidImpl [FormatId=257, GlobalId=node118/114, BranchQual=1, localId=114] 2007-03-09 11:43:04,447 DEBUG [org.apache.activemq.TransactionContext] Ended XA transaction: XID:257:6e6f64653131382f313134:31 2007-03-09 11:43:04,448 DEBUG [org.apache.activemq.TransactionContext] Prepare: XidImpl [FormatId=257, GlobalId=node118/114, BranchQual=1, localId=114] 2007-03-09 11:43:04,454 DEBUG [org.apache.activemq.TransactionContext] Commit: XidImpl [FormatId=257, GlobalId=node118/114, BranchQual=1, localId=114] 2007-03-09 11:43:05,150 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] run loop end 2007-03-09 11:43:05,178 DEBUG [org.apache.activemq.ra.ServerSessionPoolImpl] Session returned to pool: ServerSessionImpl:1 2007-03-09 11:43:05,178 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Run finished 2007-03-09 11:43:05,178 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Work completed: javax.resource.spi.work.WorkEvent [source=org.jboss.resource.work.JBossWorkManager@1461b5b] POST shutdown and restart of external broker 2007-03-09 11:46:33,077 DEBUG [org.apache.activemq.transport.WireFormatNegotiator] Sending: WireFormatInfo { version=2, properties= {TightEncodingEnabled=true, CacheSize=1024, TcpNoDelayEnabled=true, SizePrefixDisabled=false, StackTraceEnabled=true, MaxInactivityDuration=30000, CacheEnabled=true}, magic= [A,c,t,i,v,e,M,Q] } 2007-03-09 11:46:33,126 DEBUG [org.apache.activemq.transport.WireFormatNegotiator] Received WireFormat: WireFormatInfo { version=2, properties={TightEncodingEnabled=true, CacheSize=1024, TcpNoDelayEnabled=true, SizePrefixDisabled=false, StackTraceEnabled=true, MaxInactivityDuration=30000, CacheEnabled=true} , magic= [A,c,t,i,v,e,M,Q] } 2007-03-09 11:46:33,126 DEBUG [org.apache.activemq.transport.WireFormatNegotiator] tcp://seqlims.broad.mit.edu/18.103.10.168:61616 before negotiation: OpenWireFormat {version=2, cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false, sizePrefixDisabled=false} 2007-03-09 11:46:33,126 DEBUG [org.apache.activemq.transport.WireFormatNegotiator] tcp://seqlims.broad.mit.edu/18.103.10.168:61616 after negotiation: OpenWireFormat {version=2, cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false} 2007-03-09 11:53:15,196 DEBUG [org.apache.activemq.ra.ServerSessionPoolImpl] ServerSession requested. 2007-03-09 11:53:15,196 DEBUG [org.apache.activemq.ra.ServerSessionPoolImpl] Using idle session: ServerSessionImpl:1 2007-03-09 11:53:15,196 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Starting run. 2007-03-09 11:53:15,196 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Work accepted: javax.resource.spi.work.WorkEvent [source=org.jboss.resource.work.JBossWorkManager@1461b5b] 2007-03-09 11:53:15,196 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Work started: javax.resource.spi.work.WorkEvent [source=org.jboss.resource.work.JBossWorkManager@1461b5b] 2007-03-09 11:53:15,197 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Running – as you can see, no XA here 2007-03-09 11:53:15,197 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] run loop start 2007-03-09 11:53:15,197 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] run loop end 2007-03-09 11:53:15,197 DEBUG [org.apache.activemq.ra.ServerSessionPoolImpl] Session returned to pool: ServerSessionImpl:1 2007-03-09 11:53:15,197 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Run finished 2007-03-09 11:53:15,197 DEBUG [org.apache.activemq.ra.ServerSessionImpl:1] Work completed: javax.resource.spi.work.WorkEvent [source=org.jboss.resource.work.JBossWorkManager@1461b5b] Thanks for your help! John
        John Stalker made changes -
        Resolution Fixed [ 1 ]
        Status Resolved [ 5 ] Reopened [ 4 ]
        Hide
        Christopher G. Stach II added a comment -

        Does it look like the attached patch is applied to the source that you downloaded and built?

        Show
        Christopher G. Stach II added a comment - Does it look like the attached patch is applied to the source that you downloaded and built?
        Hide
        Hiram Chirino added a comment -

        The patch has been applied to 4.1 and is the current RC 1 for ActiveMQ 4.1.1

        But the XA problem that john is reporting seems to be something different entirely from the original problem addressed. I going to close this issue out since it did fix a problem. John you could you open a new issue specifically for the XA problem you are seeing. Thanks!

        Show
        Hiram Chirino added a comment - The patch has been applied to 4.1 and is the current RC 1 for ActiveMQ 4.1.1 But the XA problem that john is reporting seems to be something different entirely from the original problem addressed. I going to close this issue out since it did fix a problem. John you could you open a new issue specifically for the XA problem you are seeing. Thanks!
        Hiram Chirino made changes -
        Resolution Fixed [ 1 ]
        Status Reopened [ 4 ] Resolved [ 5 ]
        Hide
        Christopher G. Stach II added a comment -

        Also, how is this "intermittently not delivered"? If it's being delivered, but for some reason without XA, it's still being delivered. Sounds like a different issue.

        Show
        Christopher G. Stach II added a comment - Also, how is this "intermittently not delivered"? If it's being delivered, but for some reason without XA, it's still being delivered. Sounds like a different issue.
        Hide
        John Stalker added a comment -

        Yeah, looking at the source for the session executor, I see this in the wakeup() method:
        if( session.isSessionAsyncDispatch() ) {
        which replaced taskRunner != null as the 2nd test in the method...the taskRunner == null shows up in the try block – the same as the patch.

        Show
        John Stalker added a comment - Yeah, looking at the source for the session executor, I see this in the wakeup() method: if( session.isSessionAsyncDispatch() ) { which replaced taskRunner != null as the 2nd test in the method...the taskRunner == null shows up in the try block – the same as the patch.
        Hide
        John Stalker added a comment -

        you're both right, it appears to be a combination of JCA reconnect / XA restart (or whatever you want to call it). I Reopened this bug pre-maturely...sorry about that!

        I'll file a new bug.

        Show
        John Stalker added a comment - you're both right, it appears to be a combination of JCA reconnect / XA restart (or whatever you want to call it). I Reopened this bug pre-maturely...sorry about that! I'll file a new bug.
        Jeff Turner made changes -
        Project Import Fri Nov 26 22:32:02 EST 2010 [ 1290828722158 ]

          People

          • Assignee:
            Hiram Chirino
            Reporter:
            Hiram Chirino
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development