1

i have a web application using tomcat 7 (latest version) running on a windows 2012 server. The web app has some simple forms for logging in a user and sending private messages. The database calls are made with EclipseLink 2.5.0 using the JPA API, with a RESOURCE_LOCAL configuration.

My Problem is that after a while (1-2 days), my web app becomes unresponsive to any user action. There are no error messages, neither on the client nor at the server side. But when i investigate the tomcat with JConsole, i can see many threads in a "blocked" or waitung state. Here is the stacktrace at which the thread hangs:

<pre>
Name: http-apr-0.0.0.0-80-exec-9
State: BLOCKED on org.eclipse.persistence.logging.DefaultSessionLog@a17eaf8 owned by: http-apr-0.0.0.0-80-exec-3
Total blocked: 1  Total waited: 68

  Stack trace: 
  org.eclipse.persistence.logging.DefaultSessionLog.log(DefaultSessionLog.java:138)
  org.eclipse.persistence.internal.sessions.AbstractSession.log(AbstractSession.java:3484)
  org.eclipse.persistence.internal.sessions.AbstractSession.log(AbstractSession.java:4673)
  org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:615)
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:558)
org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:1995)
org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:570)
org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:248)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:242)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:228)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:299)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.selectAllRows(DatasourceCallQueryMechanism.java:694)
org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRowsFromTable(ExpressionQueryMechanism.java:2714)
org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRows(ExpressionQueryMechanism.java:2667)
org.eclipse.persistence.queries.ReadAllQuery.executeObjectLevelReadQuery(ReadAllQuery.java:477)
org.eclipse.persistence.queries.ObjectLevelReadQuery.executeDatabaseQuery(ObjectLevelReadQuery.java:1155)
org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:899)
org.eclipse.persistence.queries.ObjectLevelReadQuery.execute(ObjectLevelReadQuery.java:1114)
org.eclipse.persistence.queries.ReadAllQuery.execute(ReadAllQuery.java:402)
org.eclipse.persistence.queries.ObjectLevelReadQuery.executeInUnitOfWork(ObjectLevelReadQuery.java:1202)
org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2894)
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1797)
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1779)
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1744)
org.eclipse.persistence.internal.jpa.QueryImpl.executeReadQuery(QueryImpl.java:258)
org.eclipse.persistence.internal.jpa.QueryImpl.getSingleResult(QueryImpl.java:516)
org.eclipse.persistence.internal.jpa.EJBQueryImpl.getSingleResult(EJBQueryImpl.java:400)
org.cs.LoginServlet.login(LoginServlet.java:80)
org.cs.LoginServlet.doPost(LoginServlet.java:43)
javax.servlet.http.HttpServlet.service(HttpServlet.java:647)
javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:611)
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99)
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953)
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1023)
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:589)
org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:1852)
   - locked org.apache.tomcat.util.net.SocketWrapper@1fd672f
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
java.lang.Thread.run(Thread.java:724)
</pre>

It seems that the threads hangs during EclipseLink writing log messages to the console. Has anyone encountered this behaviour? For me, it's hard to believe that logging could lead to a deadlock. I also haven't found any resources on the web describing this "anomaly". Would be glad if someone could point me in some direction since i am totally stuck in this problem.

UPDATE 21.12.2013

Here is the thread to which the lock points to. It seems that it is somewhere deep in the PrintStream classes, reinforcing my suspicion that it is a problem with concurrent access to an output buffer while logging some stuff. I use several servlets so i have different threads but the logging is only done by EclipseLink and Tomcat. Do i have to synchronize all my methods to prevent the deadlocking?

Name: http-apr-0.0.0.0-80-exec-2
State: RUNNABLE
Total blocked: 0  Total waited: 37

Stack trace: 
java.io.FileOutputStream.writeBytes(Native Method)
java.io.FileOutputStream.write(FileOutputStream.java:318)
java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
   - locked java.io.BufferedOutputStream@4412b0a0
