Hibernate C3P0 unreturnedConnectionTimeout and debugUnreturnedConnectionStackTraces not working

Question

I am using Hibernate 3.3 and got to know it comes bundled with C3P0. But after adding C3P0 property settings in hibernate.cfg.xml, classnotfound exception appeared in console, then i downloaded and added c3p0-0.9.1.jar in my classpath and C3P0 started working.

Now when i am adding below lines to my hibernate.cfg.xml using Eclipse:

<property name="hibernate.c3p0.

Intellisense only showing me:

 hibernate.c3p0.acquire_increment
 hibernate.c3p0.idle_test_period
 hibernate.c3p0.max_size
 hibernate.c3p0.max_statements
 hibernate.c3p0.min_size
 hibernate.c3p0.timeout

It's not showing me unreturnedConnectionTimeout and debugUnreturnedConnectionStackTraces attributes, still i copy pasted these two lines and not having any effect. I am not getting debugUnreturnedConnectionStackTraces in server logs anytime.

below is my hibernate.cfg.xml:

<hibernate-configuration>
<session-factory>
<property name="hibernate.c3p0.unreturnedConnectionTimeout">40</property>
<property name="hibernate.c3p0.debugUnreturnedConnectionStackTraces">true</property>
    <property name="hibernate.dialect">org.hibernate.dialect.Oracle9Dialect</property>
    <property name="hibernate.connection.url">jdbc:oracle:thin:@xyz:1521:sid</property>
    <property name="hibernate.connection.username">abc</property>
    <property name="hibernate.connection.password">123</property>
    <property name="hibernate.connection.driver_class">oracle.jdbc.driver.OracleDriver</property>
    <property name="hibernate.connection.provider_class">org.hibernate.connection.C3P0ConnectionProvider</property>

    <property name="hibernate.c3p0.min_size">5</property>
    <property name="hibernate.c3p0.max_size">30</property>
    <property name="hibernate.c3p0.timeout">20</property>
    <property name="hibernate.c3p0.max_statements">50</property>
    <property name="hibernate.c3p0.idle_test_period">3000</property>

    <property name="hibernate.c3p0.unreturnedConnectionTimeout">40</property>
    <property name="hibernate.c3p0.debugUnreturnedConnectionStackTraces">true</property>
 </session-factory>

 </hibernate-configuration>

Info level Dump as:

INFO  [org.hibernate.validator.Version] (http--0.0.0.0-8081-3) Hibernate Validator 3.1.0.GA
INFO  [org.hibernate.connection.ConnectionProviderFactory] (http--0.0.0.0-8081-3) Initializing connection provider: org.hibernate.connection.C3P0ConnectionProvider
INFO  [org.hibernate.connection.C3P0ConnectionProvider] (http--0.0.0.0-8081-3) C3P0 using driver: oracle.jdbc.driver.OracleDriver at URL: jdbcracle:thinxyz:1521:abc
INFO  [org.hibernate.connection.C3P0ConnectionProvider] (http--0.0.0.0-8081-3) Connection properties: {user=abcd, password=****, release_mode=after_statement}
INFO  [org.hibernate.connection.C3P0ConnectionProvider] (http--0.0.0.0-8081-3) autocommit mode: false
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) RDBMS: Oracle, version: Oracle Database 11g Release 11.1.0.0.0 - Production
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) JDBC driver: Oracle JDBC driver, version: 10.2.0.5.0
INFO  [org.hibernate.dialect.Dialect] (http--0.0.0.0-8081-3) Using dialect: org.hibernate.dialect.Oracle9Dialect
 WARN  [org.hibernate.dialect.Oracle9Dialect] (http--0.0.0.0-8081-3) The Oracle9Dialect dialect has been deprecated; use either Oracle9iDialect or Oracle10gDialect instead
 INFO  [org.hibernate.transaction.TransactionFactoryFactory] (http--0.0.0.0-8081-3) Using default transaction strategy (direct JDBC transactions)
 INFO  [org.hibernate.transaction.TransactionManagerLookupFactory] (http--0.0.0.0-8081-3) No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended)
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Automatic flush during beforeCompletion(): disabled
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Automatic session close at end of transaction: disabled
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) JDBC batch size: 15
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) JDBC batch updates for versioned data: disabled
 INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Scrollable result sets: enabled
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) JDBC3 getGeneratedKeys(): disabled
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Connection release mode: after_statement
 WARN  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Overriding release mode as connection provider does not support 'after_statement'
 INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Default batch fetch size: 1
 INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Generate SQL with comments: disabled
 INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Order SQL updates by primary key: disabled
 INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Order SQL inserts for batching: disabled
 INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
 INFO  [org.hibernate.hql.ast.ASTQueryTranslatorFactory] (http--0.0.0.0-8081-3) Using ASTQueryTranslatorFactory
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Query language substitutions: {}
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) JPA-QL strict compliance: disabled
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Second-level cache: enabled
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Query cache: disabled
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Cache region factory : org.hibernate.cache.impl.NoCachingRegionFactory
INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Optimize cache for minimal puts: disabled
 INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Structured second-level cache entries: disabled
 INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Statistics: disabled
 INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Deleted entity synthetic identifier rollback: disabled
 INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Default entity-mode: pojo
 INFO  [org.hibernate.cfg.SettingsFactory] (http--0.0.0.0-8081-3) Named query checking : enabled
