Wednesday, 17 September 2014

STUCK Thread in weblogic server - Hogging Thread

 As we all know facing issue with you job is casual. But, its too difficult, if you stuck somewhere and eat your own head and goooooogle all expected sites for solutions. Such kind of issues which you don't know what might be the root cause for this issue. For any issue we need application logs and if logs are not sufficient then you might go for bit deep level like thread dump.

Hogging thread in weblogic server is most often issue, but there is no such direct solution you found from internet.

What is a Hogging Thead ?



Hogging thread is thread which never back or never release the resource. Its a STUCK thread. When a thread starts an execution, it should return or complete the task and release the thread.But, hogging thread occurs when a thread wait for more than StuckThreadMaxTime.The normal time setting for StuckThreadMaxTime is 600sec.When a thread wait more than StuckThreadMaxTime , its known as hogging thread. 

 I faced such hogging thread issue in my project ,when support team reported that there are many hogging threads on server. From that time , it started eating the head.Below error log shows my issue.

Error log :-
<11/08/2014 4:50:00 PM EST> <Error> <WebLogicServer> <BEA-000337> <[STUCK] ExecuteThread: '452' for queue: 'weblogic.kernel.Default (self-tuning)' has been busy for "697" seconds working on the request "Workmanager: default, Version: 1, Scheduled=true, Started=true, Started time: 697198 ms
[
POST /centre_service/CentreService HTTP/1.1
Content-Type: text/xml; charset=utf-8
CorID: C3C7E9100AFF811A5C061CD2BE603C85,1:1:1:1,0,0,esb02.srv.xxx.com|WebLogic|esb_server2|OSB|BusinessServices|customer_centre/business_services/centre_service_biz_bs,6,AgAAA7xIQgAAAAFGAAAAAQAAABFqYXZhLnV0aWwuSGFzaE1hcAAAAAxIQgAAAAJGAAAAAgAAABBqYXZhLmxhbmcuU3RyaW5nABFBcHBNYXBDYWxsZXJBZ2VudEhCAAAAA0UAAAACABJlc2Jfb25saW5lX3NlcnZlcjJIQgAAAARFAAAAAgAWQXBwTWFwQ2FsbGVyTWV0aG9kTmFtZUhCAAAABUUAAAACABxIdHRwVHJhbnNwb3J0U2VydmxldHxzZXJ2aWNlSEIAAAAGRQAAAAIAClR4blRyYWNlSWRIQgAAAAdFAAAAAgAgQzNDN0U5MzhDNjhFNzYxNDIyQkZDMzNGMjQ5NTBBRkFIQgAAAAhFAAAAAgAQQXBwTWFwQ2FsbGVyVHlwZUhCAAAACUUAAAACAAdTZXJ2bGV0SEIAAAAKRQAAAAIAEHByZXZfa1R4blRyYWNlSWRIQgAAAAtFAAAAAgAkQzNDNzk1QkNDNjhFNzYxNDIyQkZDMzNGOUFCQzgwQjA0MjY3SEIAAAAMRQAAAAIAD0NhbGxlclRpbWVzdGFtcEhCAAAADUUAAAACAA0xNDA3NzM4OTY0MjgwSEIAAAAORQAAAAIAEEFwcE1hcENhbGxlckhvc3RIQgAAAA9FAAAAAgAbejJlc2IwMi5zeWQub3B0dXNuZXQuY29tLmF1SEIAAAAQRQAAAAIAE0FwcE1hcENhbGxlclByb2Nlc3NIQgAAABFFAAAAAgAIV2ViTG9naWNIQgAAABJFAAAAAgALTkJUaHJlYWRUeG5IQgAAABNFAAAAAgAFZmFsc2VIQgAAABRFAAAAAgAXcHJldl9rVHhuVHJhY2VTdGFydFRpbWVIQgAAABVFAAAAAgANMTQwNzczODk2NDI2NUhCAAAAFkUAAAACAA5BcHBNYXBBcHBOYW1lc0hCAAAAF0YAAAADAAAAE2phdmEudXRpbC5BcnJheUxpc3QAAAAFSEIAAAAYRQAAAAIAClVSTCBNYXBwZXJIQgAAABlFAAAAAgAPVmlnbmV0dGUgUG9ydGFsSEIAAAAaRQAAAAIAD0N1c3RvbWVyIENlbnRyZUhCAAAAG0UAAAACABRjdXN0b21lcmFwcC1zZXJ2aWNlc0hCAAAAHEUAAAACADljdXN0b21lcl9jZW50cmVfc2VydmljZS9wcm94eV9zZXJ2aWNlcy9jdXN0b21lcl9jZW50cmVfcHNIQgAAAB1FAAAAAgAIQlNfc2VxSWRIQgAAAB5FAAAAAgAHMToxOjE6MQ==
SOAPAction: "http://services.centreservice.bservice.com/getCustomersByAccountNameList"
Transfer-Encoding: chunked
User-Agent: Java1.6.0_71
Accept: text/html, image/gif, image/jpeg, */*; q=.2
Connection: Keep-Alive

]", which is more than the configured time (StuckThreadMaxTime) of "600" seconds. Stack trace:
Thread-87420 "[STUCK] ExecuteThread: '452' for queue: 'weblogic.kernel.Default (self-tuning)'" <alive, suspended, blocked, priority=1, DAEMON> {
    -- Blocked trying to get lock: weblogic.jdbc.common.internal.GenericConnectionPool@23cd753b[thin lock]
    weblogic.common.resourcepool.ResourcePoolImpl.reserveResourceInternal(ResourcePoolImpl.java:385)
    weblogic.common.resourcepool.ResourcePoolImpl.reserveResource(ResourcePoolImpl.java:343)
    weblogic.common.resourcepool.ResourcePoolImpl.reserveResource(ResourcePoolImpl.java:330)
    weblogic.jdbc.common.internal.ConnectionPool.reserve(ConnectionPool.java:469)
    weblogic.jdbc.common.internal.ConnectionPool.reserve(ConnectionPool.java:363)
    weblogic.jdbc.common.internal.ConnectionPoolManager.reserve(ConnectionPoolManager.java:125)
    weblogic.jdbc.common.internal.ConnectionPoolManager.reserve(ConnectionPoolManager.java:158)
    weblogic.jdbc.pool.Driver.connect(Driver.java:132)
    weblogic.jdbc.jts.Driver.getNonTxConnection(Driver.java:658)
    weblogic.jdbc.jts.Driver.connect(Driver.java:127)
    weblogic.jdbc.common.internal.RmiDataSource.getConnectionInternal(RmiDataSource.java:533)
    weblogic.jdbc.common.internal.RmiDataSource.getConnection(RmiDataSource.java:498)
    weblogic.jdbc.common.internal.RmiDataSource.getConnection(RmiDataSource.java:491)
    org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.getConnection(LocalDataSourceConnectionProvider.java:81)
    org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
    org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
    org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:142)
    org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:85)
    org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1354)
    org.springframework.orm.hibernate3.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:555)
    org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:371)
    org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:335)
    org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:105)
    org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
    org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
    com.sun.proxy.$Proxy235.getCustomerByAccountNameList(Unknown Source)
    au.com.xxx.mv.srv.bizservice.centreservice.service.ws.jws.JwsCentreService.getCustomersByAccountNameList(JwsCentreService.java:611)
    sun.reflect.GeneratedMethodAccessor1108.invoke(Unknown Source)
    sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    java.lang.reflect.Method.invoke(Method.java:597)
    weblogic.wsee.jaxws.WLSInstanceResolver$WLSInvoker.invoke(WLSInstanceResolver.java:92)
    weblogic.wsee.jaxws.WLSInstanceResolver$WLSInvoker.invoke(WLSInstanceResolver.java:74)
    com.sun.xml.ws.server.InvokerTube$2.invoke(InvokerTube.java:151)
    com.sun.xml.ws.server.sei.EndpointMethodHandlerImpl.invoke(EndpointMethodHandlerImpl.java:268)
    com.sun.xml.ws.server.sei.SEIInvokerTube.processRequest(SEIInvokerTube.java:100)
    com.sun.xml.ws.api.pipe.Fiber.__doRun(Fiber.java:866)
    com.sun.xml.ws.api.pipe.Fiber._doRun(Fiber.java:815)
    com.sun.xml.ws.api.pipe.Fiber.doRun(Fiber.java:778)
    com.sun.xml.ws.api.pipe.Fiber.runSync(Fiber.java:680)
    ^-- Holding lock: com.sun.xml.ws.api.pipe.Fiber@2779e7db[thin lock]
    com.sun.xml.ws.server.WSEndpointImpl$2.process(WSEndpointImpl.java:403)
    com.sun.xml.ws.transport.http.HttpAdapter$HttpToolkit.handle(HttpAdapter.java:539)
    com.sun.xml.ws.transport.http.HttpAdapter.handle(HttpAdapter.java:253)
    com.sun.xml.ws.transport.http.servlet.ServletAdapter.handle(ServletAdapter.java:140)
    weblogic.wsee.jaxws.WLSServletAdapter.handle(WLSServletAdapter.java:171)
    weblogic.wsee.jaxws.HttpServletAdapter$AuthorizedInvoke.run(HttpServletAdapter.java:708)
    weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:363)
    weblogic.security.service.SecurityManager.runAs(SecurityManager.java:146)
    weblogic.wsee.util.ServerSecurityHelper.authenticatedInvoke(ServerSecurityHelper.java:103)
    weblogic.wsee.jaxws.HttpServletAdapter$3.run(HttpServletAdapter.java:311)
    weblogic.wsee.jaxws.HttpServletAdapter.post(HttpServletAdapter.java:336)
    weblogic.wsee.jaxws.JAXWSServlet.doRequest(JAXWSServlet.java:99)
    weblogic.servlet.http.AbstractAsyncServlet.service(AbstractAsyncServlet.java:99)
    javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
    weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:227)
    weblogic.servlet.internal.StubSecurityHelper.invokeServlet(StubSecurityHelper.java:125)
    weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:301)
    weblogic.servlet.internal.TailFilter.doFilter(TailFilter.java:26)
    weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:56)
    com.jamonapi.JAMonFilter.doFilter(JAMonFilter.java:57)
    weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:56)
    weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.wrapRun(WebAppServletContext.java:3730)
    weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3696)
    weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
    weblogic.security.service.SecurityManager.runAs(SecurityManager.java:120)
    weblogic.servlet.internal.WebAppServletContext.securedExecute(WebAppServletContext.java:2273)
    weblogic.servlet.internal.WebAppServletContext.execute(WebAppServletContext.java:2179)
    weblogic.servlet.internal.ServletRequestImpl.run(ServletRequestImpl.java:1490)
    weblogic.work.ExecuteThread.execute(ExecuteThread.java:256)
    weblogic.work.ExecuteThread.run(ExecuteThread.java:221)
}
After lot of analysis I got few points , where I can stand and try for any possible solution.As per my investigation there are many reason behind hogging thread.

Possible cause for hogging thread :-


  1. Network issue
  2. Application issue (If connections are not closed properly)
  3. Dependent service has problem (upstream and downstream )
  4. Heavy Server Load

Possible Solution :-


If your application is OK, then you can check other possible key point for this issue. In my issue , we are working on OSB (Oracle Service Bus) . Normally its related to working with proxy service and business service.

1. First and initial solution is check the Connection timeout and Read timeout  for business service. Whether those settings are fine or not.If possible configured that to as expected standard time is 30 sec .You can configure this more than 30sec.
 
2. As second solutions , you need to create a separate work manager for per each thread.By default my proxy was using default work manager. I applied with separate work manager and it worked.



Hope it will help you.





Follow for more details on Google+ and @Facebook!!!

Find More :-