java.io.PrintStream.write(PrintStream.java:482)
   - locked java.io.PrintStream@2709fb4a
sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104)
   - locked java.io.OutputStreamWriter@50cb4c
java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185)
java.io.PrintStream.write(PrintStream.java:527)
   - locked java.io.PrintStream@2709fb4a
java.io.PrintStream.print(PrintStream.java:669)
java.io.PrintStream.println(PrintStream.java:806)
   - locked java.io.PrintStream@2709fb4a
org.apache.tomcat.util.log.SystemLogHandler.println(SystemLogHandler.java:264)
org.eclipse.persistence.sessions.server.ConnectionPool.acquireConnection(ConnectionPool.java:206)
   - locked org.eclipse.persistence.sessions.server.ConnectionPool@34dc0be5
org.eclipse.persistence.sessions.server.ServerSession.getAccessors(ServerSession.java:538)
org.eclipse.persistence.sessions.server.ServerSession.executeCall(ServerSession.java:557)
org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:248)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:242)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:228)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeSelectCall(DatasourceCallQueryMechanism.java:299)
org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.selectAllRows(DatasourceCallQueryMechanism.java:694)
org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRowsFromTable(ExpressionQueryMechanism.java:2714)
org.eclipse.persistence.internal.queries.ExpressionQueryMechanism.selectAllRows(ExpressionQueryMechanism.java:2667)
org.eclipse.persistence.queries.ReadAllQuery.executeObjectLevelReadQuery(ReadAllQuery.java:477)
org.eclipse.persistence.queries.ObjectLevelReadQuery.executeDatabaseQuery(ObjectLevelReadQuery.java:1155)
org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:899)
org.eclipse.persistence.queries.ObjectLevelReadQuery.execute(ObjectLevelReadQuery.java:1114)
org.eclipse.persistence.queries.ReadAllQuery.execute(ReadAllQuery.java:402)
org.eclipse.persistence.queries.ObjectLevelReadQuery.executeInUnitOfWork(ObjectLevelReadQuery.java:1202)
org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:2894)
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1797)
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1779)
org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1744)
org.eclipse.persistence.internal.jpa.QueryImpl.executeReadQuery(QueryImpl.java:258)
org.eclipse.persistence.internal.jpa.QueryImpl.getResultList(QueryImpl.java:468)
org.cs.UserServlet.getPopularUsers(UserServlet.java:105)
org.cs.UserServlet.doPost(UserServlet.java:45)
javax.servlet.http.HttpServlet.service(HttpServlet.java:647)
javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:611)
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99)
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953)
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1023)
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:589)
org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:1852)
   - locked org.apache.tomcat.util.net.SocketWrapper@4bb13b2e
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
java.lang.Thread.run(Thread.java:724)
  • 1
    This thread points to a lock held by thread exec-3, what is that thread doing or locked on? – Chris Oct 21 '13 at 11:30
  • Hi Chris, thanks for your hint. Unfortunately, i haven't looked at the other thread stacktraces and since i have already restarted the tomcat i don't have them any more (only the one i posted). the next time it will occur i will do further investigation on the thread states. – fred madison Oct 21 '13 at 14:50
  • I finally have the blocking thread and pasted it in my original post. – fred madison Oct 21 '13 at 17:21
  • Turn off logging, as it is always a performance drain, but you'll want to check why this thread is taking so long. Try switching loggers, cycling the log, and checking the disk drive that it has sufficient space for the log. – Chris Oct 22 '13 at 11:39
  • I think i have fixed the problem. The problems occurrs only when i login to the remote server on which the tomcat runs. I could reproduce the problem successfully when i click in the tomcat console window - soon after that, my web app hangs. I have found a similar problem which is described here: http://stackoverflow.com/questions/3531692/java-thread-blocking. I have now installed tomcat as a server and the problem did not occur again. If it will work for a week i think the problem is gone :) – fred madison Oct 22 '13 at 14:18

0 Answers0