Re: [c3p0-users] Test on Checkout succeeding when connection has been dropped?
Status: Beta
Brought to you by:
swaldman
|
From: Steve W. <swa...@mc...> - 2013-07-15 09:23:01
|
the easiest thing to do is create an empty table and SELECT from that. c3p0 has some built-in support there, see http://www.mchange.com/projects/c3p0/#automaticTestTable smiles, steve On Jul 15, 2013, at 8:30 AM, Gustav Karlsson wrote: > The default preferredTestQuery seem to be working better. The application has been running for 3 days without any dropped connections now (most likely due to the fact that c3p0.idleConnectionTestPeriod is actually testing the connection now). > > Steve, do you have any tips for a quick testQuery which is not as simple as select 1? > > Thank you! > > Regards, > Gustav > > > Jul 11, 2013 kl. 2:08 PM skrev Gustav Karlsson <Gus...@BE...> > : > >> Hi Steve, >> >> Thank you for the quick reply! >> >> Yes, we have set the preferredTestQuery to "select 1 from dual", but I have also tried a domain-specific query, selecting from one of our tables (also "select 1 from mytable" though). I will try the default as you suggest and get back to you. >> >> Regards, >> Gustav >> >> >> Jul 11, 2013 kl. 1:47 PM skrev Steve Waldman <swa...@mc...> >> : >> >>> hi, >>> >>> have you set a preferredTestQuery? if so what is it? it's common to use very simple, very fast queries like SELECT 1, and that seems to work fine for a lot of set-ups. but in theory it's hazardous, a clever JDBC driver might resolve that one locally leading to an unreliable test for more elaborate queries. as a quick check, you might not set any preferredTestQuery at all, in which case c3p0 will fall back on a slow but reliable query to the database metadata. Does this still happen using the default test? >>> >>> smiles, >>> Steve >>> >>> >>> >>> On Jul 11, 2013, at 1:24 PM, Gustav Karlsson wrote: >>> >>>> Hi, >>>> >>>> We are experiencing a strange behavior of our connection pool: We get a read-timeout when executing a simple query even after the connection-test on checkout has suceeded. This occurrs typically at night after a period of low activity, leading us believe that the read-timeout may be caused by the connection having been dropped by a firewall (due to inactivity). >>>> >>>> >>>> 01:39:55.762 [server] [scheduler-3] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Testing PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb] on CHECKOUT. >>>> 01:39:55.764 [server] [scheduler-3] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Test of PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb] on CHECKOUT has SUCCEEDED. >>>> 01:40:05.779 [server] [scheduler-3] [ ] DEBUG c.m.v2.c3p0.impl.NewPooledConnection - com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb handling a throwable. >>>> 01:40:05.788 [server] [scheduler-3] [ ] DEBUG c.m.v.resourcepool.BasicResourcePool - Resource com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb marked broken by pool (com.mchange.v2.resourcepool.BasicResourcePool@31482ac5). >>>> 01:40:05.790 [server] [scheduler-3] [ ] ERROR o.s.s.s.TaskUtils$LoggingErrorHandler - Unexpected error occurred in scheduled task. >>>> org.springframework.dao.DataAccessResourceFailureException: PreparedStatementCallback; SQL [select count(*) from ...]; I/U-feil: Socket read timed out; nested exception is java.sql.SQLRecoverableException: I/U-feil: Socket read timed out >>>> >>>> >>>> >>>> Does anyone have any tips as to how the checkout-test can succeed when it seems as though the connection is dropped? (If we assume that the read-timeout is not caused by a slow query) >>>> >>>> We are using c3p0 v0.9.1.2 against an Orable 11g database. See full trace from c3p0 below. >>>> >>>> >>>> Regards, >>>> Gustav >>>> >>>> >>>> >>>> ... >>>> 1:39:09.341 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Testing PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb] on IDLE CHECK. >>>> 01:39:09.341 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#3] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Testing PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@4e514440] on IDLE CHECK. >>>> 01:39:09.342 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Testing PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@256e3879] on IDLE CHECK. >>>> 01:39:09.343 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Test of PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb] on IDLE CHECK has SUCCEEDED. >>>> 01:39:09.342 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Testing PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@5bd13aa] on IDLE CHECK. >>>> 01:39:09.342 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#4] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Testing PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@662ae1c9] on IDLE CHECK. >>>> 01:39:09.344 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Test of PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@5bd13aa] on IDLE CHECK has SUCCEEDED. >>>> 01:39:09.344 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#4] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Test of PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@662ae1c9] on IDLE CHECK has SUCCEEDED. >>>> 01:39:09.344 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#3] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Test of PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@4e514440] on IDLE CHECK has SUCCEEDED. >>>> 01:39:09.345 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Test of PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@256e3879] on IDLE CHECK has SUCCEEDED. >>>> 01:39:55.762 [server] [scheduler-3] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Testing PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb] on CHECKOUT. >>>> 01:39:55.764 [server] [scheduler-3] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Test of PooledConnection [com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb] on CHECKOUT has SUCCEEDED. >>>> 01:39:55.764 [server] [scheduler-3] [ ] DEBUG c.m.v.resourcepool.BasicResourcePool - trace com.mchange.v2.resourcepool.BasicResourcePool@31482ac5 [managed: 5, unused: 4, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@7ec2d0d0) >>>> 01:40:05.779 [server] [scheduler-3] [ ] DEBUG c.m.v2.c3p0.impl.NewPooledConnection - com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb handling a throwable. >>>> java.sql.SQLRecoverableException: I/U-feil: Socket read timed out >>>> at oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:876) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1153) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1275) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3576) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3620) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery(OraclePreparedStatementWrapper.java:1491) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:76) ~[c3p0-0.9.1.2.jar:0.9.1.2] >>>> at net.sf.log4jdbc.PreparedStatementSpy.executeQuery(PreparedStatementSpy.java:735) [log4jdbc-remix-0.2.7.jar:na] >>>> at org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement(JdbcTemplate.java:644) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE] >>>> at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:587) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE] >>>> at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:637) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE] >>>> at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:666) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE] >>>> at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:674) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE] >>>> at org.springframework.jdbc.core.JdbcTemplate.queryForObject(JdbcTemplate.java:729) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE] >>>> at org.springframework.jdbc.core.JdbcTemplate.queryForObject(JdbcTemplate.java:745) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE] >>>> at org.springframework.jdbc.core.JdbcTemplate.queryForInt(JdbcTemplate.java:776) [spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE] >>>> ... >>>> Caused by: oracle.net.ns.NetException: Socket read timed out >>>> at oracle.net.ns.Packet.receive(Packet.java:321) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at oracle.net.ns.DataPacket.receive(DataPacket.java:103) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> ... >>>> 01:40:05.781 [server] [scheduler-3] [ ] DEBUG com.mchange.v2.sql.SqlUtils - Attempted to convert SQLException to SQLException. Leaving it alone. [SQLState: 08006; errorCode: 17002] >>>> java.sql.SQLRecoverableException: I/U-feil: Socket read timed out >>>> at oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:876) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1153) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> ... >>>> Caused by: oracle.net.ns.NetException: Socket read timed out >>>> at oracle.net.ns.Packet.receive(Packet.java:321) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at oracle.net.ns.DataPacket.receive(DataPacket.java:103) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> ... >>>> 01:40:05.783 [server] [scheduler-3] [ ] DEBUG c.m.v.c.impl.DefaultConnectionTester - Testing a Connection in response to an Exception: >>>> java.sql.SQLRecoverableException: I/U-feil: Socket read timed out >>>> at oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:876) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1153) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> ... >>>> Caused by: oracle.net.ns.NetException: Socket read timed out >>>> at oracle.net.ns.Packet.receive(Packet.java:321) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> ... >>>> 01:40:05.784 [server] [scheduler-3] [ ] DEBUG c.m.v.c.impl.DefaultConnectionTester - Connection oracle.jdbc.driver.T4CConnection@3fdcc849 failed Connection test with an Exception! [query=select 1 from dual] >>>> java.sql.SQLRecoverableException: Lukket tilkobling >>>> at oracle.jdbc.driver.PhysicalConnection.createStatement(PhysicalConnection.java:3371) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at oracle.jdbc.driver.PhysicalConnection.createStatement(PhysicalConnection.java:3346) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at com.mchange.v2.c3p0.impl.DefaultConnectionTester.activeCheckConnection(DefaultConnectionTester.java:72) [c3p0-0.9.1.2.jar:0.9.1.2] >>>> ... >>>> 01:40:05.786 [server] [scheduler-3] [ ] DEBUG c.m.v2.c3p0.impl.NewPooledConnection - com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb invalidated by Exception. >>>> java.sql.SQLRecoverableException: I/U-feil: Socket read timed out >>>> at oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:876) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1153) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> ... >>>> Caused by: oracle.net.ns.NetException: Socket read timed out >>>> at oracle.net.ns.Packet.receive(Packet.java:321) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> ... >>>> 01:40:05.788 [server] [scheduler-3] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - CONNECTION ERROR OCCURRED! >>>> 01:40:05.788 [server] [scheduler-3] [ ] DEBUG c.m.v.resourcepool.BasicResourcePool - Resource com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb marked broken by pool (com.mchange.v2.resourcepool.BasicResourcePool@31482ac5). >>>> 01:40:05.788 [server] [scheduler-3] [ ] DEBUG c.m.v.resourcepool.BasicResourcePool - incremented pending_acquires: 1 >>>> 01:40:05.788 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1] [ ] DEBUG c.m.v.resourcepool.BasicResourcePool - Preparing to destroy resource: com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb >>>> 01:40:05.788 [server] [scheduler-3] [ ] DEBUG c.m.v.resourcepool.BasicResourcePool - trace com.mchange.v2.resourcepool.BasicResourcePool@31482ac5 [managed: 4, unused: 4, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@7ec2d0d0) >>>> 01:40:05.788 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Preparing to destroy PooledConnection: com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb >>>> 01:40:05.789 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1] [ ] DEBUG c.m.v2.c3p0.impl.NewPooledConnection - com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb closed by a client. >>>> java.lang.Exception: DEBUG -- CLOSE BY CLIENT STACK TRACE >>>> at com.mchange.v2.c3p0.impl.NewPooledConnection.close(NewPooledConnection.java:566) [c3p0-0.9.1.2.jar:0.9.1.2] >>>> at com.mchange.v2.c3p0.impl.NewPooledConnection.close(NewPooledConnection.java:234) [c3p0-0.9.1.2.jar:0.9.1.2] >>>> at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.destroyResource(C3P0PooledConnectionPool.java:470) [c3p0-0.9.1.2.jar:0.9.1.2] >>>> at com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask.run(BasicResourcePool.java:964) [c3p0-0.9.1.2.jar:0.9.1.2] >>>> at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547) [c3p0-0.9.1.2.jar:0.9.1.2] >>>> 01:40:05.789 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - Successfully destroyed PooledConnection: com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb >>>> 01:40:05.789 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1] [ ] DEBUG c.m.v.resourcepool.BasicResourcePool - Successfully destroyed resource: com.mchange.v2.c3p0.impl.NewPooledConnection@35270bfb >>>> 01:40:05.790 [server] [scheduler-3] [ ] ERROR o.s.s.s.TaskUtils$LoggingErrorHandler - Unexpected error occurred in scheduled task. >>>> org.springframework.dao.DataAccessResourceFailureException: PreparedStatementCallback; SQL [select count(*) from ...]; I/U-feil: Socket read timed out; nested exception is java.sql.SQLRecoverableException: I/U-feil: Socket read timed out >>>> at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:253) ~[spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE] >>>> at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72) ~[spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE] >>>> at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:603) ~[spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE] >>>> at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:637) ~[spring-jdbc-3.1.1.RELEASE.jar:3.1.1.RELEASE] >>>> ... >>>> Caused by: java.sql.SQLRecoverableException: I/U-feil: Socket read timed out >>>> at oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:876) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1153) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> ... >>>> Caused by: oracle.net.ns.NetException: Socket read timed out >>>> at oracle.net.ns.Packet.receive(Packet.java:321) ~[ojdbc6-11.2.0.2.0.jar:11.2.0.2.0] >>>> ... >>>> 01:40:05.833 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2] [ ] DEBUG c.m.v.c.i.C3P0PooledConnectionPool - com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager@69fed553.acquireResource() returning. >>>> 01:40:05.834 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2] [ ] DEBUG c.m.v.resourcepool.BasicResourcePool - trace com.mchange.v2.resourcepool.BasicResourcePool@31482ac5 [managed: 5, unused: 5, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@7ec2d0d0) >>>> 01:40:05.834 [server] [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2] [ ] DEBUG c.m.v.resourcepool.BasicResourcePool - decremented pending_acquires: 0 >>>> 01:44:09.343 [server] [Timer-0] [ ] DEBUG c.m.v.resourcepool.BasicResourcePool - Refurbishing idle resources - Thu Jul 11 01:44:09 CEST 2013 [com.mchange.v2.resourcepool.BasicResourcePool@31482ac5] >>>> 01:44:09.343 [server] [Timer-0] [ ] DEBUG c.m.v.resourcepool.BasicResourcePool - trace com.mchange.v2.resourcepool.BasicResourcePool@31482ac5 [managed: 5, unused: 5, excluded: 0] (e.g. com.mchange.v2.c3p0.impl.NewPooledConnection@7ec2d0d0) >>>> >>>> >>>> >>>> ------------------------------------------------------------------------------ >>>> See everything from the browser to the database with AppDynamics >>>> Get end-to-end visibility with application monitoring from AppDynamics >>>> Isolate bottlenecks and diagnose root cause in seconds. >>>> Start your free trial of AppDynamics Pro today! >>>> http://pubads.g.doubleclick.net/gampad/clk?id=48808831&iu=/4140/ostg.clktrk >>>> _______________________________________________ >>>> c3p0-users mailing list >>>> c3p...@li... >>>> https://lists.sourceforge.net/lists/listinfo/c3p0-users >>> >> >> >> ------------------------------------------------------------------------------ >> See everything from the browser to the database with AppDynamics >> Get end-to-end visibility with application monitoring from AppDynamics >> Isolate bottlenecks and diagnose root cause in seconds. >> Start your free trial of AppDynamics Pro today! >> http://pubads.g.doubleclick.net/gampad/clk?id=48808831&iu=/4140/ostg.clktrk >> _______________________________________________ >> c3p0-users mailing list >> c3p...@li... >> https://lists.sourceforge.net/lists/listinfo/c3p0-users > |