Thread deadlock detected using JCA on WLS

Hi,

Incidentally we are experiencing ‘hangs’ in our (quite complex) enterprise application. During such a situation I created a thread dump and noticed the following information:

1LKDEADLOCK Deadlock detected !!!
NULL ---------------------
NULL
2LKDEADLOCKTHR Thread “Thread-7” (0x397BB5B0)
3LKDEADLOCKWTR is waiting for:
4LKDEADLOCKMON sys_mon_t:0x37280CD8 infl_mon_t: 0x00000000:
4LKDEADLOCKOBJ
com.softwareag.tamino.db.api.invocation.http.THTTPInvocation@97926DD0/97926DD8:
3LKDEADLOCKOWN which is owned by:
2LKDEADLOCKTHR Thread “ExecuteThread: ‘16’ for queue: ‘default’” (0x32B9E8C0)
3LKDEADLOCKWTR which is waiting for:
4LKDEADLOCKMON sys_mon_t:0x3B189F48 infl_mon_t: 0x00000000:
4LKDEADLOCKOBJ
com.softwareag.tamino.db.api.connection.TTransactionModeCoordinator@97926B78/97
926B80:
3LKDEADLOCKOWN which is owned by:
2LKDEADLOCKTHR Thread “Thread-7” (0x397BB5B0)

Here are fragments of the stack traces of both threads:

“Thread-7”: the container commits the connection after SchedulerBean::scheduleTasks finished succesfully:

3XMTHREADINFO “Thread-7” (TID:0x9BB6CB48, sys_thread_t:0x397BB5B0, state:CW, native ID:0x8083) prio=5
4XESTACKTRACE at com.softwareag.tamino.db.api.invocation.TAbstractInvocation.doTemplateInvoke(Unknown Source)(Compiled Code)
4XESTACKTRACE at com.softwareag.tamino.db.api.invocation.TAbstractInvocation.invoke(Unknown Source)(Compiled Code)
4XESTACKTRACE at com.softwareag.tamino.db.api.accessor.TAbstractAccessor.invoke(Unknown Source)(Inlined Compiled Code)
4XESTACKTRACE at com.softwareag.tamino.db.api.accessor.TGenericAccessorImpl.execute(Unknown Source)(Compiled Code)
4XESTACKTRACE at com.softwareag.tamino.db.api.accessor.TGenericAccessorImpl.execute(Unknown Source)(Inlined Compiled Code)
4XESTACKTRACE at com.softwareag.tamino.db.api.connection.TLocalTransactionMode.commit(Unknown Source)(Compiled Code)
4XESTACKTRACE at com.softwareag.tamino.db.api.connector.spi.TaminoLocalTransaction.commit(Unknown Source)(Compiled Code)
4XESTACKTRACE at weblogic.connector.common.internal.LocalTransXAWrapper.commit(LocalTransXAWrapper.java(Compiled Code))
4XESTACKTRACE at weblogic.transaction.internal.ServerResourceInfo.commit(ServerResourceInfo.java(Compiled Code))
4XESTACKTRACE at weblogic.transaction.internal.ServerResourceInfo.commit(ServerResourceInfo.java(Compiled Code))
4XESTACKTRACE at weblogic.transaction.internal.ServerSCInfo.startCommit(ServerSCInfo.java(Compiled Code))
4XESTACKTRACE at weblogic.transaction.internal.ServerTransactionImpl.localCommit(ServerTransactionImpl.java(Compiled Code))
4XESTACKTRACE at weblogic.transaction.internal.ServerTransactionImpl.globalRetryCommit(ServerTransactionImpl.java(Compiled Code))
4XESTACKTRACE at weblogic.transaction.internal.ServerTransactionImpl.globalCommit(ServerTransactionImpl.java(Inlined Compiled Code))
4XESTACKTRACE at weblogic.transaction.internal.ServerTransactionImpl.internalCommit(ServerTransactionImpl.java(Compiled Code))
4XESTACKTRACE at weblogic.transaction.internal.ServerTransactionImpl.commit(ServerTransactionImpl.java(Compiled Code))
4XESTACKTRACE at weblogic.ejb20.internal.BaseEJBObject.postInvoke(BaseEJBObject.java(Compiled Code))
4XESTACKTRACE at weblogic.ejb20.internal.StatelessEJBObject.postInvoke(StatelessEJBObject.java(Compiled Code))
4XESTACKTRACE at nl.schiphol.ciss.logic.scheduler.session.SchedulerBean_uhfel7_EOImpl.scheduleTasks(SchedulerBean_uhfel7_EOImpl.java(Compiled Code))
4XESTACKTRACE at nl.schiphol.ciss.jms.consumer.beans.MessageConsumerBean.onMessage(Unknown Source)(Compiled Code)
4XESTACKTRACE at weblogic.ejb20.internal.MDListener.execute(MDListener.java(Compiled Code))
4XESTACKTRACE at weblogic.ejb20.internal.MDListener.transactionalOnMessage(MDListener.java(Compiled Code))
4XESTACKTRACE at weblogic.ejb20.internal.MDListener.onMessage(MDListener.java(Compiled Code))
4XESTACKTRACE at com.seebeyond.jms.client.STCMessageConsumer.onMessage(STCMessageConsumer.java(Compiled Code))
4XESTACKTRACE at com.seebeyond.jms.client.STCSession.onMessage(STCSession.java(Compiled Code))
4XESTACKTRACE at com.seebeyond.jms.sockets.ReceiverSocket.deliverMessage(ReceiverSocket.java(Compiled Code))
4XESTACKTRACE at com.seebeyond.jms.sockets.ThreadPerConnectionMgr$ConnThread.run(ThreadPerConnectionMgr.java:230)

