In our production environment, we have a soa suite cluster with 3 nodes. All 3 of the servers keep turning up stuck and hogging threads, and eventually they all grind to a halt where I can't even view composite instances through em. There is a bpel process that is using a dbadapter to poll for records every 5 seconds and then performs some service call outs and other dbadapters. This process is generating thousands of instances a day and I think it is the culprit. If I view the logs, I see one of the dbadapters that it calls out to fails occasionally with a PK violation. I looked at the developer's code, and they have no error handling in the process at all. In the logs, there will the a hit for the PK violation, then about 10 minutes later the a STUCK thread gets logged(the configured timeout is 600 seconds, or 10 minutes). Would not handling an error in a BPEL process hog/STUCK a thread? I need to be able to show what code is causing the issue so I can have a resolution path.
I also see a note in the trace about something holding a lock:
Holding lock: oracle.jdbc.driver.T4CConnection@1fbc3486[thin lock]....would that be an un-rolled back transaction?
Here is the dump of the STUCK thread. Any help is greatly appreciated. Thanks!
<Aug 5, 2011 10:30:02 AM EDT> <Error> <WebLogicServer> <BEA-000337> <[STUCK] ExecuteThread: '64' for queue: 'weblogic.kernel.Default (self-tuning)' has been busy for "634" seconds working on the request "oracle.soa.management.internal.ejb.impl.FacadeFinderBean_4vacyo_FacadeFinderBeanImpl", which is more than the configured time (StuckThreadMaxTime) of "600" seconds. Stack trace:
Thread-517 "[STUCK] ExecuteThread: '64' for queue: 'weblogic.kernel.Default (self-tuning)'" <alive, in native, suspended, priority=1, DAEMON> {
jrockit.net.SocketNativeIO.readBytesPinned(SocketNativeIO.java:???)
jrockit.net.SocketNativeIO.socketRead(SocketNativeIO.java:24)
java.net.SocketInputStream.socketRead0(SocketInputStream.java:???)
java.net.SocketInputStream.read(SocketInputStream.java:107)
oracle.net.nt.MetricsEnabledInputStream.read(TcpNTAdapter.java:553)
oracle.net.ns.Packet.receive(Packet.java:249)
oracle.net.ns.DataPacket.receive(DataPacket.java:94)
oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:168)
oracle.net.ns.NetInputStream.read(NetInputStream.java:113)
oracle.net.ns.NetInputStream.read(NetInputStream.java:96)
oracle.net.ns.NetInputStream.read(NetInputStream.java:81)
oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:120)
oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:75)
oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1081)
oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1062)
oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:588)
oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:70)
oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:854)
oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:918)
oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1252)
oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3541)
oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3605)
^-- Holding lock: oracle.jdbc.driver.T4CConnection@1fbc3486[thin lock]
oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery(OraclePreparedStatementWrapper.java:1667)
weblogic.jdbc.wrapper.PreparedStatement.executeQuery(PreparedStatement.java:123)
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeSelect(DatabaseAccessor.java:887)
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:541)
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:530)
org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:521)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:202)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:192)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:254)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelect(DatasourceCallQueryMechanism.java:245)
org.eclipse.persistence.queries.DataReadQuery.executeNonCursor(DataReadQuery.java:188)
org.eclipse.persistence.queries.DataReadQuery.executeDatabaseQuery(DataReadQuery.java:141)
org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:603)
org.eclipse.persistence.queries.DataReadQuery.execute(DataReadQuery.java:115)
org.eclipse.persistence.queries.DatabaseQuery.executeInUnitOfWork(DatabaseQuery.java:589)
org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2898)
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1218)
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1190)
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1176)
org.eclipse.persistence.internal.jpa.EJBQueryImpl.executeReadQuery(EJBQueryImpl.java:378)
org.eclipse.persistence.internal.jpa.EJBQueryImpl.getSingleResult(EJBQueryImpl.java:701)
weblogic.deployment.TransactionalEntityManagerProxyImpl$QueryImpl.getSingleResult(TransactionalEntityManagerProxyImpl.java:232)
com.collaxa.cube.persistence.dao.impl.jpa.JpaCubeInstanceDaoImpl.getNumberOfInstances(JpaCubeInstanceDaoImpl.java:439)
oracle.fabric.CubeServiceEngine.getNumberOfComponentInstances(CubeServiceEngine.java:1962)
oracle.soa.management.internal.ejb.impl.FacadeFinderBeanImpl.getNumberOfComponentInstances(FacadeFinderBeanImpl.java:1618)
oracle.soa.management.internal.ejb.impl.FacadeFinderBeanImpl.getComponentSnapShot(FacadeFinderBeanImpl.java:1653)
sun.reflect.GeneratedMethodAccessor5852.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
java.lang.reflect.Method.invoke(Method.java:575)
com.bea.core.repackaged.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
com.bea.core.repackaged.springframework.jee.intercept.MethodInvocationInvocationContext.proceed(MethodInvocationInvocationContext.java:104)
oracle.security.jps.ee.ejb.JpsAbsInterceptor$1.run(JpsAbsInterceptor.java:88)
oracle.security.jps.util.JpsSubject.doAsPrivileged(JpsSubject.java:299)
oracle.security.jps.ee.util.JpsPlatformUtil.runJaasMode(JpsPlatformUtil.java:406)
oracle.security.jps.wls.JpsWeblogicEjbInterceptor.runJaasMode(JpsWeblogicEjbInterceptor.java:61)
oracle.security.jps.ee.ejb.JpsAbsInterceptor.intercept(JpsAbsInterceptor.java:81)
oracle.security.jps.ee.ejb.JpsInterceptor.intercept(JpsInterceptor.java:101)
sun.reflect.GeneratedMethodAccessor863.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
java.lang.reflect.Method.invoke(Method.java:575)
com.bea.core.repackaged.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
com.bea.core.repackaged.springframework.jee.intercept.JeeInterceptorInterceptor.invoke(JeeInterceptorInterceptor.java:66)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:102)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
com.bea.core.repackaged.springframework.jee.spi.MethodInvocationVisitorImpl.visit(MethodInvocationVisitorImpl.java:37)
weblogic.ejb.container.injection.EnvironmentInterceptorCallbackImpl.callback(EnvironmentInterceptorCallbackImpl.java:22)
com.bea.core.repackaged.springframework.jee.spi.EnvironmentInterceptor.invoke(EnvironmentInterceptor.java:49)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
com.bea.core.repackaged.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:86)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:102)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
com.bea.core.repackaged.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:151)
$Proxy309.getComponentSnapShot(Unknown Source)
oracle.soa.management.internal.ejb.impl.FacadeFinderBean_4vacyo_FacadeFinderBeanImpl.getComponentSnapShot(FacadeFinderBean_4vacyo_FacadeFinderBeanImpl.java:1604)
oracle.soa.management.internal.ejb.impl.FacadeFinderBean_4vacyo_FacadeFinderBeanImpl_WLSkel.invoke(Unknown Source)
weblogic.rmi.internal.BasicServerRef.invoke(BasicServerRef.java:567)
weblogic.rmi.internal.BasicServerRef$1.run(BasicServerRef.java:477)
weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:350)
weblogic.security.service.SecurityManager.runAs(SecurityManager.java:143)
weblogic.rmi.internal.BasicServerRef.handleRequest(BasicServerRef.java:425)
weblogic.rmi.internal.wls.WLSExecuteRequest.run(WLSExecuteRequest.java:117)
weblogic.work.ExecuteThread.execute(ExecuteThread.java:198)
weblogic.work.ExecuteThread.run(ExecuteThread.java:165)
}
>
<Aug 5, 2011 10:30:02 AM EDT> <Notice> <Diagnostics> <BEA-320068> <Watch 'StuckThread' with severity 'Notice' on server 'soa_server1' has triggered at Aug 5, 2011 10:30:02 AM EDT. Notification details:
WatchRuleType: Log
WatchRule: (SEVERITY = 'Error') AND (MSGID = 'BEA-000337')
WatchData: DATE = Aug 5, 2011 10:30:02 AM EDT SERVER = soa_server1 MESSAGE = [STUCK] ExecuteThread: '64' for queue: 'weblogic.kernel.Default (self-tuning)' has been busy for "634" seconds working on the request "oracle.soa.management.internal.ejb.impl.FacadeFinderBean_4vacyo_FacadeFinderBeanImpl", which is more than the configured time (StuckThreadMaxTime) of "600" seconds. Stack trace:
Thread-517 "[STUCK] ExecuteThread: '64' for queue: 'weblogic.kernel.Default (self-tuning)'" <alive, in native, suspended, priority=1, DAEMON> {
jrockit.net.SocketNativeIO.readBytesPinned(SocketNativeIO.java:???)
jrockit.net.SocketNativeIO.socketRead(SocketNativeIO.java:24)
java.net.SocketInputStream.socketRead0(SocketInputStream.java:???)
java.net.SocketInputStream.read(SocketInputStream.java:107)
oracle.net.nt.MetricsEnabledInputStream.read(TcpNTAdapter.java:553)
oracle.net.ns.Packet.receive(Packet.java:249)
oracle.net.ns.DataPacket.receive(DataPacket.java:94)
oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:168)
oracle.net.ns.NetInputStream.read(NetInputStream.java:113)
oracle.net.ns.NetInputStream.read(NetInputStream.java:96)
oracle.net.ns.NetInputStream.read(NetInputStream.java:81)
oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:120)
oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:75)
oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1081)
oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1062)
oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:588)
oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:70)
oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:854)
oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:918)
oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1252)
oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3541)
oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3605)
^-- Holding lock: oracle.jdbc.driver.T4CConnection@1fbc3486[thin lock]
oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery(OraclePreparedStatementWrapper.java:1667)
weblogic.jdbc.wrapper.PreparedStatement.executeQuery(PreparedStatement.java:123)
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeSelect(DatabaseAccessor.java:887)
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:541)
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:530)
org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:521)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:202)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:192)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:254)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelect(DatasourceCallQueryMechanism.java:245)
org.eclipse.persistence.queries.DataReadQuery.executeNonCursor(DataReadQuery.java:188)
org.eclipse.persistence.queries.DataReadQuery.executeDatabaseQuery(DataReadQuery.java:141)
org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:603)
org.eclipse.persistence.queries.DataReadQuery.execute(DataReadQuery.java:115)
org.eclipse.persistence.queries.DatabaseQuery.executeInUnitOfWork(DatabaseQuery.java:589)
org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2898)
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1218)
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1190)
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1176)
org.eclipse.persistence.internal.jpa.EJBQueryImpl.executeReadQuery(EJBQueryImpl.java:378)
org.eclipse.persistence.internal.jpa.EJBQueryImpl.getSingleResult(EJBQueryImpl.java:701)
weblogic.deployment.TransactionalEntityManagerProxyImpl$QueryImpl.getSingleResult(TransactionalEntityManagerProxyImpl.java:232)
com.collaxa.cube.persistence.dao.impl.jpa.JpaCubeInstanceDaoImpl.getNumberOfInstances(JpaCubeInstanceDaoImpl.java:439)
oracle.fabric.CubeServiceEngine.getNumberOfComponentInstances(CubeServiceEngine.java:1962)
oracle.soa.management.internal.ejb.impl.FacadeFinderBeanImpl.getNumberOfComponentInstances(FacadeFinderBeanImpl.java:1618)
oracle.soa.management.internal.ejb.impl.FacadeFinderBeanImpl.getComponentSnapShot(FacadeFinderBeanImpl.java:1653)
sun.reflect.GeneratedMethodAccessor5852.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
java.lang.reflect.Method.invoke(Method.java:575)
com.bea.core.repackaged.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
com.bea.core.repackaged.springframework.jee.intercept.MethodInvocationInvocationContext.proceed(MethodInvocationInvocationContext.java:104)
oracle.security.jps.ee.ejb.JpsAbsInterceptor$1.run(JpsAbsInterceptor.java:88)
oracle.security.jps.util.JpsSubject.doAsPrivileged(JpsSubject.java:299)
oracle.security.jps.ee.util.JpsPlatformUtil.runJaasMode(JpsPlatformUtil.java:406)
oracle.security.jps.wls.JpsWeblogicEjbInterceptor.runJaasMode(JpsWeblogicEjbInterceptor.java:61)
oracle.security.jps.ee.ejb.JpsAbsInterceptor.intercept(JpsAbsInterceptor.java:81)
oracle.security.jps.ee.ejb.JpsInterceptor.intercept(JpsInterceptor.java:101)
sun.reflect.GeneratedMethodAccessor863.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
java.lang.reflect.Method.invoke(Method.java:575)
com.bea.core.repackaged.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
com.bea.core.repackaged.springframework.jee.intercept.JeeInterceptorInterceptor.invoke(JeeInterceptorInterceptor.java:66)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:102)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
com.bea.core.repackaged.springframework.jee.spi.MethodInvocationVisitorImpl.visit(MethodInvocationVisitorImpl.java:37)
weblogic.ejb.container.injection.EnvironmentInterceptorCallbackImpl.callback(EnvironmentInterceptorCallbackImpl.java:22)
com.bea.core.repackaged.springframework.jee.spi.EnvironmentInterceptor.invoke(EnvironmentInterceptor.java:49)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
com.bea.core.repackaged.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:86)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
com.bea.core.repackaged.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:102)
com.bea.core.repackaged.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
com.bea.core.repackaged.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:151)
$Proxy309.getComponentSnapShot(Unknown Source)
oracle.soa.management.internal.ejb.impl.FacadeFinderBean_4vacyo_FacadeFinderBeanImpl.getComponentSnapShot(FacadeFinderBean_4vacyo_FacadeFinderBeanImpl.java:1604)
oracle.soa.management.internal.ejb.impl.FacadeFinderBean_4vacyo_FacadeFinderBeanImpl_WLSkel.invoke(Unknown Source)
weblogic.rmi.internal.BasicServerRef.invoke(BasicServerRef.java:567)
weblogic.rmi.internal.BasicServerRef$1.run(BasicServerRef.java:477)
weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:350)
weblogic.security.service.SecurityManager.runAs(SecurityManager.java:143)
weblogic.rmi.internal.BasicServerRef.handleRequest(BasicServerRef.java:425)
weblogic.rmi.internal.wls.WLSExecuteRequest.run(WLSExecuteRequest.java:117)
weblogic.work.ExecuteThread.execute(ExecuteThread.java:198)
weblogic.work.ExecuteThread.run(ExecuteThread.java:165)
}
SUBSYSTEM = WebLogicServer USERID = <WLS Kernel> SEVERITY = Error THREAD = [ACTIVE] ExecuteThread: '96' for queue: 'weblogic.kernel.Default (self-tuning)' MSGID = BEA-000337 MACHINE = soaprod TXID = CONTEXTID = f5d0b85a929630a2:6eada0f7:1304e0a2bdc:-7ffb-00000000017e1605 TIMESTAMP = 1312554602698
WatchAlarmType: AutomaticReset
WatchAlarmResetPeriod: 600000
>
Edited by: Brutus35 on Aug 5, 2011 8:04 AM