> From: Christopher Schultz [mailto:ch...@christopherschultz.net] > Sent: Tuesday, January 13, 2015 1:05 PM > To: Tomcat Users List > Subject: Re: Occasional long wait for a JDBC connection > > -----BEGIN PGP SIGNED MESSAGE----- > Hash: SHA256 > > Darren, > > On 1/13/15 11:49 AM, Darren Davis wrote: > > The problem occurred again this morning. I was able to generate a > > thread dump and narrow down the source of our problem to tomcat > thread > > 23. > > > >> From 8:45:51,397 to 09:01:19,083, it was stuck in the validate check > >> for a > > newly instantiated connection: > > > > I ran the thread dump several times during this interval, and the > > stack trace for thread 23 did not change at all. > > > > I did check our database log file and determined that during the 8 > > hours that led up to our first error on the server yesterday, we had > > just a total of 12 unique connections. The problem occurred the the > > creation of connection # 13, which was then used several other times > > later. > > > > The incident this morning also coincided with creating a new > > connection in the pool. It does not make any sense that the simple > > validation query of "SELECT 1" would require a wait of 15 minutes to > > succeed. > > Agreed. > > > It's also strange that this only happens sporadically, and not every > > time a new connection is being "birthed" by the system. > > > > We've tried two different pooling technologies: DBCP and the new > > Apache JDBC pooling on this server and both exhibit the same 15 minute > > occasional wait. > > The problem is with the driver and/or database, not with the connection > pool. It's not surprising that you are experiencing problems regardless of the > pool being used. > > > we've come across documentation that suggests we could modify our > > validation statement by prefixing it with /* ping */, which we're > > thinking about trying > > Using "/* ping */" is usually a good idea for MySQL, but it may mask the > problem. What you may find is that the next "real" query you use hangs for > 15 minutes. If you are going to use /* ping */ and you are going to use the > tomcat-jdbc pool, then you may as well not configure a validation query at all > because Tomcat's pool will use Connection.isValid which amounts to the > same thing (and will work for any compliant JDBC driver, not just with > MySQL). > > > "http-nio-8443-exec-23" #156 daemon prio=5 os_prio=0 > > tid=0x00007f0658387000 nid=0x7a60 runnable [0x00007f05e7466000] > > java.lang.Thread.State: RUNNABLE at > > java.net.SocketInputStream.$$YJP$$socketRead0(Native Method) at > > java.net.SocketInputStream.socketRead0(SocketInputStream.java) at > > java.net.SocketInputStream.read(SocketInputStream.java:150) at > > java.net.SocketInputStream.read(SocketInputStream.java:121) at > > > com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.jav > > a:114) > > > > > at > > > com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfN > ec > > essary(ReadAheadInputStream.java:161) > > > > > at > > > com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.j > av > > a:189) > > > > > - - locked <0x00000000bdf09420> (a > > com.mysql.jdbc.util.ReadAheadInputStream) at > > com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2549) at > > com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3002) at > > com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2991) at > > com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3532) at > > com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2002) at > > com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2163) at > > com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2618) - > > locked <0x00000000bdf04df0> (a com.mysql.jdbc.JDBC4Connection) at > > com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2568) at > > com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:842) - locked > > <0x00000000bdf04df0> (a com.mysql.jdbc.JDBC4Connection) - locked > > <0x00000000ff107cd8> (a com.mysql.jdbc.StatementImpl) at > > com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:681) at > > > org.apache.tomcat.jdbc.pool.PooledConnection.validate(PooledConnection > > .java:503) > > > > > at > > > org.apache.tomcat.jdbc.pool.PooledConnection.validate(PooledConnection > > .java:437) > > > > > at > > > org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(Connectio > n > > Pool.java:763) > > > > > at > > > org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(Connectio > n > > Pool.java:617) > > > > > at > > > org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPoo > > l.java:186) > > > > > at > > > org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourcePr > > oxy.java:127) > > > > > at > > > org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.g > > etConnection(LocalDataSourceConnectionProvider.java:83) > > > > > at > > > org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManag > er. > > java:446) > > > > > at > > > org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager > .j > > ava:167) > > > > > at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:160) > > at > > org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:8 > > 1) > > > > > at > > org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1473) > > > > > at > > > org.springframework.orm.hibernate3.HibernateTransactionManager.doBegi > n > > (HibernateTransactionManager.java:556) > > > > > at > > org.springframework.transaction.support.AbstractPlatformTransactionMan > > ager.handleExistingTransaction(AbstractPlatformTransactionManager.java > > :424) > > > > > at > > org.springframework.transaction.support.AbstractPlatformTransactionMan > > ager.getTransaction(AbstractPlatformTransactionManager.java:348) > > > > > at > > org.springframework.transaction.interceptor.TransactionAspectSupport.c > > reateTransactionIfNecessary(TransactionAspectSupport.java:417) > > > > > at > > org.springframework.transaction.interceptor.TransactionAspectSupport.i > > nvokeWithinTransaction(TransactionAspectSupport.java:255) > > > > > at > > org.springframework.transaction.interceptor.TransactionInterceptor.inv > > oke(TransactionInterceptor.java:94) > > > > > at > > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed( > R > > eflectiveMethodInvocation.java:172) > > > > > at > > > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDyna > mic > > AopProxy.java:204) > > > > > at com.sun.proxy.$Proxy77.findOrCreateSystemTask(Unknown Source) > > at > > com.tracom.max.service.impl.SynchronizationServiceImpl.findOrCreateSys > > temTask(SynchronizationServiceImpl.java:115) > > > > > - - locked <0x00000000a45652b8> (a > > com.tracom.max.service.impl.SynchronizationServiceImpl) at > > com.tracom.max.service.impl.SessionServiceImpl.processRaterInvitation( > > SessionServiceImpl.java:1767) > > > > > at > > com.tracom.max.service.impl.SessionServiceImpl.addRaterToSession(Sessi > > onServiceImpl.java:1697) > > > > > at sun.reflect.GeneratedMethodAccessor566.invoke(Unknown Source) > > at > > > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces > s > > orImpl.java:43) > > > > > at java.lang.reflect.Method.invoke(Method.java:483) > > at > > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflectio > > n(AopUtils.java:317) > > > > > at > > > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoi > > npoint(ReflectiveMethodInvocation.java:183) > > > > > at > > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed( > R > > eflectiveMethodInvocation.java:150) > > > > > at > > org.springframework.transaction.interceptor.TransactionInterceptor$1.p > > roceedWithInvocation(TransactionInterceptor.java:96) > > > > > at > > org.springframework.transaction.interceptor.TransactionAspectSupport.i > > nvokeWithinTransaction(TransactionAspectSupport.java:260) > > > > > at > > org.springframework.transaction.interceptor.TransactionInterceptor.inv > > oke(TransactionInterceptor.java:94) > > > > > at > > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed( > R > > eflectiveMethodInvocation.java:172) > > > > > at > > > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDyna > mic > > AopProxy.java:204) > > > > > at com.sun.proxy.$Proxy64.addRaterToSession(Unknown Source) > > at > > com.tracom.tracomlearning.controller.InviteRaterController.processInvi > > teRater(InviteRaterController.java:461) > > > > > at sun.reflect.GeneratedMethodAccessor565.invoke(Unknown Source) > > at > > > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces > s > > orImpl.java:43) > > > > > at java.lang.reflect.Method.invoke(Method.java:483) > > at > > > org.springframework.web.method.support.InvocableHandlerMethod.invok > e(I > > nvocableHandlerMethod.java:215) > > > > > at > > > org.springframework.web.method.support.InvocableHandlerMethod.invok > eFo > > rRequest(InvocableHandlerMethod.java:132) > > > > > at > > > org.springframework.web.servlet.mvc.method.annotation.ServletInvocable > > > HandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104 > ) > > > > > at > > > org.springframework.web.servlet.mvc.method.annotation.RequestMapping > Ha > > > ndlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:7 > 45) > > > > > at > > > org.springframework.web.servlet.mvc.method.annotation.RequestMapping > Ha > > ndlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:685) > > > > > at > > > org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAda > pte > > r.handle(AbstractHandlerMethodAdapter.java:80) > > > > > at > > org.springframework.web.servlet.DispatcherServlet.doDispatch(Dispatche > > rServlet.java:919) > > > > > at > > org.springframework.web.servlet.DispatcherServlet.doService(Dispatcher > > Servlet.java:851) > > > > > at > > > org.springframework.web.servlet.FrameworkServlet.processRequest(Frame > w > > orkServlet.java:953) > > > > > at > > > org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkSer > vl > > et.java:855) > > > > > at javax.servlet.http.HttpServlet.service(HttpServlet.java:644) > > at > > > org.springframework.web.servlet.FrameworkServlet.service(FrameworkSer > v > > let.java:829) > > > > > at javax.servlet.http.HttpServlet.service(HttpServlet.java:725) > > at > > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Appli > > cationFilterChain.java:291) > > > > > at > > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFi > > lterChain.java:206) > > > > > at > > org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) > > > > > at > > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Appli > > cationFilterChain.java:239) > > > > > at > > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFi > > lterChain.java:206) > > > > > at > > com.tracom.tracomlearning.utils.XSSFilter.doFilterInternal(XSSFilter.j > > ava:33) > > > > > at > > org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRe > > questFilter.java:106) > > > > > at > > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Appli > > cationFilterChain.java:239) > > > > > at > > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFi > > lterChain.java:206) > > > > > at > > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.d > > oFilter(FilterChainProxy.java:330) > > > > > at > > org.springframework.security.web.access.intercept.FilterSecurityInterc > > eptor.invoke(FilterSecurityInterceptor.java:118) > > > > > at > > org.springframework.security.web.access.intercept.FilterSecurityInterc > > eptor.doFilter(FilterSecurityInterceptor.java:84) > > > > > at > > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.d > > oFilter(FilterChainProxy.java:342) > > > > > at > > org.springframework.security.web.access.ExceptionTranslationFilter.doF > > ilter(ExceptionTranslationFilter.java:113) > > > > > at > > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.d > > oFilter(FilterChainProxy.java:342) > > > > > at > > org.springframework.security.web.session.SessionManagementFilter.doFil > > ter(SessionManagementFilter.java:103) > > > > > at > > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.d > > oFilter(FilterChainProxy.java:342) > > > > > at > > > org.springframework.security.web.authentication.AnonymousAuthenticatio > > nFilter.doFilter(AnonymousAuthenticationFilter.java:113) > > > > > at > > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.d > > oFilter(FilterChainProxy.java:342) > > > > > at > > org.springframework.security.web.servletapi.SecurityContextHolderAware > > RequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:54 > > ) > > > > > at > > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.d > > oFilter(FilterChainProxy.java:342) > > > > > at > > > org.springframework.security.web.savedrequest.RequestCacheAwareFilter. > > doFilter(RequestCacheAwareFilter.java:45) > > > > > at > > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.d > > oFilter(FilterChainProxy.java:342) > > > > > at > > org.springframework.security.web.authentication.www.BasicAuthenticatio > > nFilter.doFilter(BasicAuthenticationFilter.java:150) > > > > > at > > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.d > > oFilter(FilterChainProxy.java:342) > > > > > at > > org.springframework.security.web.authentication.AbstractAuthentication > > ProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java: > > 183) > > > > > at > > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.d > > oFilter(FilterChainProxy.java:342) > > > > > at > > org.springframework.security.web.authentication.logout.LogoutFilter.do > > Filter(LogoutFilter.java:105) > > > > > at > > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.d > > oFilter(FilterChainProxy.java:342) > > > > > at > > org.springframework.security.web.context.SecurityContextPersistenceFil > > ter.doFilter(SecurityContextPersistenceFilter.java:87) > > > > > at > > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.d > > oFilter(FilterChainProxy.java:342) > > > > > at > > org.springframework.security.web.FilterChainProxy.doFilterInternal(Fil > > terChainProxy.java:192) > > > > > at > > org.springframework.security.web.FilterChainProxy.doFilter(FilterChain > > Proxy.java:160) > > > > > at > > org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(De > > legatingFilterProxy.java:343) > > > > > at > > org.springframework.web.filter.DelegatingFilterProxy.doFilter(Delegati > > ngFilterProxy.java:260) > > > > > at > > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Appli > > cationFilterChain.java:239) > > > > > at > > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFi > > lterChain.java:206) > > > > > at > > org.springframework.web.filter.CharacterEncodingFilter.doFilterInterna > > l(CharacterEncodingFilter.java:88) > > > > > at > > org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRe > > questFilter.java:106) > > > > > at > > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Appli > > cationFilterChain.java:239) > > > > > at > > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFi > > lterChain.java:206) > > > > > at > > > org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperV > a > > lve.java:219) > > > > > at > > > org.apache.catalina.core.StandardContextValve.invoke(StandardContextVa > > lve.java:106) > > > > > at > > org.apache.catalina.authenticator.AuthenticatorBase.invoke(Authenticat > > orBase.java:506) > > > > > at > > org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.ja > > va:142) > > > > > at > > org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.ja > > va:79) > > > > > at > > org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAcces > > sLogValve.java:610) > > > > > at > > org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValv > > e.java:88) > > > > > at > > org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java > > :537) > > > > > at > > org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp1 > > 1Processor.java:1081) > > > > > at > > > org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(A > > bstractProtocol.java:658) > > > > > at > > > org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.pro > > cess(Http11NioProtocol.java:222) > > > > > at > > > org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoi > > nt.java:1566) > > > > > at > > org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint > > .java:1523) > > > > > - - locked <0x00000000fecbac90> (a > > org.apache.tomcat.util.net.SecureNioChannel) at > > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.j > > ava:1142) > > > > > at > > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor. > > java:617) > > > > > at > > > org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThr > > ead.java:61) > > > > > at java.lang.Thread.run(Thread.java:745) > > Is it possible to rule-out any network problems? Is there any pattern at all > to > the pauses? > > - -chris > -----BEGIN PGP SIGNATURE----- > Version: GnuPG v1 > Comment: GPGTools - http://gpgtools.org > > iQIcBAEBCAAGBQJUtV5CAAoJEBzwKT+lPKRYpOgP/RNMzeCZf1NdihufZvs26a > s6 > AfvsJik+W7w5FPh6McxF+fIv14KMCftxV+gthoFi6M5XemQndBmt/iWiCfA5DEi > E > QeLM8uY3HNP6gWJbpNvyV+TLu87+TVusJG/7QjNi+FvdBdWalwnBQ658P/jU > gITr > VVkheN2RHzTtgCLTAjcah9eAibeGV8sr/5jikeuVGCxj7JdGwkxuJBAtT7XNc6VY > oF0N0SmsLCukEWPzNuc5dhLFMhiNnbBEnRvIuLyCyG5i/CaPvDzJnaxBEZcyXC > P/ > /BLvwIzOeb22Sx9l1NVU3CLogaLW+UYjraD9FMcADG7KIZn5NFxLpCbdkjOdYq > Yw > yLb+mNH31JSoRJErb2cfJzu+JYQYKDCa+5eIcQrDZ561gGDd5oDQBdW/0hQADf > mF > D4NGc1epCiFh3Fbx26ti1h5gYrZO1GVBlpU6JESaIPUBCEDO0stbGx9avPxlrr0k > szLTWvigz7YOFKhdgVuXdXogxQdEcbICGUDrPOhOLQJJN4+RAuqZI1xSQPH+ > M0cQ > WSgl7vNZT1R66aa3doYtmFdypSPGCIrJ24vz4cuOtiRvADW7hca5X5D+tig1/7EL > 38mzJ/5U7p90kxTzPe1UYQEu3rv5EG10ER8VLuVUUl0lIByhx6lZuluc038dD+4i > o0YGlRfVHb4I3YmZyQk6 > =/ayz > -----END PGP SIGNATURE----- > > --------------------------------------------------------------------- > To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org > For additional commands, e-mail: users-h...@tomcat.apache.org >
There are numerous MySQL/Connector J bugs that are related to the stacktrace you sent, and more or less match the symptoms you are seeing, most around incorrect threading. See #9515, #24995, #56411, #74979.
