On Fri, Mar 15, 2013 at 2:21 PM, Christopher Schultz <ch...@christopherschultz.net> wrote: > -----BEGIN PGP SIGNED MESSAGE----- > Hash: SHA256 > > Colin, > > On 3/14/13 3:41 PM, Colin Ingarfield wrote: >> (Sorry I cannot reply correctly b/c I was on the digest list) >> >> The deadlocked threads: Deadlock Detection: >> >> Found one Java-level deadlock: ============================= >> >> "qtp1840392480-3740": waiting to lock Monitor@0x00007f4350001fd0 >> (Object@0x00000006c01a0e88, a com/mysql/jdbc/JDBC4Connection), >> which is held by "PoolCleaner[2009981184:1363034108768]" >> "PoolCleaner[2009981184:1363034108768]": waiting to lock >> Monitor@0x00007f4350001f28 (Object@0x00000006c1ed5738, a >> com/mysql/jdbc/JDBC4ResultSet), which is held by >> "qtp1840392480-3740" >> >> Found a total of 1 deadlock. >> >> Here are the stack traces: Thread 12820: (state = BLOCKED) - >> com.mysql.jdbc.ConnectionImpl.getCharacterSetMetadata() @bci=0, >> line=2851 (Compiled frame) - >> com.mysql.jdbc.Field.getStringFromBytes(int, int) @bci=37, >> line=717 (Compiled frame) - com.mysql.jdbc.Field.getName() @bci=17, >> line=631 (Interpreted frame) - >> com.mysql.jdbc.ResultSetImpl.buildIndexMapping() @bci=78, line=752 >> (Compiled frame) - >> com.mysql.jdbc.ResultSetImpl.findColumn(java.lang.String) @bci=12, >> line=1110 (Interpreted frame) - >> com.mysql.jdbc.ResultSetImpl.getString(java.lang.String) @bci=3, >> line=5609 (Interpreted frame) - >> org.eclipse.jetty.server.session.JDBCSessionManager$1.run() >> @bci=111, line=844 (Interpreted frame) - >> org.eclipse.jetty.server.handler.ContextHandler.handle(java.lang.Runnable) >> >> > @bci=53, line=1119 (Interpreted frame) >> - >> org.eclipse.jetty.server.session.JDBCSessionManager.loadSession(java.lang.String, >> >> > java.lang.String, java.lang.String) @bci=61, line=884 (Interpreted >> frame) - >> org.eclipse.jetty.server.session.JDBCSessionManager.getSession(java.lang.String) >> >> > @bci=345, line=518 (Interpreted frame) >> - >> org.eclipse.jetty.server.session.JDBCSessionManager.getSession(java.lang.String) >> >> > @bci=2, line=69 (Interpreted frame) >> - >> org.eclipse.jetty.server.session.AbstractSessionManager.getHttpSession(java.lang.String) >> >> > @bci=13, line=272 (Interpreted frame) >> - >> org.eclipse.jetty.server.session.SessionHandler.checkRequestedSessionId(org.eclipse.jetty.server.Request, >> >> > javax.servlet.http.HttpServletRequest) @bci=192, line=277 (Interpreted >> frame) - >> org.eclipse.jetty.server.session.SessionHandler.doScope(java.lang.String, >> >> > org.eclipse.jetty.server.Request, >> javax.servlet.http.HttpServletRequest, >> javax.servlet.http.HttpServletResponse) @bci=47, line=158 >> (Interpreted frame) - >> org.eclipse.jetty.server.handler.ContextHandler.doScope(java.lang.String, >> >> > org.eclipse.jetty.server.Request, >> javax.servlet.http.HttpServletRequest, >> javax.servlet.http.HttpServletResponse) @bci=416, line=999 >> (Interpreted frame) - >> org.eclipse.jetty.server.handler.ScopedHandler.handle(java.lang.String, >> >> > org.eclipse.jetty.server.Request, >> javax.servlet.http.HttpServletRequest, >> javax.servlet.http.HttpServletResponse) @bci=13, line=117 >> (Interpreted frame) - >> org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(java.lang.String, >> >> > org.eclipse.jetty.server.Request, >> javax.servlet.http.HttpServletRequest, >> javax.servlet.http.HttpServletResponse) @bci=399, line=250 >> (Interpreted frame) - >> org.eclipse.jetty.server.handler.HandlerCollection.handle(java.lang.String, >> >> > org.eclipse.jetty.server.Request, >> javax.servlet.http.HttpServletRequest, >> javax.servlet.http.HttpServletResponse) @bci=42, line=149 >> (Compiled frame) - >> org.eclipse.jetty.server.handler.HandlerWrapper.handle(java.lang.String, >> >> > org.eclipse.jetty.server.Request, >> javax.servlet.http.HttpServletRequest, >> javax.servlet.http.HttpServletResponse) @bci=23, line=111 >> (Compiled frame) - >> org.eclipse.jetty.server.Server.handle(org.eclipse.jetty.server.AbstractHttpConnection) >> >> > @bci=134, line=350 (Compiled frame) >> - org.eclipse.jetty.server.AbstractHttpConnection.handleRequest() >> @bci=228, line=454 (Compiled frame) - >> org.eclipse.jetty.server.AbstractHttpConnection.headerComplete() >> @bci=448, line=890 (Interpreted frame) - >> java.util.HashMap.get(java.lang.Object) @bci=74, line=320 (Compiled >> frame) - >> org.eclipse.jetty.io.BufferCache.get(org.eclipse.jetty.io.Buffer) >> @bci=5, line=59 (Compiled frame) - >> org.eclipse.jetty.http.HttpParser.parseNext() @bci=625, line=371 >> (Compiled frame) - >> org.eclipse.jetty.http.HttpParser.parseAvailable() @bci=1, >> line=230 (Compiled frame) - >> org.eclipse.jetty.server.AsyncHttpConnection.handle() @bci=80, >> line=77 (Compiled frame) - >> org.eclipse.jetty.io.nio.SslConnection.handle() @bci=36, line=191 >> (Compiled frame) - >> org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle() @bci=10, >> line=606 (Compiled frame) - >> org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run() @bci=4, >> line=46 (Interpreted frame) - >> org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(java.lang.Runnable) >> >> > @bci=1, line=603 (Compiled frame) >> - org.eclipse.jetty.util.thread.QueuedThreadPool$3.run() @bci=47, >> line=538 (Compiled frame) - java.lang.Thread.run() @bci=11, >> line=679 (Interpreted frame) >> >> Locked ownable synchronizers: - None >> >> Thread 890: (state = BLOCKED) - >> com.mysql.jdbc.ResultSetImpl.realClose(boolean) @bci=0, line=7195 >> (Interpreted frame) - com.mysql.jdbc.ResultSetImpl.close() @bci=2, >> line=909 (Interpreted frame) - >> com.mysql.jdbc.StatementImpl.realClose(boolean, boolean) @bci=126, >> line=2478 (Interpreted frame) - >> com.mysql.jdbc.PreparedStatement.realClose(boolean, boolean) >> @bci=71, line=3098 (Interpreted frame) - >> com.mysql.jdbc.ConnectionImpl.closeAllOpenStatements() @bci=90, >> line=1628 (Interpreted frame) - >> com.mysql.jdbc.ConnectionImpl.realClose(boolean, boolean, boolean, >> java.lang.Throwable) @bci=176, line=4388 (Interpreted frame) - >> com.mysql.jdbc.ConnectionImpl.close() @bci=32, line=1601 >> (Interpreted frame) - >> org.apache.tomcat.jdbc.pool.PooledConnection.disconnect(boolean) >> @bci=47, line=330 (Interpreted frame) - >> org.apache.tomcat.jdbc.pool.PooledConnection.release() @bci=2, >> line=489 (Interpreted frame) - >> org.apache.tomcat.jdbc.pool.ConnectionPool.release(org.apache.tomcat.jdbc.pool.PooledConnection) >> >> > @bci=10, line=573 (Interpreted frame) >> - >> org.apache.tomcat.jdbc.pool.ConnectionPool.abandon(org.apache.tomcat.jdbc.pool.PooledConnection) >> >> > @bci=82, line=532 (Interpreted frame) >> - org.apache.tomcat.jdbc.pool.ConnectionPool.checkAbandoned() >> @bci=130, line=950 (Interpreted frame) - >> org.apache.tomcat.jdbc.pool.ConnectionPool$PoolCleaner.run() >> @bci=70, line=1340 (Interpreted frame) - >> java.util.TimerThread.mainLoop() @bci=221, line=534 (Compiled >> frame) - java.util.TimerThread.run() @bci=1, line=484 (Interpreted >> frame) >> >> Locked ownable synchronizers: - <0x00000006c01b3860>, (a >> java/util/concurrent/locks/ReentrantReadWriteLock$NonfairSync) >> >> >> Once I dug up these stack traces I started to wonder if the mysql >> driver was the problem (or contributing to the problem.) I was >> using Connector/J version 5.1.19 when the deadlock occurred. I >> found this bug: http://bugs.mysql.com/bug.php?id=61247 which >> sounds a lot like what appears to have happened. I'm interested in >> your thoughts on this. >> >> In the meantime I have upgraded to latest Connector/J which >> includes a fix for this bug. I was running the old driver for >> months before this deadlock, though, so it will be difficult to >> know if it fixes the issue or not. > > Looking at that MySQL Connector/J problem and your stack traces above, > I would think that both problems stem from multi-threaded access of > the same java.sql.Connection object... are you grabbing a single > connection from the pool and using it in multiple places? If so, you > are just asking for problems like this. > > Your code should: > > 1. Check-out a connection from the pool > 2. Use it > 3. Return it to the pool > > If you do the above for every request, then you should never have any > connections that suffer deadlock like this. > > Hope that helps, > - -chris > -----BEGIN PGP SIGNATURE----- > Version: GnuPG/MacGPG2 v2.0.17 (Darwin) > Comment: GPGTools - http://gpgtools.org > Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/ > > iEYEAREIAAYFAlFDdKUACgkQ9CaO5/Lv0PDveACgjyOc0C4xjDMYLlNeaEAPYvZL > LQAAoLYigRP5nekQjINlCPjCSzLTS1zb > =6Eto > -----END PGP SIGNATURE----- > > --------------------------------------------------------------------- > To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org > For additional commands, e-mail: users-h...@tomcat.apache.org >
Chris, My database access code is built on Spring 3's JDBC APIs, so I do not do any explicit connection management in my code. Its Spring's job to get connections and release them, and I assume its JDBC APIs is well-tested. So I don't think my code is the problem here. The Jetty session manager is storing HTTP session data in the database, and it does acquire connections directly from the pool. I haven't dug through the Jetty source to see if they are doing anything questionable, tho I did email their user list about this issue. The issue appears to me that a jetty worker thread had retrieved a connection from the pool and the pool PoolCleaner thread fired up and tried to do something w/ the same connection. Neither of these threads "belong" to my code, which is why I'm emailing this list :) Thanks for taking a look at it. -- Colin --------------------------------------------------------------------- To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
