Where to find explanation/workaround for ARJUNA-22226, ARJUNA-22223

[jjfraney]

With jboss as 6.0.0,

using the jboss 'all' server,

converted to use jts (via the shell script provided in 'docs/examples/transaction'),

with only ONE jboss instance,

a web service implementation calls an EJB (CallControlServiceBean) which calls a another EJB (a singleton timer bean),

the transaction is successfully commited (verified by looking at the database).

Then, we see the following warnings,

rooted apparently because a certain object does not exist.

What is happening?

What is the meaning of this warning?

Is JTS operational or failing?

Thanks

John

2012-06-13 10:04:40,726 INFO [com.tp.services.callcontrol.CallControlServiceBean] (http-10.144.27.141-8180-1) Add participant result to IVR: ConferenceId 138-138-12-06-13, ParticipantId 138-283-12-06-13, isHost false, confStatus false, hosttimeout 300, participanttimeout 300

2012-06-13 10:04:40,890 WARN  [jacorb.poa.controller] (RequestController-1) rid: 42 opname: shouldMerge cannot process request, because object doesn't exist

2012-06-13 10:04:40,895 WARN  [jacorb.poa.controller] (RequestController-1) rid: 42 opname: shouldMerge request rejected with exception:

2012-06-13 10:04:40,899 WARN  [jacorb.poa.controller] (RequestController-1) rid: 44 opname: shouldReplace cannot process request, because object doesn't exist

2012-06-13 10:04:40,901 WARN  [jacorb.poa.controller] (RequestController-1) rid: 44 opname: shouldReplace request rejected with exception:

2012-06-13 10:04:40,902 WARN  [jacorb.poa.controller] (RequestController-1) rid: 46 opname: shouldAdd cannot process request, because object doesn't exist

2012-06-13 10:04:40,904 WARN  [jacorb.poa.controller] (RequestController-1) rid: 46 opname: shouldAdd request rejected with exception:

2012-06-13 10:04:40,906 WARN  [jacorb.poa.controller] (RequestController-1) rid: 48 opname: shouldAlter cannot process request, because object doesn't exist

2012-06-13 10:04:40,908 WARN  [jacorb.poa.controller] (RequestController-1) rid: 48 opname: shouldAlter request rejected with exception:

2012-06-13 10:04:40,909 WARN  [jacorb.poa.controller] (RequestController-1) rid: 50 opname: _get_uid cannot process request, because object doesn't exist

2012-06-13 10:04:40,911 WARN  [jacorb.poa.controller] (RequestController-1) rid: 50 opname: _get_uid request rejected with exception:

2012-06-13 10:04:40,916 WARN  [jacorb.poa.controller] (RequestController-1) rid: 52 opname: saveRecord cannot process request, because object doesn't exist

2012-06-13 10:04:40,917 WARN  [jacorb.poa.controller] (RequestController-1) rid: 52 opname: saveRecord request rejected with exception:

2012-06-13 10:04:40,919 WARN  [com.arjuna.ats.jts] (http-10.144.27.141-8180-1) ARJUNA-22226 ExtendedResourceRecord.doSave failed. Returning default value: true

2012-06-13 10:04:40,937 WARN  [jacorb.poa.controller] (RequestController-1) rid: 54 opname: commit cannot process request, because object doesn't exist

2012-06-13 10:04:40,939 WARN  [jacorb.poa.controller] (RequestController-1) rid: 54 opname: commit request rejected with exception:

2012-06-13 10:04:40,940 WARN  [com.arjuna.ats.jts] (http-10.144.27.141-8180-1) ARJUNA-22223 ExtendedResourceRecord.topLevelCommit caught exception: org.omg.CORBA.OBJECT_NOT_EXIST: Server-side Exception:   vmcid: 0x0  minor code: 0  completed: No

at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) [:1.6.0_22]

at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39) [:1.6.0_22]

at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27) [:1.6.0_22]

at java.lang.reflect.Constructor.newInstance(Constructor.java:513) [:1.6.0_22]

at org.jacorb.orb.SystemExceptionHelper.read(Unknown Source) [:6.0.0.Final]

at org.jacorb.orb.ReplyReceiver.getReply(Unknown Source) [:6.0.0.Final]

at org.jacorb.orb.Delegate.invoke_internal(Unknown Source) [:6.0.0.Final]

at org.jacorb.orb.Delegate.invoke(Unknown Source) [:6.0.0.Final]

at org.omg.CORBA.portable.ObjectImpl._invoke(ObjectImpl.java:457) [:1.6.0_22]

at com.arjuna.ArjunaOTS._ArjunaSubtranAwareResourceStub.commit(_ArjunaSubtranAwareResourceStub.java:252) [:6.0.0.Final]

