jleinawe [https://community.jboss.org/people/jleinawe] created the discussion "Re: JCA Spec violation using resource-adapter in JBoss 7?" To view the discussion, visit: https://community.jboss.org/message/799747#799747 -------------------------------------------------------------- The relevant bits of the JCA spec are:    JCA 1.5 spec:       Figure 6-7 (page 6-43)       7.6.5 "Scenario: Connection Close and JTA Transactional Cleanup" (page 7-26)       Figure 7-8 (page 7-28)    JCA 1.6 spec:       Figure 6-7 (page 6-41)       7.6.5 "Scenario: Connection Close and JTA Transactional Cleanup" (page 7-24)       Figure 7-8 (page 7-26) A slice of the log summary showing that the the RA is sending connection close notification but jboss is not responding (as required) by delisting the resource:    [...]    out:MessageListener.onMessage(genericStreamMessage0) #1 @1361560697008..1361560702586       in:wlxaQueueConnectionFactory0.createConnection() -> wlConnection0 #1 @1361560698037..1361560700740           out:ConnectionManager.allocateConnection(wlManagedXAQueueConnectionFactory0,connectionRequestInfoImpl0) -> wlConnection0 #1 @1361560698093..1361560700687             in:wlManagedXAQueueConnectionFactory0.createManagedConnection(null,connectionRequestInfoImpl0) -> managedConnectionImpl0 #1 @1361560698194..1361560699457                [...]             [...]             in:managedConnectionImpl0.getXAResource() -> xaResourceWrapper2 #1 @1361560699619..1361560699675             [...]             in:xaResourceWrapper2.start(xid3,2097152) #6 @1361560700092..1361560700275                [...]             [...]       [...]       in:wlConnection0.close() #1 @1361560702160..1361560702546          [...]          *out:ConnectionEventListener.connectionClosed*([...]) #1 @1361560702423..1361560702503    out:MessageEndpoint.afterDelivery() #4 @1361560702595..1361560702930       [...]    [...] I.e., immediately after the "out:ConnectionEventListener.connectionClosed" call (and with an additional level of indent) there should be an "in:xaResourceWrapper2.end" call, but the app-server is not calling XAResource.end as required. -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/799747#799747] Start a new discussion in IronJacamar at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]

jleinawe [https://community.jboss.org/people/jleinawe] created the discussion "Re: JCA Spec violation using resource-adapter in JBoss 7?" To view the discussion, visit: https://community.jboss.org/message/799934#799934 -------------------------------------------------------------- If I download the latest snapshop https://hudson.jboss.org/hudson/view/JBoss%20AS/job/JBoss-AS-7.0.x/ https://hudson.jboss.org/hudson/view/JBoss%20AS/job/JBoss-AS-7.0.x/ Will I need to run the patchtool for Ironjacamar (as discussed here): https://community.jboss.org/thread/196508 https://community.jboss.org/thread/196508 -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/799934#799934] Start a new discussion in IronJacamar at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]

Jesper Pedersen [https://community.jboss.org/people/jesper.pedersen] created the discussion "Re: JCA Spec violation using resource-adapter in JBoss 7?" To view the discussion, visit: https://community.jboss.org/message/799957#799957 -------------------------------------------------------------- Also include TRACE log for org.jboss.jca -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/799957#799957] Start a new discussion in IronJacamar at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]

jleinawe [https://community.jboss.org/people/jleinawe] created the discussion "Re: JCA Spec violation using resource-adapter in JBoss 7?" To view the discussion, visit: https://community.jboss.org/message/799975#799975 -------------------------------------------------------------- Attached file named "logs_0227.zip". This contains a new JBoss server log with org.jboss.jca logging set to TRACE and the output of the rar info tool. -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/799975#799975] Start a new discussion in IronJacamar at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]

jleinawe [https://community.jboss.org/people/jleinawe] created the discussion "Re: JCA Spec violation using resource-adapter in JBoss 7?" To view the discussion, visit: https://community.jboss.org/message/800132#800132 -------------------------------------------------------------- I used these instructions to enable logging when I ran the test yesterday: https://community.jboss.org/docs/DOC-16648 https://community.jboss.org/wiki/JBossAS7Logging I just attached a new set of logs (logs_0228.zip), this time I added this to logging.properties +logger.org.jboss.jca.level=TRACE+ +logger.org.jboss.jca.useParentHandlers=true+ When I look at the new server.log, I do see TRACE messages for org.jboss.jca* +10:12:09,254 TRACE [org.jboss.jca.core.connectionmanager.pool.idle.IdleRemover] (IdleRemover) Result of await: true+ The logs_0228.zip attachment has my standalone.xml, logger.xml, output from the JBoss server (myjbossserver.out), and server.log.   If I am not setting logging correctly, can you forward instructions - thanks. -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/800132#800132] Start a new discussion in IronJacamar at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]

jleinawe [https://community.jboss.org/people/jleinawe] created the discussion "Re: JCA Spec violation using resource-adapter in JBoss 7?" To view the discussion, visit: https://community.jboss.org/message/800151#800151 -------------------------------------------------------------- attached is the MDB source, which contains the @annotations for the activiation-spec properties. I'll see about getting a filtered log for the connection. -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/800151#800151] Start a new discussion in IronJacamar at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]

Jeff Steidl [https://community.jboss.org/people/jsteidl] created the discussion "Re: JCA Spec violation using resource-adapter in JBoss 7?" To view the discussion, visit: https://community.jboss.org/message/800173#800173 -------------------------------------------------------------- To quickly see the problem, search the log summary jleinawe provided (tempm.txt) for "xaResourceWrapper2".  The first three instances are: in:managedConnectionImpl0.getXAResource() -> xaResourceWrapper2 #1 @1362075193107..1362075193110 [...] in:xaResourceWrapper2.start(xid3,2097152) #6 @1362075193148..1362075193161 [...] in:xaResourceWrapper2.start(xid5,2097152) threw #8 @1362075193570..1362075193577 As you can see, the app-server gets this XAResource from the RA, then calls XAResource.start on it multiple times in a row without calling XAResource.end in between (which is why the RA throws an exception the second time xaResourceWrapper2.start is called).  If you keep searching for "xaResourceWrapper2", you'll see several more calls to XAResource.start, but no calls to XAResource.end. If you then search from the top of the log summary for "xid3", you'll find the following calls made to the RA ("in:" calls): in:xaResourceWrapper0.start(xid3,0) #4 @1362075179562..1362075179570 [...] in:xaResourceWrapper2.start(xid3,2097152) #6 @1362075193148..1362075193161 [...] in:xaResourceWrapper0.end(xid3,67108864) #4 @1362075193388..1362075193396 [...] in:xaResourceWrapper0.commit(xid3,true) #4 @1362075193397..1362075193438 You can see that while the app-server is ending the association for xaResourceWrapper0 before committing the transaction, it is failing to do so for xaResourceWrapper2. This line shows that wlConnection0 is the connection handle being used for managedConnectionImpl0:    in:managedConnectionImpl0.getConnection(null,connectionRequestInfoImpl0) -> wlConnection0 #1 @1362075193164..1362075193199 And if you look at wlConnection0 being closed:    in:wlConnection0.close() #1 @1362075193351..1362075193382       out:Connection.stop() #1 @1362075193356..1362075193361       out:XAResource.end(xid3,67108864) #4 @1362075193364..1362075193368       out:ConnectionEventListener.connectionClosed(javax.resource.spi.ConnectionEvent[source=OracleJMSConnector.ManagedConnectionImpl.adc2100774.us.oracle.com.-2ebdb17:13d22011ace:-7ffb.20]) #1 @1362075193372..1362075193379 out:MessageEndpoint.afterDelivery() #4 @1362075193386..1362075193444 you'll see that the RA is calling ConnectionEventListener.connectionClosed, but the app-server is failing to delist xaResourceWrapper2 in response (as the JCA spec requires).  [Note that the "out:XAResource.end" call above is for a secondary JMS provider XAResource used internally by the RA, and is not the same as xaResourceWrapper2.] Since the above lines are grabbed as-is (except for indent) from tempm.txt, you can see those calls in context by searching for them in that file. -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/800173#800173] Start a new discussion in IronJacamar at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]

jsteidl [https://community.jboss.org/people/jsteidl] created the discussion "Re: JCA Spec violation using resource-adapter in JBoss 7?" To view the discussion, visit: https://community.jboss.org/message/800406#800406 -------------------------------------------------------------- I'm not sure exactly which log you're getting that from (it's from a different run than the last one), and anyways only the latest set of logs includes the intermediate file, so I'll just go with the essentially identical bit from the logs included with post #11: out:MessageEndpoint.beforeDelivery(public abstract void javax.jms.MessageListener.onMessage(javax.jms.Message)) #4 @1362075179551..1362075179571    in:xaResourceWrapper0.setTransactionTimeout(300) -> true #4 @1362075179554..1362075179560       out:XAResource.setTransactionTimeout(300) -> true #4 @1362075179556..1362075179559    in:xaResourceWrapper0.start(xid3,0) #4 @1362075179562..1362075179570       out:XAResource.start(xid3,0) #4 @1362075179565..1362075179568 (The only difference from the instance you were looking at is the timestamps.) As described in post #11, you can get a full stack trace for any given call.  In this case you want to know how this is getting called:    in:xaResourceWrapper0.start(xid3,0) #4 @1362075179562..1362075179570 The easiest way to find that is to search the intermediate file (tempm.int) for the start time (1362075179562) until you locate the entry record for the in:XAResource.start #4 call: OracleJMSConnector event: enter method    formal method: javax.transaction.xa.XAResource.start    call direction: in (OracleJMSConnector is callee)    call count: 4    currentThread: Thread[default-threads - 1,5,default-threads]    currentTimeMillis: 1362075179562    call stack:       weblogic.jms.ra.XAResourceWrapper.start(XAResourceWrapper.java:384)       com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:636)       com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:397)       org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.beforeDelivery(MessageEndpointInvocationHandler.java:110)       sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)       sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)       sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)       java.lang.reflect.Method.invoke(Method.java:601)       org.jboss.as.ejb3.inflow.AbstractInvocationHandler.handle(AbstractInvocationHandler.java:60)       org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:136)       org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73)       $Proxy9.beforeDelivery(Unknown Source)       weblogic.jms.ra.Provider.beforeDelivery(Provider.java:1460)       weblogic.jms.ra.EndpointListener.run(EndpointListener.java:315)       weblogic.jms.ra.EndpointThread.run(EndpointThread.java:143)       org.jboss.jca.core.workmanager.WorkWrapper.run(WorkWrapper.java:218)       org.jboss.threads.SimpleDirectExecutor.execute(SimpleDirectExecutor.java:33)       org.jboss.threads.QueueExecutor.runTask(QueueExecutor.java:806)       org.jboss.threads.QueueExecutor.access$100(QueueExecutor.java:45)       org.jboss.threads.QueueExecutor$Worker.run(QueueExecutor.java:826)       java.lang.Thread.run(Thread.java:722)       org.jboss.threads.JBossThread.run(JBossThread.java:122)    target:       formal type: javax.transaction.xa.XAResource       actual type: weblogic.jms.ra.XAResourceWrapper       classloader.toString: 'ModuleClassLoader for Module "deployment.wl-jms-ra.rar:main" from Service Module Loader'       interfaces:          interface: javax.transaction.xa.XAResource          classloader.toString: 'ModuleClassLoader for Module "javax.transaction.api:main" from local module loader @73d0a8dc (finder: local module finder @7fe3eeb (roots: /scratch/jleinawe/p4/w/src1212_17010b18_x86_64/bea/results/wls/functional/jms/jboss/modules,/scratch/jleinawe/p4/w/src1212_17010b18_x86_64/bea/results/wls/functional/jms/jboss/modules/system/layers/base))'       identityHashCode: 23175cbf       toString: 'weblogic.jms.ra.XAResourceWrapper@23175cbf'    parameter #1:       formal type: javax.transaction.xa.Xid       actual type: com.arjuna.ats.jta.xa.XidImple       classloader.toString: 'ModuleClassLoader for Module "org.jboss.jts:main" from local module loader @73d0a8dc (finder: local module finder @7fe3eeb (roots: /scratch/jleinawe/p4/w/src1212_17010b18_x86_64/bea/results/wls/functional/jms/jboss/modules,/scratch/jleinawe/p4/w/src1212_17010b18_x86_64/bea/results/wls/functional/jms/jboss/modules/system/layers/base))'       interfaces:          interface: java.io.Serializable          classloader is null          interface: javax.transaction.xa.Xid          classloader.toString: 'ModuleClassLoader for Module "javax.transaction.api:main" from local module loader @73d0a8dc (finder: local module finder @7fe3eeb (roots: /scratch/jleinawe/p4/w/src1212_17010b18_x86_64/bea/results/wls/functional/jms/jboss/modules,/scratch/jleinawe/p4/w/src1212_17010b18_x86_64/bea/results/wls/functional/jms/jboss/modules/system/layers/base))'       identityHashCode: 3447fc7       Xid value:          formatID: 131077 (0x20005)              gtid: 00000000000000000000ffff0ae5bb875709964c512f9df90000001d31 (29 bytes)             bqual: 00000000000000000000ffff0ae5bb875709964c512f9df90000001e0000000000000000 (36 bytes)       toString: '< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffff0ae5bb87:5709964c:512f9df9:1d, node_name=1, branch_uid=0:ffff0ae5bb87:5709964c:512f9df9:1e, subordinatenodename=null, eis_name=unknown eis name >'    parameter #2:       type: int       value: 0    related:       in:javax.resource.spi.ResourceAdapter.endpointActivation #1       in:weblogic.jms.ra.api.DestinationSetListener.add #1 -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/800406#800406] Start a new discussion in IronJacamar at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]

jleinawe [https://community.jboss.org/people/jleinawe] created the discussion "Re: JCA Spec violation using resource-adapter in JBoss 7?" To view the discussion, visit: https://community.jboss.org/message/800860#800860 -------------------------------------------------------------- for the JBoss folks - is there anything more I can do with regards to adding logging/tracing that can help with understanding this issue?   (I would need specific instructions on what to enable or what configuration to change).     Is there any question regarding the resource-adapter implementation we are developing that jsteidl could answer? -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/800860#800860] Start a new discussion in IronJacamar at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]

jleinawe [https://community.jboss.org/people/jleinawe] created the discussion "Re: JCA Spec violation using resource-adapter in JBoss 7?" To view the discussion, visit: https://community.jboss.org/message/802214#802214 -------------------------------------------------------------- new log (logs_0312.zip) attached along with the standalone.xml, logging.properties, the stdout/err from the JBoss server and the MDB's source file which has the @annotated  activation config This will be a different MDB than before, same basic function, just simplified so I can work outside our test framework. 1) RA deployed and configured in JBoss (as before) 2) RA-backed MDB deployed to JBoss.  MDB is XA enabled, it receives a message then sends an outbound response (Container Managed Txn). 3) A WebLogic client enqueues 3 messages to the inbound queue (this is done on the WebLogic side, no RA or JBoss). 4) MDB should consume the 3 messages and send a response message for each but fails. You can jump to the failure in the server.log by searcing it for "ERROR". -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/802214#802214] Start a new discussion in IronJacamar at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]

Jesper Pedersen [https://community.jboss.org/people/jesper.pedersen] created the discussion "Re: JCA Spec violation using resource-adapter in JBoss 7?" To view the discussion, visit: https://community.jboss.org/message/802395#802395 -------------------------------------------------------------- If you are seeing the problem by just sending one message then just include that log - sending more messages only clutters it -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/802395#802395] Start a new discussion in IronJacamar at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]

jleinawe [https://community.jboss.org/people/jleinawe] created the discussion "Re: JCA Spec violation using resource-adapter in JBoss 7?" To view the discussion, visit: https://community.jboss.org/message/802469#802469 -------------------------------------------------------------- New log file attached.   This has com.arjuna logging set to TRACE. This has the Byteman script you provided in a previous post and I see the "BM" messages in the log This does not have our RA tracing enabled (which might make it easier for you to read). I simplified the test case to sending 2 messages.   The first will work but the second fails as it tries to reuse the outbound connection once again (the transaction didn't delist the first time).  I also simplified the MDB in that it no longer tries to redeliver messages.   Before it was using a default where it makes 5 attempts to deliver the same message to the MDB (a config parameter that protects against poison messages).   This time it will try to deliver it once then discard it if that delivery fails   This should help unclutter the logs a bit more. -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/802469#802469] Start a new discussion in IronJacamar at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]

jsteidl [https://community.jboss.org/people/jsteidl] created the discussion "Re: JCA Spec violation using resource-adapter in JBoss 7?" To view the discussion, visit: https://community.jboss.org/message/802339#802339 -------------------------------------------------------------- Attached are the log summary (tempm.txt) and intermediate file (tempm.int) derived from the full logs included with post #18. [Due to the test changes described by jleinawe, the attached log summary is a bit different than the one described in post #12.  It is now "xaResourceWrapper1" rather than "xaResourceWrapper2" that is being repeatedly 'XAResource.start'ed and never 'XAResource.end'ed.  And the first xid where the transaction is committed without first ending the association is "xid1".] -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/802339#802339] Start a new discussion in IronJacamar at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]