“ExecuteThread: ‘16’ for queue: ‘default’” the FlightBean::updateFlight tries to update a document:

3XMTHREADINFO “ExecuteThread: ‘16’ for queue: ‘default’” (TID:0x800534F0, sys_thread_t:0x32B9E8C0, state:CW, native ID:0x1A1B) prio=5
4XESTACKTRACE at com.softwareag.tamino.db.api.invocation.TAbstractInvocation.doTemplateInvoke(Unknown Source)(Compiled Code)
4XESTACKTRACE at com.softwareag.tamino.db.api.invocation.TAbstractInvocation.invoke(Unknown Source)(Compiled Code)
4XESTACKTRACE at com.softwareag.tamino.db.api.accessor.TAbstractAccessor.invoke(Unknown Source)(Inlined Compiled Code)
4XESTACKTRACE at com.softwareag.tamino.db.api.accessor.TStreamAccessorImpl.process(Unknown Source)(Compiled Code)
4XESTACKTRACE at com.softwareag.tamino.db.api.accessor.TStreamAccessorImpl.update(Unknown Source)(Compiled Code)
4XESTACKTRACE at nl.schiphol.ciss.database.access.AbstractTaminoAccessor.updateDocument(Unknown Source)(Compiled Code)
4XESTACKTRACE at nl.schiphol.ciss.logic.flight.flt.FltAccessor.updateFlt(Unknown Source)(Inlined Compiled Code)
4XESTACKTRACE at nl.schiphol.ciss.logic.flight.flt.FltAccessor.updateFlight(Unknown Source)(Compiled Code)
4XESTACKTRACE at nl.schiphol.ciss.logic.flight.session.FlightBean.updateFlight(Unknown Source)(Compiled Code)
4XESTACKTRACE at nl.schiphol.ciss.logic.flight.session.FlightBean.updateFlight(Unknown Source)(Inlined Compiled Code)
4XESTACKTRACE at nl.schiphol.ciss.logic.flight.session.FlightBean_yugk9c_EOImpl.updateFlight(FlightBean_yugk9c_EOImpl.java(Compiled Code))
4XESTACKTRACE at nl.schiphol.ciss.control.processbeans.flight.UpdateFlight.execute(Unknown Source)(Compiled Code)
4XESTACKTRACE at org.apache.commons.scaffold.util.ProcessBeanBase.execute(Unknown Source)(Inlined Compiled Code)
4XESTACKTRACE at nl.schiphol.ciss.control.processbeans.base.AbstractProcessBean.execute(Unknown Source)(Compiled Code)
4XESTACKTRACE at nl.schiphol.ciss.web.actions.process.BaseProcessAction.executeLogic(Unknown Source)(Compiled Code)
4XESTACKTRACE at nl.schiphol.ciss.web.actions.process.UpdateProcessAction.executeLogic(Unknown Source)(Compiled Code)
4XESTACKTRACE at nl.schiphol.ciss.web.actions.base.AbstractHelperAction.executeLogic(Unknown Source)(Compiled Code)
4XESTACKTRACE at org.apache.struts.scaffold.BaseAction.execute(BaseAction.java(Compiled Code))


Maybe someone can advice on further analysis of the problem.

Best regards,

Django

