On May 3, 2014, at 9:08 PM, Rallavagu <rallav...@gmail.com> wrote: > Here is the thread BLOCKED waiting on another lock. > > "http-bio-28080-exec-613" daemon prio=10 tid=0x00007fcbac0e0800 nid=0x7897 > waiting for monitor entry [0x00007fcb915d3000] > java.lang.Thread.State: BLOCKED (on object monitor) > at java.util.logging.StreamHandler.publish(StreamHandler.java:191) > - waiting to lock <0x00000007008187b0> (a > java.util.logging.ConsoleHandler) > at java.util.logging.ConsoleHandler.publish(ConsoleHandler.java:105) > at java.util.logging.Logger.log(Logger.java:610) > at java.util.logging.Logger.doLog(Logger.java:631) > at java.util.logging.Logger.logp(Logger.java:831) > at org.apache.juli.logging.DirectJDKLog.log(DirectJDKLog.java:185) > at org.apache.juli.logging.DirectJDKLog.error(DirectJDKLog.java:151) > at > org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:260) > at > org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123) > at > org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502) > at > org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171) > at > org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100) > at > org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953) > at > org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118) > at > org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408) > at > org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1041) > at > org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:603) > at > org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:310) > - locked <0x00000007e1b0f808> (a > org.apache.tomcat.util.net.SocketWrapper) > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > at java.lang.Thread.run(Thread.java:744)
Looks like this is waiting to log something. Where are you writing your logs? Is it a local disk or network disk? Is the disk busy or otherwise slow? Dan > > Locked ownable synchronizers: > - <0x00000007e1b0f8d0> (a > java.util.concurrent.ThreadPoolExecutor$Worker) > > On 5/2/14, 9:19 PM, Christopher Schultz wrote: >> -----BEGIN PGP SIGNED MESSAGE----- >> Hash: SHA256 >> >> Rallavagu, >> >> On 5/2/14, 6:22 PM, Rallavagu wrote: >>> Tomcat Version: 7.0.47 JVM Version: 1.7.0_51-b13 >>> >>> I see many blocked threads (90) in the thread dump. There are >>> mainly two monitors that block 69 threads. >>> >>> One of them is below. It appears that it is simply trying to log. >>> ---------------------------------------------------------------------------------- >>> >>> "http-bio-28080-exec-396" daemon prio=10 tid=0x00007fcbc814f000 >>> nid=0x5804 runnable [0x00007fcc2144d000] java.lang.Thread.State: >>> RUNNABLE at java.lang.Throwable.getStackTraceElement(Native >>> Method) >> >> This thread is not blocked. What makes you think it is? >> >>> at java.lang.Throwable.getOurStackTrace(Throwable.java:827) - >>> locked <0x00000007e1886340> (a java.util.NoSuchElementException) at >>> java.lang.Throwable.printStackTrace(Throwable.java:656) - locked >>> <0x00000007e207a5a8> (a java.io.PrintWriter) at >>> java.lang.Throwable.printStackTrace(Throwable.java:721) at >>> java.util.logging.SimpleFormatter.format(SimpleFormatter.java:157) >>> - locked <0x00000007008187e8> (a >>> java.util.logging.SimpleFormatter) at >>> java.util.logging.StreamHandler.publish(StreamHandler.java:196) - >>> locked <0x00000007008187b0> (a java.util.logging.ConsoleHandler) >>> at >>> java.util.logging.ConsoleHandler.publish(ConsoleHandler.java:105) >>> at java.util.logging.Logger.log(Logger.java:610) at >>> java.util.logging.Logger.doLog(Logger.java:631) at >>> java.util.logging.Logger.logp(Logger.java:831) at >>> org.apache.juli.logging.DirectJDKLog.log(DirectJDKLog.java:185) at >>> org.apache.juli.logging.DirectJDKLog.error(DirectJDKLog.java:151) >>> at >>> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:260) >>> >>> at >>> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123) >>> >>> at >>> org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502) >>> >>> at >>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171) >>> >>> at >>> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100) >>> >>> at >>> org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953) >>> >>> >> at >>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118) >>> >>> at >>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408) >>> >>> >> at >>> org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1041) >>> >>> at >>> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:603) >>> >>> at >>> org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:310) >>> >>> - locked <0x00000007e0ba5dd8> (a >>> org.apache.tomcat.util.net.SocketWrapper) at >>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) >>> >>> at >>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) >>> >>> at java.lang.Thread.run(Thread.java:744) >>> >>> ---------------------------------------------------------------------------------- >>> >>> >>> >>> The second one has the lock on StandardClassLoader. >>> >>> ---------------------------------------------------------------------------------- >>> >>> >>> >>> "http-bio-28080-exec-605" daemon prio=10 tid=0x00007fcbc82b8800 >>> nid=0x77e6 runnable [0x00007fcb919d6000] java.lang.Thread.State: >>> RUNNABLE at java.lang.ClassLoader.findLoadedClass0(Native Method) >> >> This thread is also not blocked. >> >>> at java.lang.ClassLoader.findLoadedClass(ClassLoader.java:1093) at >>> java.lang.ClassLoader.loadClass(ClassLoader.java:407) - locked >>> <0x0000000700810fc8> (a >>> org.apache.catalina.loader.StandardClassLoader) at >>> java.lang.ClassLoader.loadClass(ClassLoader.java:358) at >>> java.util.ResourceBundle$Control.newBundle(ResourceBundle.java:2566) >>> >>> >> at java.util.ResourceBundle.loadBundle(ResourceBundle.java:1436) >>> at java.util.ResourceBundle.findBundle(ResourceBundle.java:1400) at >>> java.util.ResourceBundle.findBundle(ResourceBundle.java:1354) at >>> java.util.ResourceBundle.findBundle(ResourceBundle.java:1354) at >>> java.util.ResourceBundle.getBundleImpl(ResourceBundle.java:1296) at >>> java.util.ResourceBundle.getBundle(ResourceBundle.java:721) at >>> oracle.net.ns.Message11.getMessage(Message11.java:62) at >>> oracle.net.ns.NetException.getMessage(NetException.java:222) at >>> oracle.net.ano.AnoComm.b(Unknown Source) at >>> oracle.net.ano.AnoComm.o(Unknown Source) at >>> oracle.net.ano.Ano.a(Unknown Source) at >>> oracle.net.ano.Ano.negotiation(Unknown Source) at >>> oracle.net.ns.NSProtocol.connect(NSProtocol.java:407) at >>> oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:966) at >>> oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:292) at >>> oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:508) >>> >>> >> at oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:203) >>> at >>> oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:33) >>> >>> at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:510) >>> at >>> org.apache.tomcat.dbcp.dbcp.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:38) >>> >>> at >>> org.apache.tomcat.dbcp.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:582) >>> >>> at >>> org.apache.tomcat.dbcp.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1185) >>> >>> at >>> org.apache.tomcat.dbcp.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:106) >>> >>> at >>> org.apache.tomcat.dbcp.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044) >>> >>> at >>> org.hibernate.service.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:141) >>> >>> at >>> org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:292) >>> >>> at >>> org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:297) >>> >>> at >>> org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:169) >>> >>> at >>> org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:67) >>> >>> at >>> org.hibernate.engine.transaction.spi.AbstractTransactionImpl.begin(AbstractTransactionImpl.java:160) >>> >>> at >>> org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1395) >>> >>> >> at >>> org.springframework.orm.hibernate4.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:387) >>> >>> at >>> org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:371) >>> >>> at >>> org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:334) >>> >>> at >>> org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:105) >>> >>> at >>> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) >>> >>> at >>> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204) >>> >>> at com.sun.proxy.$Proxy236.getOauth2AccessTokenByTokenId(Unknown >>> Source) >>> ---------------------------------------------------------------------------------- >>> >>> >>> >>> I need help explain these two locks. >> >> Which two locks? The "locked" objects? Those are pretty standard >> object monitors. These two threads have no overlapping locks that I >> can see. Then again, it's pretty late at night for me... >> >>> I am wondering how would class loader would block those many >>> threads. >> >> Any class that modifies its internal state in a multi-threaded >> environment had better protect itself with such locks. If something is >> causing the class loading to take a long time, you might find threads >> waiting on each other. >> >> But I don't see any evidence that many (any?) threads are stuck at >> all. You showed two thread stack traces that appear to have little to >> do with one another. >> >>> One clue is that App Dynamics plugin is running for monitoring. >>> However, I do not find it's class in the stack trace. Looking for >>> some clues here. Thanks in advance. >> >> You need to provide more information. I don't see any problems, yet. >> >> - -chris >> -----BEGIN PGP SIGNATURE----- >> Version: GnuPG v1 >> Comment: GPGTools - http://gpgtools.org >> Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/ >> >> iQIcBAEBCAAGBQJTZG5EAAoJEBzwKT+lPKRYuYsP/jIo4xoSHgPIi0E5fmmKgOW2 >> AJkKh6X5rpeivPVRdAD3tf3QHWfJ3yX+YNSnfcgJlvHx2XsFfXgS+wxQViapg3IO >> MxEtSTlzmkDk1XwdWZr2yao7YRbDXJTtw5P8zi9Z8MSd3s0AZllvtTPTJP9WAKTt >> DgcaUZHSk6RIwrNZnrQmwYl4XpynWJSwC1nS/vp8PvVCn9ZizfcElN6IjvTNZ/BX >> jhstDVrVZyvP6+i9GAupTEnZRDzIl+q3czke8g6oBftw63URX74OczgKzCAjcfuz >> M9zCk0PTsj3hDxqiSqo9XmWlretYwy9NgWsW6+9DMI4PMIF8nIES7D0dMWsOvYCI >> ySMx7G7aPMxGrFxGNETJj6uvtOzfrytowJJfvUsA9MbxpIJlW7lcWtG9+maDYImO >> ikZ4E+dp/eKvlMmm7O6/0VvK0oXfzy1Tl36b5d34hbRXUw4flqLKrIxJ0bm8k1Qy >> XPIrzI8ZmMrSvIyU3bF6yzg0pO1Zk07knFroZdjhL5k2nKQozCCjPrvjOhiR8WQr >> 2TxkrbrxFCE8BygG80yysd2WG2AelXfBzRTs4DrKWv5LaDbCTtvK7nK5fOTqJLI+ >> p/OJyZy8ie/yhEXp5oPASQ8mbYvxlImphzcMcmsmaErbuU/oBx3Au3zZU/7KQURT >> F51ctX8ZcTJBNlrPuUiC >> =COyv >> -----END PGP SIGNATURE----- >> >> --------------------------------------------------------------------- >> To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org >> For additional commands, e-mail: users-h...@tomcat.apache.org >> > > --------------------------------------------------------------------- > To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org > For additional commands, e-mail: users-h...@tomcat.apache.org > --------------------------------------------------------------------- To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org