Application Performance is degraded and leading to hung threads

Document ID : KB000095779
Last Modified Date : 26/06/2018
Show Technical Document Details
Issue:
We are seeing a lot of hung threads related to CA APM Introscope Agent transaction trace in the WebSphere Application SystemOut.log. Most hung threads would take around 11 - 14 minutes to complete.

Here's an example of the stack trace for the hung thread:

Note: actual class name has been modified to remove sensitive data

000004b9 ThreadMonitor W   WSVR0605W: Thread "WorkManager.EventsWorkManager : 9465" (00005819) has been active for 672189 milliseconds and may be hung.  There is/are 750 thread(s) in total in the server that may be hung.
    at com.wily.introscope.agent.trace.hc2.BlamePointTracer.doOnEndTrace(BlamePointTracer.java:1239)
    at com.wily.introscope.agent.trace.cas.TransactionStructure.submitNextEndTransaction(TransactionStructure.java:540)
    at com.wily.introscope.agent.trace.hc2.ASingleInstanceTracerFactoryHC.submitToTransactionStructureOnEndTrace(ASingleInstanceTracerFactoryHC.java:210)
    at com.wily.introscope.agent.trace.hc2.BlamePointTracer.ITracer_finishTrace(BlamePointTracer.java:445)
    at com.wily.introscope.agent.trace.InvocationData.IMethodTracer_finishTrace(InvocationData.java:1504)
  
 at com.123tech.cache.entities.LogicalFPath.getFXmlType(LogicalFPath.java:118)
    at backend.services.search.MessagesIndexEntityRequest.getRelevantLogicalFieldsForPdo(MessagesIndexEntityRequest.java:147)
    at backend.services.search.MessagesIndexEntityRequest.getDataMap(MessagesIndexEntityRequest.java:95)
    at backend.services.search.elasticsearch.operation.ESIndexOperation.prepareElasticIndexRequest(ESIndexOperation.java:705)
    at backend.services.search.elasticsearch.operation.ESIndexOperation.index(ESIndexOperation.java:113)
    at backend.services.search.elasticsearch.ElasticSearchPlatform.index(ElasticSearchPlatform.java:163)
    at sun.reflect.GeneratedMethodAccessor1472.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
    at java.lang.reflect.Method.invoke(Method.java:508)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:302)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at backend.services.search.SearchPlatfromOperationsAspect.invoke(SearchPlatfromOperationsAspect.java:26)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:208)
    at com.sun.proxy.$Proxy271.index(Unknown Source)
    at backend.services.search.IndexLastResource.indexDocument(IndexLastResource.java:97)
    at backend.services.search.IndexLastResource.access$100(IndexLastResource.java:27)
    at backend.services.search.IndexLastResource$1.run(IndexLastResource.java:81)
    at org.springframework.scheduling.commonj.DelegatingWork.run(DelegatingWork.java:62)
    at com.ibm.ws.asynchbeans.J2EEContext$RunProxy.run(J2EEContext.java:267)
    at java.security.AccessController.doPrivileged(AccessController.java:620)
    at javax.security.auth.Subject.doAs(Subject.java:488)
    at com.ibm.websphere.security.auth.WSSubject.doAs(WSSubject.java:133)
    at com.ibm.websphere.security.auth.WSSubject.doAs(WSSubject.java:91)
    at com.ibm.ws.asynchbeans.J2EEContext$DoAsProxy.run(J2EEContext.java:338)
    at java.security.AccessController.doPrivileged(AccessController.java:650)
    at com.ibm.ws.asynchbeans.J2EEContext.run(J2EEContext.java:1174)
    at com.ibm.ws.asynchbeans.WorkWithExecutionContextImpl.go(WorkWithExecutionContextImpl.java:199)
    at com.ibm.ws.asynchbeans.CJWorkItemImpl.run(CJWorkItemImpl.java:236)
    at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1892)


 
Environment:
CA APM Introscope Java Agent for WebSphere Application Server 10.5.0.28
WebSphere Platform ND 8.5.5.11
AIX 7.1
IBM J9 VM 1.8 64bit
Cause:
From the thread dumps (example shown above), it was determined that the process takes more time to execute instrumented class com.123tech.cache.entities.LogicalFPath, as all the hung threads were initiated through this class.

Interestingly, Blocked operations are the integer operations, such as :

java.security.SecureRandom.next()
SharedDataStructure5$SynchronizedCounter.increase()
SharedDataStructure5$SynchronizedCounter.decrease()


Typically, these are not resource intensive operations. One possibility could be that the LogicalFPath.getFXmlType method is called too frequently.

 
Resolution:
Given the nature of usage of this class in your application, the recommendation is to skip this class from getting instrumented.

To do that, you can add the following SkipClass directive to either a new skip.pbd or to an existing pbd that will be loaded

SkipClass:  com.123tech.cache.entities.LogicalFPath