Note: there are reasons to assume WLS (700fp4) JCA/JTA is not working properly especially using component demarcated transactions and that it does return invalid connections from the pool. We incidentally see the following exception:

com.softwareag.common.instrumentation.contract.ViolatedPrecondition: Violated Precondition: Connection handle is invalid!
at com.softwareag.common.instrumentation.contract.Precondition.check(Unknown Source)(Inlined Compiled Code)
at com.softwareag.tamino.db.api.connector.spi.TConnectionWrapper.setIsolationDegree(Unknown Source)(Compiled Code)
at java.lang.reflect.Method.invoke(Native Method)
at weblogic.connector.common.internal.ConnectionWrapper.invoke(ConnectionWrapper.java(Compiled Code))
at $Proxy112.setIsolationDegree(Unknown Source)(Compiled Code)
at nl.schiphol.ciss.database.access.AbstractTaminoAccessor.getConnectionWithProtectedLock(Unknown Source)(Compiled Code)
at nl.schiphol.ciss.logic.ejb.AbstractSessionBean.getConnectionWithProtectedLock(Unknown Source)(Inlined Compiled Code)
at nl.schiphol.ciss.logic.scheduler.session.SchedulerBean.scheduleTasks(Unknown Source)(Compiled Code)
at nl.schiphol.ciss.logic.scheduler.session.SchedulerBean_uhfel7_EOImpl.scheduleTasks(SchedulerBean_uhfel7_EOImpl.java(Compiled Code))
at nl.schiphol.ciss.jms.consumer.beans.MessageConsumerBean.onMessage(Unknown Source)(Compiled Code)
at weblogic.ejb20.internal.MDListener.execute(MDListener.java(Compiled Code))
at weblogic.ejb20.internal.MDListener.transactionalOnMessage(MDListener.java(Compiled Code))
at weblogic.ejb20.internal.MDListener.onMessage(MDListener.java(Compiled Code))
at com.seebeyond.jms.client.STCMessageConsumer.onMessage(STCMessageConsumer.java(Compiled Code))
at com.seebeyond.jms.client.STCSession.onMessage(STCSession.java(Compiled Code))
at com.seebeyond.jms.sockets.ReceiverSocket.deliverMessage(ReceiverSocket.java(Compiled Code))
at com.seebeyond.jms.sockets.ThreadPerConnectionMgr$ConnThread.run(ThreadPerConnectionMgr.java:230)

Hi,

We’d need a bit more of study on your issue, as for now could you kindly confirm if you are really using WSL or the HTTP mode. I ask this because, after having a closer look at the given log we observe an entry which states the following -

4LKDEADLOCKOBJ
com.softwareag.tamino.db.api.invocation.http.THTTPInvocation@97926DD0/97926DD8


Let me mention here that THTTPInvocation is exclusively used only incase of HTTP invocation mode. If your source is using WSL we’d rater expect TWSLInvocation.

We’d appreciate if you could confirm that at the earlist.

Rahul Roy

Tamino API for Java
Software AG (INDIA)

Hi Rahul,

Sorry for the confusion but I meant WebLogic Server and not web server less!

Regards,

Django

PS Maybe the admin can change the title to end further confusion

Hi Django,

Firstly i apologise for the delay in replying. We tried to analyse your problem but I don’t think that we have enough information to get down to the roots. Especially, without seeing the code that produced the trace, I fear it may be impossible for us being at this position to diagnose. Also, given the complexity of the system at Schiphol, I fear that the best we can offer is some hints on what the problem might be. - Perhaps it would be helpful to address the second problem first.

When setting the isolation degree there should not be a precondition error in the Tamino API. It would be useful to discover if there are other errors along these lines, as these could be contributing to the “hang” problem.

Another useful step might be to activate logging in the Tamino API. (This is done by setting the system property com.softwareag.LoggingOn=true) Once logging is activated, output can be controlled via the log4j.properties file. (The first occurrence of this file in the classpath is used.) This will provide some information beyond the error messages, so hopefully we can figure out the conditions leading to the error.

A rather more wild idea to try would be to de-activate the JIT compiler. Exactly how to do this will depend on the JVM being used to execute the code. Doing this will eliminate the possibility that the [human written] code is fine and the problem is just being introduced by the JVM.

I hope that is helpful for now. If not, I’d request you to contact the Software AG regional support staff and they could possibily take care of this issue for you.

Rahul Roy

Tamino API for Java
Software AG (INDIA)

For you information, we are facing the same issue when we have a high load on a production system.