at com.arjuna.ats.internal.jts.resources.ExtendedResourceRecord.topLevelCommit(ExtendedResourceRecord.java:499) [:6.0.0.Final]

at com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2789) [:6.0.0.Final]

at com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2705) [:6.0.0.Final]

at com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Commit(BasicAction.java:1788) [:6.0.0.Final]

at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1481) [:6.0.0.Final]

at com.arjuna.ats.internal.jts.orbspecific.coordinator.ArjunaTransactionImple.commit(ArjunaTransactionImple.java:345) [:6.0.0.Final]

at com.arjuna.ats.internal.jts.ControlWrapper.commit(ControlWrapper.java:238) [:6.0.0.Final]

at com.arjuna.ats.internal.jts.orbspecific.CurrentImple.commit(CurrentImple.java:249) [:6.0.0.Final]

at com.arjuna.ats.jts.extensions.AtomicTransaction.commit(AtomicTransaction.java:269) [:6.0.0.Final]

at com.arjuna.ats.internal.jta.transaction.jts.TransactionImple.commitAndDisassociate(TransactionImple.java:1287) [:6.0.0.Final]

at com.arjuna.ats.internal.jta.transaction.jts.BaseTransaction.commit(BaseTransaction.java:132) [:6.0.0.Final]

at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) [:6.0.0.Final]

at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:82) [:0.0.1]

at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:255) [:0.0.1]

at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.requiresNew(CMTTxInterceptor.java:392) [:0.0.1]

at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.invoke(CMTTxInterceptor.java:211) [:0.0.1]

at org.jboss.ejb3.tx2.aop.CMTTxInterceptorWrapper.invoke(CMTTxInterceptorWrapper.java:52) [:0.0.1]

at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:76) [:1.0.0.GA]

at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

at org.jboss.aspects.remoting.ReplicantsManagerInterceptor.invoke(ReplicantsManagerInterceptor.java:56) [:1.0.1.GA]

at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

at org.jboss.ejb3.tx.NullInterceptor.invoke(NullInterceptor.java:42) [:1.0.3]

at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

at org.jboss.ejb3.security.Ejb3AuthenticationInterceptorv2.invoke(Ejb3AuthenticationInterceptorv2.java:182) [:1.7.17]

at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:41) [:1.7.17]

at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

at org.jboss.ejb3.BlockContainerShutdownInterceptor.invoke(BlockContainerShutdownInterceptor.java:67) [:1.7.17]

at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

at org.jboss.ejb3.core.context.CurrentInvocationContextInterceptor.invoke(CurrentInvocationContextInterceptor.java:47) [:1.7.17]

at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

at org.jboss.aspects.currentinvocation.CurrentInvocationInterceptor.invoke(CurrentInvocationInterceptor.java:67) [:1.0.1]

at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

at org.jboss.ejb3.interceptor.EJB3TCCLInterceptor.invoke(EJB3TCCLInterceptor.java:86) [:1.7.17]

at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

at org.jboss.ejb3.session.SessionSpecContainer.invoke(SessionSpecContainer.java:323) [:1.7.17]

at org.jboss.ejb3.session.SessionSpecContainer.invoke(SessionSpecContainer.java:380) [:1.7.17]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [:1.6.0_22]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [:1.6.0_22]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [:1.6.0_22]

at java.lang.reflect.Method.invoke(Method.java:597) [:1.6.0_22]

at org.jboss.ejb3.proxy.impl.handler.session.SessionLocalProxyInvocationHandler$LocalContainerInvocation.invokeTarget(SessionLocalProxyInvocationHandler.java:184) [:1.0.11]

at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:111) [jboss-aop.jar:2.2.1.GA]

at org.jboss.ejb3.async.impl.interceptor.AsynchronousClientInterceptor.invoke(AsynchronousClientInterceptor.java:143) [:1.7.17]

at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]

at org.jboss.ejb3.proxy.impl.handler.session.SessionLocalProxyInvocationHandler$LocalInvokableContextHandler.invoke(SessionLocalProxyInvocationHandler.java:159) [:1.0.11]

at $Proxy294.invoke(Unknown Source) at org.jboss.ejb3.proxy.impl.handler.session.SessionProxyInvocationHandlerBase.invoke(SessionProxyInvocationHandlerBase.java:185) [:1.0.11]

at $Proxy292.addDialInParticipant(Unknown Source)    at com.tp.services.webservices.IVRCallControl.addParticipant(IVRCallControl.java:57)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [:1.6.0_22]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [:1.6.0_22]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [:1.6.0_22]

at java.lang.reflect.Method.invoke(Method.java:597) [:1.6.0_22]

