That is very easily fixed testOnBorrow="true" validationQuery="SELECT 1"
Do you have this set? Otherwise, yes, you wont be able to detect if connections time out. send me your config ----- Original Message ----- > From: "Colin Ingarfield" <colin...@gmail.com> > To: users@tomcat.apache.org > Sent: Wednesday, March 21, 2012 6:23:02 AM > Subject: Re: how to enable debug logging for Tomcat jdbc pool (Tomcat 6.0.32) > > Hello Filip, > > Over the weekend my application appears to have lost connectivity to > its > MySQL server. At that point in my logs I see these errors: > > 2012-03-16 18:25:18,248 ERROR [pool-3-thread-201] > c.l.c.s.e.EventServiceImpl failed to store event > [com.lim.cd.service.event.beans.SubscribeEvent@730c434d] > org.springframework.dao.RecoverableDataAccessException: > PreparedStatementCallback; SQL [insert into sessions (session_id, > username, uuid, created) values (?, ?, ?, ?)]; Communications link > failure > > The last packet sent successfully to the server was 0 milliseconds > ago. > The driver has not received any packets from the server.; nested > exception is com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: > Communications link failure > (... a lot omitted ...) > Caused by: java.net.ConnectException: Connection timed out > > (the whole stack trace is long, I'll post it at the end.) > > This error appeared over and over again for 2 hours and every MySQL > request failed. After restarting Tomcat the app was able to connect > to > MySQL and functioned normally. This is the first and only time I've > seen this happen. > > Assuming this was a brief network or MySQL outage (the sys admins > haven't said either way), I would expect the connection pool to > handle > the situation by destroying these dead connections and creating new > ones > automatically once database connectivity was restored. That never > happened (until we restarted Tomcat.) > > So my thought was to turn up the logging on the connection pool and > try > to see what's going on. I couldn't find any log output from the pool > in > my logs or in the Tomcat logs directory. > > My application uses Spring JDBC and Spring's @Transaction annotations > so > my code does not directly interact with the DataSource or the jdbc > Connections. > > I suspect a misconfiguration on my part but I need to know what is > actually failing before I can figure out what's wrong. > > Any advice greatly appreciated. > > Thanks, > Colin > > full stack trace: > 2012-03-16 18:25:18,248 ERROR [pool-3-thread-201] > c.l.c.s.e.EventServiceImpl failed to store event > [com.lim.cd.service.event.beans.SubscribeEvent@730c434d] > org.springframework.dao.RecoverableDataAccessException: > PreparedStatementCallback; SQL [insert into sessions (session_id, > username, uuid, created) values (?, ?, ?, ?)]; Communications link > failure > > The last packet sent successfully to the server was 0 milliseconds > ago. > The driver has not received any packets from the server.; nested > exception is com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: > Communications link failure > > The last packet sent successfully to the server was 0 milliseconds > ago. > The driver has not received any packets from the server. > at > org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:98) > ~[spring-jdbc-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72) > ~[spring-jdbc-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80) > ~[spring-jdbc-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:602) > ~[spring-jdbc-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:811) > ~[spring-jdbc-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:867) > ~[spring-jdbc-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:875) > ~[spring-jdbc-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > com.lim.cd.service.event.dao.MySqlEventDao.createSession(MySqlEventDao.java:201) > ~[MySqlEventDao.class:na] > at > com.lim.cd.service.event.dao.MySqlEventDao.createOrUpdateSession(MySqlEventDao.java:191) > ~[MySqlEventDao.class:na] > at sun.reflect.GeneratedMethodAccessor62.invoke(Unknown Source) > ~[na:na] > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > ~[na:1.6.0_29] > at java.lang.reflect.Method.invoke(Method.java:597) > ~[na:1.6.0_29] > at > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309) > ~[spring-aop-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) > ~[spring-aop-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) > ~[spring-aop-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110) > ~[spring-tx-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) > ~[spring-aop-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) > ~[spring-aop-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at $Proxy26.createOrUpdateSession(Unknown Source) ~[na:na] > at > com.lim.cd.service.event.EventServiceImpl$1.run(EventServiceImpl.java:94) > ~[EventServiceImpl$1.class:na] > at > java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) > [na:1.6.0_29] > at > java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) > [na:1.6.0_29] > at java.util.concurrent.FutureTask.run(FutureTask.java:138) > [na:1.6.0_29] > at > java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) > [na:1.6.0_29] > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) > [na:1.6.0_29] > at java.lang.Thread.run(Thread.java:662) [na:1.6.0_29] > Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: > Communications link failure > > The last packet sent successfully to the server was 0 milliseconds > ago. > The driver has not received any packets from the server. > at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native > Method) ~[na:1.6.0_29] > at > sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39) > ~[na:1.6.0_29] > at > sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27) > ~[na:1.6.0_29] > at > java.lang.reflect.Constructor.newInstance(Constructor.java:513) > ~[na:1.6.0_29] > at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) > ~[mysql-connector-java-5.1.17-bin.jar:na] > at > com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1116) > ~[mysql-connector-java-5.1.17-bin.jar:na] > at com.mysql.jdbc.MysqlIO.<init>(MysqlIO.java:344) > ~[mysql-connector-java-5.1.17-bin.jar:na] > at > com.mysql.jdbc.ConnectionImpl.coreConnect(ConnectionImpl.java:2333) > ~[mysql-connector-java-5.1.17-bin.jar:na] > at > com.mysql.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:2370) > ~[mysql-connector-java-5.1.17-bin.jar:na] > at > com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2154) > ~[mysql-connector-java-5.1.17-bin.jar:na] > at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:792) > ~[mysql-connector-java-5.1.17-bin.jar:na] > at > com.mysql.jdbc.JDBC4Connection.<init>(JDBC4Connection.java:47) > ~[mysql-connector-java-5.1.17-bin.jar:na] > at > sun.reflect.GeneratedConstructorAccessor101.newInstance(Unknown > Source) ~[na:na] > at > sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27) > ~[na:1.6.0_29] > at > java.lang.reflect.Constructor.newInstance(Constructor.java:513) > ~[na:1.6.0_29] > at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) > ~[mysql-connector-java-5.1.17-bin.jar:na] > at > com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:381) > ~[mysql-connector-java-5.1.17-bin.jar:na] > at > com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:305) > ~[mysql-connector-java-5.1.17-bin.jar:na] > at > org.apache.tomcat.jdbc.pool.PooledConnection.connectUsingDriver(PooledConnection.java:267) > ~[tomcat-jdbc-1.1.0.1.jar:na] > at > org.apache.tomcat.jdbc.pool.PooledConnection.connect(PooledConnection.java:176) > ~[tomcat-jdbc-1.1.0.1.jar:na] > at > org.apache.tomcat.jdbc.pool.ConnectionPool.createConnection(ConnectionPool.java:653) > ~[tomcat-jdbc-1.1.0.1.jar:na] > at > org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:595) > ~[tomcat-jdbc-1.1.0.1.jar:na] > at > org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:174) > ~[tomcat-jdbc-1.1.0.1.jar:na] > at > org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:111) > ~[tomcat-jdbc-1.1.0.1.jar:na] > at sun.reflect.GeneratedMethodAccessor22.invoke(Unknown Source) > ~[na:na] > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > ~[na:1.6.0_29] > at java.lang.reflect.Method.invoke(Method.java:597) > ~[na:1.6.0_29] > at > net.bull.javamelody.JdbcWrapper$4.invoke(JdbcWrapper.java:660) > ~[javamelody-core-1.34.0.jar:1.34.0] > at > net.bull.javamelody.JdbcWrapper$DelegatingInvocationHandler.invoke(JdbcWrapper.java:232) > ~[javamelody-core-1.34.0.jar:1.34.0] > at $Proxy4.getConnection(Unknown Source) ~[na:na] > at sun.reflect.GeneratedMethodAccessor22.invoke(Unknown Source) > ~[na:na] > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > ~[na:1.6.0_29] > at java.lang.reflect.Method.invoke(Method.java:597) > ~[na:1.6.0_29] > at > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309) > ~[spring-aop-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:196) > ~[spring-aop-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at $Proxy13.getConnection(Unknown Source) ~[na:na] > at sun.reflect.GeneratedMethodAccessor22.invoke(Unknown Source) > ~[na:na] > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > ~[na:1.6.0_29] > at java.lang.reflect.Method.invoke(Method.java:597) > ~[na:1.6.0_29] > at > net.bull.javamelody.JdbcWrapper$4.invoke(JdbcWrapper.java:660) > ~[javamelody-core-1.34.0.jar:1.34.0] > at > net.bull.javamelody.JdbcWrapper$DelegatingInvocationHandler.invoke(JdbcWrapper.java:232) > ~[javamelody-core-1.34.0.jar:1.34.0] > at $Proxy21.getConnection(Unknown Source) ~[na:na] > at > org.springframework.jdbc.datasource.LazyConnectionDataSourceProxy$LazyConnectionInvocationHandler.getTargetConnection(LazyConnectionDataSourceProxy.java:403) > ~[spring-jdbc-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.jdbc.datasource.LazyConnectionDataSourceProxy$LazyConnectionInvocationHandler.invoke(LazyConnectionDataSourceProxy.java:376) > ~[spring-jdbc-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at $Proxy28.prepareStatement(Unknown Source) ~[na:na] > at sun.reflect.GeneratedMethodAccessor28.invoke(Unknown Source) > ~[na:na] > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > ~[na:1.6.0_29] > at java.lang.reflect.Method.invoke(Method.java:597) > ~[na:1.6.0_29] > at > net.bull.javamelody.JdbcWrapper$ConnectionInvocationHandler.invoke(JdbcWrapper.java:176) > ~[javamelody-core-1.34.0.jar:1.34.0] > at > net.bull.javamelody.JdbcWrapper$DelegatingInvocationHandler.invoke(JdbcWrapper.java:232) > ~[javamelody-core-1.34.0.jar:1.34.0] > at $Proxy29.prepareStatement(Unknown Source) ~[na:na] > at > org.springframework.jdbc.core.JdbcTemplate$SimplePreparedStatementCreator.createPreparedStatement(JdbcTemplate.java:1375) > ~[spring-jdbc-3.0.5.RELEASE.jar:3.0.5.RELEASE] > at > org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:580) > ~[spring-jdbc-3.0.5.RELEASE.jar:3.0.5.RELEASE] > ... 22 common frames omitted > Caused by: java.net.ConnectException: Connection timed out > at java.net.PlainSocketImpl.socketConnect(Native Method) > ~[na:1.6.0_29] > at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:351) > ~[na:1.6.0_29] > at > java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:213) > ~[na:1.6.0_29] > at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:200) > ~[na:1.6.0_29] > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366) > ~[na:1.6.0_29] > at java.net.Socket.connect(Socket.java:529) ~[na:1.6.0_29] > at java.net.Socket.connect(Socket.java:478) ~[na:1.6.0_29] > at java.net.Socket.<init>(Socket.java:375) ~[na:1.6.0_29] > at java.net.Socket.<init>(Socket.java:218) ~[na:1.6.0_29] > at > com.mysql.jdbc.StandardSocketFactory.connect(StandardSocketFactory.java:257) > ~[mysql-connector-java-5.1.17-bin.jar:na] > at com.mysql.jdbc.MysqlIO.<init>(MysqlIO.java:294) > ~[mysql-connector-java-5.1.17-bin.jar:na] > ... 68 common frames omitted > > > > > > > > On 03/20/2012 10:29 AM, Filip Hanik (mailing lists) wrote: > > Define "connection timeouts" so that we can understand your problem > to > suggest for how to trace it down. > What are you trying to search for. Errors would be logged as errors, > and > should show up with the standard configuration > > Filip > > > -----Original Message----- > From: Colin Ingarfield [mailto:colin...@gmail.com > <colin...@gmail.com>] > Sent: Monday, March 19, 2012 1:51 PM > To: users@tomcat.apache.org > Subject: how to enable debug logging for Tomcat jdbc pool (Tomcat > 6.0.32) > > Hello, > > I'm using the new Tomcat jdbc pool (1.1.0.1) with Tomcat 6.0.32, > Ubuntu > x86_64. I would like to increase the logging from the pool to try > and > chase down connection timeouts. > > I added the following line to $CATALINA_BASE/conf/logging.properties: > org.apache.tomcat.jdbc.pool.level=FINE > > (the rest of the logging.properties file is unchanged.) > > But I don't see any pool debug logging output on the console. I > thought > this setting would enable debug logging for all classes in that > package. > Is there something else I need to do? > > Thank you, > Colin > --------------------------------------------------------------------- To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