If you did find any solution on your side, please tell the forum.

On my side, I am working trough support to solve it. [Our now escalated request has reference #539574.]


Software AG Belgium, Business Consulting Services

We have not yet resolved the problem. We have opened support requests with both Bea and Software AG (reference #547178).

We also experience two other problems that may be related to this issue:
1. ViolatedPrecondition. Occasionally we see the following stack trace, typically after a garbage collect:

<AF[729]: Allocation Failure. need 760 bytes, 183322 ms since last AF>
<AF[729]: managing allocation failure, action=1 (0/1070594560) (3145728/3145728)>
<GC(729): GC cycle started Sun Jul 4 11:05:11 2004
<GC(729): freed 1011229320 bytes, 94% free (1014375048/1073740288), in 110 ms>
<GC(729): mark: 92 ms, sweep: 18 ms, compact: 0 ms>
<GC(729): refs: soft 0 (age >= 32), weak 5, final 3661, phantom 0>
<AF[729]: completed in 112 ms>
WARNING: ViolatedPrecondition detected. Treating is like a document lock exception to allow retry.
com.softwareag.common.instrumentation.contract.ViolatedPrecondition: Violated Precondition: Connection handle is invalid!
at com.softwareag.common.instrumentation.contract.Precondition.check(Unknown Source)(Inlined Compiled Code)
at com.softwareag.tamino.db.api.connector.spi.TConnectionWrapper.newStreamAccessor(Unknown Source)(Compiled Code)
at java.lang.reflect.Method.invoke(Native Method)
at weblogic.connector.common.internal.ConnectionWrapper.invoke(ConnectionWrapper.java(Compiled Code))
at $Proxy112.newStreamAccessor(Unknown Source)(Compiled Code)
at nl.schiphol.ciss.database.access.AbstractTaminoAccessor.getStreamAccessor(Unknown Source)(Compiled Code)
at nl.schiphol.ciss.database.access.AbstractTaminoAccessor.readLockedDocument(Unknown Source)(Compiled Code)
at nl.schiphol.ciss.logic.flight.flt.FltAccessor.getLockedFltByCompletelyReasoneableArguments(Unknown Source)(Inlined Compiled Code)
at nl.schiphol.ciss.logic.flight.flt.FltAccessor.updateFlight(Unknown Source)(Compiled Code)
at nl.schiphol.ciss.logic.flight.session.FlightBean.updateFlight(Unknown Source)(Compiled Code)
at nl.schiphol.ciss.logic.flight.session.FlightBean_yugk9c_EOImpl.updateFlight(FlightBean_yugk9c_EOImpl.java(Compiled Code))
at nl.schiphol.ciss.jms.consumer.invokers.FlightInvoker.invoke(Unknown Source)(Compiled Code)
at nl.schiphol.ciss.jms.consumer.invokers.Invoker.process(Unknown Source)(Compiled Code)
at nl.schiphol.ciss.jms.consumer.beans.MessageProcessorBean.processMessage(Unknown Source)(Compiled Code)
at nl.schiphol.ciss.jms.consumer.beans.MessageProcessorBean_mlbwx7_EOImpl.processMessage(MessageProcessorBean_mlbwx7_EOImpl.java(Compiled Code))
at nl.schiphol.ciss.jms.consumer.beans.MessageConsumerBean.onMessage(Unknown Source)(Compiled Code)
at weblogic.ejb20.internal.MDListener.execute(MDListener.java(Compiled Code))
at weblogic.ejb20.internal.MDListener.transactionalOnMessage(MDListener.java(Compiled Code))
at weblogic.ejb20.internal.MDListener.onMessage(MDListener.java(Compiled Code))
at com.seebeyond.jms.client.STCMessageConsumer.onMessage(STCMessageConsumer.java(Compiled Code))
at com.seebeyond.jms.client.STCSession.onMessage(STCSession.java(Compiled Code))
at com.seebeyond.jms.sockets.ReceiverSocket.deliverMessage(ReceiverSocket.java(Compiled Code))
at com.seebeyond.jms.sockets.ThreadPerConnectionMgr$ConnThread.run(ThreadPerConnectionMgr.java(Compiled Code))

2. After the application has run for a while Weblogic is detecting a lot of connection leaks.

Are you also having these problems with your application?

Regards,
Sebastiaan

We had exact same deadlock with the thread dump. This issue was solved by Software AG in 4.2.1.7. This problem went away after we upgraded to 4.2.1.7. Make sure you upgrade to latest Tamino JAVA API for this version.