at org.jboss.wsf.common.invocation.AbstractInvocationHandlerJSE.invoke(AbstractInvocationHandlerJSE.java:102) [:1.4.1.GA]

at org.jboss.wsf.stack.cxf.AbstractInvoker._invokeInternal(AbstractInvoker.java:164) [:3.4.1.GA]

at org.jboss.wsf.stack.cxf.AbstractInvoker.invoke(AbstractInvoker.java:112) [:3.4.1.GA]

at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:58) [:2.3.1]

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [:1.6.0_22]

at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [:1.6.0_22]

at java.util.concurrent.FutureTask.run(FutureTask.java:138) [:1.6.0_22]

at org.apache.cxf.workqueue.SynchronousExecutor.execute(SynchronousExecutor.java:37) [:2.3.1]

at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:106) [:2.3.1]

at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:255) [:2.3.1]

at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:113) [:2.3.1]

at org.apache.cxf.transport.servlet.ServletDestination.invoke(ServletDestination.java:97) [:2.3.1]

at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:461) [:2.3.1]

at org.jboss.wsf.stack.cxf.ServletControllerExt.invoke(ServletControllerExt.java:172) [:3.4.1.GA]

at org.jboss.wsf.stack.cxf.RequestHandlerImpl.handleHttpRequest(RequestHandlerImpl.java:57) [:3.4.1.GA]

at org.jboss.wsf.stack.cxf.transport.ServletHelper.callRequestHandler(ServletHelper.java:156) [:3.4.1.GA]

at org.jboss.wsf.stack.cxf.CXFNonSpringServletExt.invoke(CXFNonSpringServletExt.java:90) [:3.4.1.GA]

at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:179) [:2.3.1]

at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:103) [:2.3.1]

at javax.servlet.http.HttpServlet.service(HttpServlet.java:754) [:1.0.0.Final]

at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:159) [:2.3.1]

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:324) [:6.0.0.Final]

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:242) [:6.0.0.Final]

at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:275) [:6.0.0.Final]

at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [:6.0.0.Final]

at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:181) [:6.0.0.Final]

at org.jboss.modcluster.catalina.CatalinaContext$RequestListenerValve.event(CatalinaContext.java:285) [:1.1.0.Final]

at org.jboss.modcluster.catalina.CatalinaContext$RequestListenerValve.invoke(CatalinaContext.java:261) [:1.1.0.Final]

at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:88) [:6.0.0.Final]

at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:100) [:6.0.0.Final]

at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [:6.0.0.Final]

at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [:6.0.0.Final]

at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158) [:6.0.0.Final]

at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [:6.0.0.Final]

at org.jboss.web.tomcat.service.request.ActiveRequestResponseCacheValve.invoke(ActiveRequestResponseCacheValve.java:53) [:6.0.0.Final]

at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:362) [:6.0.0.Final]

at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:877) [:6.0.0.Final]

at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:654) [:6.0.0.Final]

at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:951) [:6.0.0.Final]

at java.lang.Thread.run(Thread.java:662) [:1.6.0_22]

[tomjenkinson]

Hi John,

Couple of questions:

1. Most important: please can you try this on AS7, its totally overhauled and a great choice for deployment: http://www.jboss.org/jbossas/downloads/?

2. What resource did you enlist?

Thanks,

Tom

PS: question 1 is the most important as tracking this down could lead to an AS issue and AS6 is no longer in active development.

[jjfraney]

Tom, Thanks for answering.

1. Most important: please can you try this on AS7, its totally overhauled and a great choice for deployment: http://www.jboss.org/jbossas/downloads/?

Yes.  I understand: AS7 is where the developers' attention is now invested.

Are you certain this is not a configuration or application level problem?  What makes you certain?

The stack trace shows jboss disconnected the remote corba object from the poa permaturely, apparently.  What conditions does the jboss jts disconnect the object from the poa?   Maybe this is a bug in AS6, but is this incorrect behavior under all conditions?  Here is the hope that someone encountered this while AS6 was shiny and new, and remembers what they did.

2. What resource did you enlist?

Two databases, both mysql database.  One is the jboss database that stores a timer, the other is our application's database.

We discovered after I posted this discussion that these are not setup as 'xa datasources'.  That is a configuration error we will correct.  Can anyone confirm that the error above would be caused by using 'local datasources'?

Thanks,

John

[tomjenkinson]

Hi John,

Unfortunately I am not too familiar with AS6 so can't say for sure. Once we get you on AS7 I will be in a better position to confirm whether or not this is a configuration issue.

As to not being xa datasources, it could well be that the error was caused by that, certainly any expected 2PC behavior would not have occurred so that is a good change to start with!

Tom

[jjfraney]

The root cause of this problem is use of local datasource.  xa datasource is required.