INFO  [org.hibernate.impl.SessionFactoryImpl] (http--0.0.0.0-8081-3) building session factory
INFO  [org.hibernate.impl.SessionFactoryObjectFactory] (http--0.0.0.0-8081-3) Not binding factory to JNDI, no JNDI name configured

com.mchange logs:

DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.dialect=org.hibernate.dialect.Oracle9Dialect
DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.connection.url=jdbc:oracle:thin:@abcd:1521:xyz
DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.connection.username=yyy
DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.connection.password=xxx
DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.connection.driver_class=oracle.jdbc.driver.OracleDriver
DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.connection.provider_class=org.hibernate.connection.C3P0ConnectionProvider
DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.connection.release_mode=after_statement
DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.c3p0.min_size=5
DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.c3p0.max_size=30
DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.c3p0.timeout=20
DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.c3p0.max_statements=50
DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.c3p0.idle_test_period=3000
DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.c3p0.unreturnedConnectionTimeout=40
DEBUG [org.hibernate.cfg.Configuration] (http--0.0.0.0-8081-1) hibernate.c3p0.debugUnreturnedConnectionStackTraces=true

com.mchange Logs at ERROR Level:

ERROR [org.hibernate.util.JDBCExceptionReporter] (http--0.0.0.0-8081-1) com.mchange.v2.c3p0.PoolBackedDataSource@3a49b3d [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@f6d285eb [ acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, debugUnreturnedConnectionStackTraces -> true, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 31l7yg907o7aar1ysxqrk|22915056, idleConnectionTestPeriod -> 3000, initialPoolSize -> 5, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 20, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 30, maxStatements -> 50, maxStatementsPerConnection -> 0, minPoolSize -> 5, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@8bc0578a     [ description -> null, driverClass -> null, factoryClassLocation -> null, identityToken -> 31l7yg907o7aar1ysxqrk|58363f95, jdbcUrl -> jdbc:oracle:thin:@cFRO:1521:ivfrt, properties -> {user=******, password=******, release_mode=after_statement} ], preferredTestQuery -> null, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 40, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, factoryClassLocation -> null, identityToken -> 31l7yg907o7aar1ysxqrk|301c2c35, numHelperThreads -> 3 ] has been closed() -- you can no longer use it.
TRACE [org.jboss.modules] (http--0.0.0.0-8081-8) Attempting to find resource frro/daos/administration/ in Module "deployment.appname.war:main" from Service Module Loader
ERROR [stderr] (http--0.0.0.0-8081-1) Error! Please, check your JDBC/JDNI Configurations and Database Server avaliability.

Answer 1

With c3p0 9.2.1 I only see the stack trace when I set debug level to FINEST. This gives

23/08/2019 18.32.11:BST:FINEST: com.mchange.v2.c3p0.impl.NewPooledConnection@6231dbc0 closed by a client.
java.lang.Exception: DEBUG -- CLOSE BY CLIENT STACK TRACE
    at com.mchange.v2.c3p0.impl.NewPooledConnection.close(NewPooledConnection.java:646)
    at com.mchange.v2.c3p0.impl.NewPooledConnection.closeMaybeCheckedOut(NewPooledConnection.java:259)
    at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.destroyResource(C3P0PooledConnectionPool.java:619)
    at com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask.run(BasicResourcePool.java:1024)
    at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:648)
23/08/2019 18.32.11:BST:FINEST: com.mchange.v2.c3p0.impl.NewPooledConnection@26190855 closed by a client.

And the code in NewPooledCOnnection.java says

 if (cause == null) {
                this.invalidatingException = NORMAL_CLOSE_PLACEHOLDER;
                if (logger.isLoggable(MLevel.FINEST)) {
                    logger.log(MLevel.FINEST, this + " closed by a client.", new Exception("DEBUG -- CLOSE BY CLIENT STACK TRACE"));
                }

                logCloseExceptions((Throwable)null, closeExceptions);
                if (closeExceptions.size() > 0) {
                    throw new SQLException("Some resources failed to close properly while closing " + this);
                }
            } else {
                this.invalidatingException = cause;
                logCloseExceptions(cause, closeExceptions);
            }

So maybe this explains why the stack traces are not shown.

Answer 2

Maybe the news is good, and your application has no Connection leaks. These settings will have visible effect only if Connections are checked out, but then are sometimes never checked back in. In a well-written application that will never happen.

Do verify, though, that the settings are "taking". c3p0 dumps its config at INFO on pool initialization. Verify that unreturnedConnectionTimeout and debugUnreturnedConnectionStackTraces have the values you expect.

c3p0 0.9.1.x is very old. Upgrade at least to 0.9.2.1, or to the latest 0.9.5 pre release, please.

Once you are satisfied that you've debugged any Connection leak (or that there is none), do disable debugUnreturnedConnectionStackTraces, which creates a significant performance drag.