This discussion is archived
6 Replies Latest reply: May 26, 2011 1:06 PM by PHCharbonneau RSS

Instance Crashed

845782 Newbie
Currently Being Moderated
Hi,

We are using Weblogic Server 8.1 sp2. Today, two instances was aborted due to struck thread and I would like to know how to troubleshoot and analyze this scenario to identify the route cause. I am a newbie to this area of analyzing and would greatly appreciate inputs on this regard. I have used the Samurai tool to analyze the thread dump but could not take much leads.

As the dump is too big, i could not paste here under.


Regards,
NZ
  • 1. Re: Instance Crashed
    PHCharbonneau Explorer
    Currently Being Moderated
    Hi NZ,

    As a starting point, can you please provide in the post a few Thread Stack Trace (4-5) from the Weblogic default queue.

    Since your Weblogic version is 8.1 and unless you defined your own Execute Queue, the Thread data we are interested in are:

    "ExecuteThread: '0' for queue: 'weblogic.kernel.Default'"
    "ExecuteThread: '1' for queue: 'weblogic.kernel.Default'"
    "ExecuteThread: '2' for queue: 'weblogic.kernel.Default'"
    .....................

    You will find these Threads along with the associated state and Stack Trace within the Thread Dump snapshot you generated.

    I will show you quickly how to analyse once you provide these sample Threads.

    Regards,
    P-H
    http://javaeesupportpatterns.blogspot.com/
  • 2. Re: Instance Crashed
    845782 Newbie
    Currently Being Moderated
    Hi,

    Managed to extract out the below snippet. Believe this is what you wanted to look at

    "ExecuteThread: '4' for queue: 'weblogic.kernel.Default'" daemon prio=5 tid=0xc82038 nid=0x10 in Object.wait() [6c781000..6c7819bc]
         at java.lang.Object.wait(Native Method)
         - waiting on <9144f7a0> (a weblogic.kernel.ExecuteThread)
         at java.lang.Object.wait(Object.java:426)
         at weblogic.kernel.ExecuteThread.waitForRequest(ExecuteThread.java:145)
         - locked <9144f7a0> (a weblogic.kernel.ExecuteThread)
         at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:164)

    "ExecuteThread: '3' for queue: 'weblogic.kernel.Default'" daemon prio=5 tid=0xc81c40 nid=0xf in Object.wait() [6c881000..6c8819bc]
         at java.lang.Object.wait(Native Method)
         - waiting on <9144f820> (a weblogic.kernel.ExecuteThread)
         at java.lang.Object.wait(Object.java:426)
         at weblogic.kernel.ExecuteThread.waitForRequest(ExecuteThread.java:145)
         - locked <9144f820> (a weblogic.kernel.ExecuteThread)
         at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:164)

    "ExecuteThread: '2' for queue: 'weblogic.kernel.Default'" daemon prio=5 tid=0xc811f8 nid=0xe in Object.wait() [6c981000..6c9819bc]
         at java.lang.Object.wait(Native Method)
         - waiting on <9144f8a0> (a weblogic.kernel.ExecuteThread)
         at java.lang.Object.wait(Object.java:426)
         at weblogic.kernel.ExecuteThread.waitForRequest(ExecuteThread.java:145)
         - locked <9144f8a0> (a weblogic.kernel.ExecuteThread)
         at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:164)

    "ExecuteThread: '1' for queue: 'weblogic.kernel.Default'" daemon prio=5 tid=0x25b580 nid=0xd in Object.wait() [6ca81000..6ca819bc]
         at java.lang.Object.wait(Native Method)
         - waiting on <9144f920> (a weblogic.kernel.ExecuteThread)
         at java.lang.Object.wait(Object.java:426)
         at weblogic.kernel.ExecuteThread.waitForRequest(ExecuteThread.java:145)
         - locked <9144f920> (a weblogic.kernel.ExecuteThread)
         at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:164)

    "ExecuteThread: '0' for queue: 'weblogic.kernel.Default'" daemon prio=5 tid=0xd697c8 nid=0xc in Object.wait() [6cb81000..6cb819bc]
         at java.lang.Object.wait(Native Method)
         - waiting on <9144f9a0> (a weblogic.kernel.ExecuteThread)
         at java.lang.Object.wait(Object.java:426)
         at weblogic.kernel.ExecuteThread.waitForRequest(ExecuteThread.java:145)
         - locked <9144f9a0> (a weblogic.kernel.ExecuteThread)
         at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:164

    Regards,
    NZ
  • 3. Re: Instance Crashed
    PHCharbonneau Explorer
    Currently Being Moderated
    Thanks NZ,

    Yes but these Threads are basically not doing anything, just waiting for an incoming request.

    Please look for Weblogic Threads not involved in the at weblogic.kernel.ExecuteThread.waitForRequest(ExecuteThread.java:145).

    Regards,
    P-H
  • 4. Re: Instance Crashed
    845782 Newbie
    Currently Being Moderated
    Hi,

    We hit the instance crash again and this time around using Samurai tool, i see several areas where deadlock is been noticed. One of the code snippets we found on deadlock is below. The corresponding application code referred at line no. 898 is just a simple statement that is trying to close a statement withing a catch block.Not sure why this is causing a deadlock.Need assistance to troubleshoot on this.


    at weblogic.jdbc.wrapper.Statement.close(Statement.java:293)
    at com.crimsonlogic.trade.sdec.sau.util.CommonUtil.getHijri(CommonUtil.java:898)
    at com.crimsonlogic.trade.sdec.sau.model.SAUSDECVehicleTransaction.setHijrifromGregorian_trnDate(SAUSDECVehicleTransaction.java:261)
    at com.crimsonlogic.trade.sdec.sau.dao.SAUSDECVehicleTransactionDAOImpl.search(SAUSDECVehicleTransactionDAOImpl.java:175)
    at com.crimsonlogic.trade.sdec.sau.dao.SAUSDECMasterDAOImpl.searchSDECMsg(SAUSDECMasterDAOImpl.java:310)
    at com.crimsonlogic.trade.sdec.sau.ejb.SAUSDECSvcBean.search(SAUSDECSvcBean.java:452)
    at com.crimsonlogic.trade.sdec.sau.ejb.SAUSDECSvcBean_bxozws_EOImpl.search(SAUSDECSvcBean_bxozws_EOImpl.java:1290)



    Found one Java-level deadlock:
    =============================
    "asyncDelivery42":
    waiting to lock monitor 0xdfb820 (object 0x87351698, a oracle.jdbc.driver.OracleConnection),
    which is held by "ExecuteThread: '93' for queue: 'weblogic.kernel.Default'"
    "ExecuteThread: '93' for queue: 'weblogic.kernel.Default'":
    waiting to lock monitor 0xdbf550 (object 0x873782b0, a oracle.jdbc.driver.OracleCallableStatement),
    which is held by "asyncDelivery42"

    Java stack information for the threads listed above:
    ===================================================
    "asyncDelivery42":
    at oracle.jdbc.driver.OracleConnection.getDefaultRowPrefetch(OracleConnection.java:1866)
    - waiting to lock <87351698> (a oracle.jdbc.driver.OracleConnection)
    at oracle.jdbc.driver.OracleStatement.setPrefetchInternal(OracleStatement.java:1635)
    at oracle.jdbc.driver.OracleStatement.setFetchSize(OracleStatement.java:6505)
    - locked <873782b0> (a oracle.jdbc.driver.OracleCallableStatement)
    at weblogic.jdbc.common.internal.ConnectionEnv.cleanUpStatementForReUse(ConnectionEnv.java:1091)
    at weblogic.jdbc.common.internal.ConnectionEnv.returnCachedStatement(ConnectionEnv.java:883)
    at weblogic.jdbc.wrapper.Statement.internalClose(Statement.java:271)
    at weblogic.jdbc.wrapper.Statement.close(Statement.java:293)
    at com.crimsonlogic.trade.sdec.sau.util.CommonUtil.getHijri(CommonUtil.java:898)
    at com.crimsonlogic.trade.sdec.sau.model.SAUSDECVehicleTransaction.setHijrifromGregorian_trnDate(SAUSDECVehicleTransaction.java:261)
    at com.crimsonlogic.trade.sdec.sau.dao.SAUSDECVehicleTransactionDAOImpl.search(SAUSDECVehicleTransactionDAOImpl.java:175)
    at com.crimsonlogic.trade.sdec.sau.dao.SAUSDECMasterDAOImpl.searchSDECMsg(SAUSDECMasterDAOImpl.java:310)
    at com.crimsonlogic.trade.sdec.sau.ejb.SAUSDECSvcBean.search(SAUSDECSvcBean.java:452)
    at com.crimsonlogic.trade.sdec.sau.ejb.SAUSDECSvcBean_bxozws_EOImpl.search(SAUSDECSvcBean_bxozws_EOImpl.java:1290)
    at com.crimsonlogic.trade.sdec.sau.ejb.SAUSDECSvcBean_bxozws_EOImpl_CBV.search(Unknown Source)
    at com.crimsonlogic.trade.sdec.sau.business.SAUSDECDelegate.search(SAUSDECDelegate.java:278)
    at com.crimsonlogic.trade.sdec.sau.business.SDECMsgProcessor.process(SDECMsgProcessor.java:72)
    at com.crimsonlogic.trade.sau.msg.ejb.MsgSvcBean.processMsg(MsgSvcBean.java:201)
    at com.crimsonlogic.trade.sau.msg.ejb.MsgSvcBean_5z2zq6_EOImpl.processMsg(MsgSvcBean_5z2zq6_EOImpl.java:1340)
    at com.crimsonlogic.trade.sau.msg.util.MsgDelegate.processMsg(MsgDelegate.java:196)
    at com.crimsonlogic.trade.sau.msg.ejb.ProcessPortMsgIDMDB.onMessage(ProcessPortMsgIDMDB.java:72)
    at weblogic.ejb20.internal.MDListener.execute(MDListener.java:382)
    at weblogic.ejb20.internal.MDListener.transactionalOnMessage(MDListener.java:316)
    at weblogic.ejb20.internal.MDListener.onMessage(MDListener.java:281)
    at com.ibm.mq.jms.MQMessageConsumer.receiveAsyncQ(MQMessageConsumer.java:2431)
    - locked <7bc2f570> (a java.lang.Object)
    - locked <7bc2f4e8> (a com.ibm.mq.jms.MQQueueReceiver)
    at com.ibm.mq.jms.MQMessageConsumer.receiveAsync(MQMessageConsumer.java:3816)
    - locked <7bc2f4e8> (a com.ibm.mq.jms.MQQueueReceiver)
    at com.ibm.mq.jms.SessionAsyncHelper.run(SessionAsyncHelper.java:420)
    at java.lang.Thread.run(Thread.java:536)
    "ExecuteThread: '93' for queue: 'weblogic.kernel.Default'":
    at oracle.jdbc.driver.OracleCallableStatement.sendBatch(OracleCallableStatement.java:446)
    - waiting to lock <873782b0> (a oracle.jdbc.driver.OracleCallableStatement)
    at oracle.jdbc.driver.OracleConnection.commit(OracleConnection.java:1336)
    - locked <87351698> (a oracle.jdbc.driver.OracleConnection)
    at weblogic.jdbc.wrapper.JTSConnection.internalCommit(JTSConnection.java:362)
    at weblogic.jdbc.wrapper.JTSXAResourceImpl.commit(JTSXAResourceImpl.java:56)
    at weblogic.transaction.internal.XAServerResourceInfo.commit(XAServerResourceInfo.java:1223)
    at weblogic.transaction.internal.XAServerResourceInfo.commit(XAServerResourceInfo.java:472)
    at weblogic.transaction.internal.ServerSCInfo.startCommit(ServerSCInfo.java:421)
    at weblogic.transaction.internal.ServerTransactionImpl.localCommit(ServerTransactionImpl.java:1761)
    at weblogic.transaction.internal.ServerTransactionImpl.globalRetryCommit(ServerTransactionImpl.java:2384)
    at weblogic.transaction.internal.ServerTransactionImpl.globalCommit(ServerTransactionImpl.java:2315)
    at weblogic.transaction.internal.ServerTransactionImpl.internalCommit(ServerTransactionImpl.java:255)
    at weblogic.transaction.internal.ServerTransactionImpl.commit(ServerTransactionImpl.java:221)
    at weblogic.ejb20.internal.BaseEJBObject.postInvoke(BaseEJBObject.java:289)
    at weblogic.ejb20.internal.StatelessEJBObject.postInvoke(StatelessEJBObject.java:141)
    at com.crimsonlogic.trade.sau.msg.ejb.MsgSvcBean_5z2zq6_EOImpl.checkLinkedRefIDStatus(MsgSvcBean_5z2zq6_EOImpl.java:110)
    at com.crimsonlogic.trade.sau.msg.util.MsgDelegate.checkLinkedRefIDStatus(MsgDelegate.java:824)
    at com.crimsonlogic.trade.sau.msg.action.ProcessMsg.getProcessMsgIDList(ProcessMsg.java:260)
    at com.crimsonlogic.trade.sau.msg.action.ProcessMsg._process(ProcessMsg.java:123)
    at com.crimsonlogic.trade.sau.msg.action.AbstractAction.process(AbstractAction.java:61)
    at com.crimsonlogic.trade.sau.msg.servlet.SAUMsgProcessServlet.doPost(SAUMsgProcessServlet.java:102)
    at com.crimsonlogic.trade.sau.msg.servlet.SAUMsgProcessServlet.doGet(SAUMsgProcessServlet.java:52)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:740)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
    at weblogic.servlet.internal.ServletStubImpl$ServletInvocationAction.run(ServletStubImpl.java:971)
    at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:402)
    at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:305)
    at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:6354)
    at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:317)
    at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:118)
    at weblogic.servlet.internal.WebAppServletContext.invokeServlet(WebAppServletContext.java:3635)
    at weblogic.servlet.internal.ServletRequestImpl.execute(ServletRequestImpl.java:2585)
    at weblogic.kernel.ExecuteThread.execute(ExecuteThread.java:197)
    at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:170)

    Found 2 deadlocks.

    Regards,
    Nawaz
  • 5. Re: Instance Crashed
    Rohit Jaiswal Newbie
    Currently Being Moderated
    Hi,

    File a bug WLS support.

    Regards,
    Rohit Jaiswal
  • 6. Re: Instance Crashed
    PHCharbonneau Explorer
    Currently Being Moderated
    Hi user13006278,

    This Thread deadlock is quite interesting and showing 2 separate Threads involved in a real deadlock situation over JDBC objects. I only saw about 5 similar issues in the past 8 years on other Java EE applications and they were all related to same root cause: separate Threads attempting to use the same JDBC Connection at the same time from the application.

    In your situation:

    Thread #93 acquired a lock on JDBC Connection object <87351698> but is waiting to acquire a lock on OracleCallableStatement <873782b0> in order to complete its JTA TX commit.
    Such Statement object is already locked by a non Weblogic Thread “asyncDelivery42” (async / MQSeries related) but also waiting to acquire a lock on the SAME JDBC Connection <87351698>.

    The key problem is the fact that both Threads are attempting to use the same JDBC Connection object at the same time. This should never happen. You application must guarantee that each Thread will use a different JDBC Connection for each transaction otherwise deadlock or other unexpected behaviours are to be expected.

    Recommendations:

    -     Please provide us with code snippet on how you are creating and managing your JDBC Connection objects; especially perform a close code review of com.crimsonlogic.trade.sdec.sau.util.CommonUtil. Are you trying to statically cache any JDBC Connection object? The JDBC DataSource (if using Connection Pool) should be the only object cached; any JDBC Connection created by the DriverManager or returned from the Weblogic pool must be closed explicitely in a finally{} block after each Thread operation and must be available for garbage collection after any transaction e.g. no caching.

    We had the exact same issue with another platform last year. The application was caching the returned JDBC Connection and was attempting to "share" it across all the Threads which did lead to deadlock and severe impact (Thread depletion) to the production enviornment. The solution was to configure proper Weblogic connection pool and properly handle closure of JDBC related objects in finally{} blocks.

    Regards,
    P-H
    http://javaeesupportpatterns.blogspot.com/

    Edited by: PHCharbonneau on 26-May-2011 1:03 PM

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points