Context: I am accessing AWS Athena DB using Simba JDBC Driver with C3P0 connection pooling (CP) configured. Encountering DB Connection Pooling threads being reinitialized after some time, even though have configured various C3P0 fine tuning properties. Please find list of them below:
C3P0 Version: c3p0-0.9.5.5 \[built 11-December-2019 22:18:33 -0800; debug? true; trace: 10\]
maxWait: "20"
maxStatements: "10"
maxPoolSize: "20"
minPoolSize: "3"
maxIdleTime: "1800"
preparedStatementCacheSize: "5"
acquireIncrement: "3"
idleConnectionTestPeriod: "30"
initialPoolSize: "3"
testConnectionOnCheckin: "true"
testConnectionOnCheckout: "false"
debugUnreturnedConnectionStackTraces: "true"
App Deployed on 2 workers with multiple (>1) worker threads.
Issues & Questions:
initialPoolSizeis not working at all. At max, pool size is at most 1 connection per worker.
- Even after C3P0 pool is stable (with "Refurbishing idle resources" logs appearing in logs frequently)
- Once DB request is initiated, CP thread is re-initialized as new (Log Sample 1: Initializing c3p0 pool...)
- Another Observation is there seem to be multiple CP objects simultaneously in same worker. Could this correspond to worker threads? Why do they exist simultaneously? (Log Sample 2: BasicResourcePool@52e8fb44 & BasicResourcePool@6383620e)
Log Sample 1: Sample Logs from 1 worker (not necessarily for same DB Connection Pool thread):
[2023-10-22 12:01:54.067] WARN Attempted to override property initialPoolSize using additional-properties. Proceeding to use initialPoolSize = 3.
[2023-10-22 12:01:54.235] INFO Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@233ef5fb [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@39b1da15 [ acquireIncrement -> 3, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 20000, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, contextClassLoaderSource -> caller, debugUnreturnedConnectionStackTraces -> true, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, forceSynchronousCheckins -> false, identityToken -> rvmyeoazo7l0pbm9pc6k|4201cfe6, idleConnectionTestPeriod -> 30, initialPoolSize -> 3, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 1800, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 20, maxStatements -> 10, maxStatementsPerConnection -> 5, minPoolSize -> 3, nestedDataSource -> StandardDataSource:
[2023-10-22 12:01:55.788] DEBUG acquire test -- pool size: 1; target_pool_size: 6; desired target? 4
[2023-10-22 12:01:55.783] DEBUG awaitAvailable():
[2023-10-22 12:01:56.460] DEBUG ResultSet opened, now 1 active [2023-10-22 12:01:56.595] DEBUG Closing 1 resultSets
Log Sample 2: Logs for multiple CP Objects in question 2:
[2023-10-22 07:52:49.552] DEBUG com.mchange.v2.resourcepool.BasicResourcePool [C3P0PooledConnectionPoolManager[identityToken->rvn2r2aznyqbureaga4x|6c762ebf]-AdminTaskTimer]: Refurbishing idle resources - Sun Oct 22 07:52:49 UTC 2023 [com.mchange.v2.resourcepool.BasicResourcePool@52e8fb44]
[2023-10-22 08:01:04.771] DEBUG com.mchange.v2.resourcepool.BasicResourcePool [C3P0PooledConnectionPoolManager[identityToken->rvn2r2aznyqbureaga4x|26020260]-AdminTaskTimer]: Refurbishing idle resources - Sun Oct 22 08:01:04 UTC 2023 [com.mchange.v2.resourcepool.BasicResourcePool@6383620e]
[2023-10-22 08:13:34.773] DEBUG com.mchange.v2.resourcepool.BasicResourcePool [C3P0PooledConnectionPoolManager[identityToken->rvn2r2aznyqbureaga4x|26020260]-AdminTaskTimer]: Refurbishing idle resources - Sun Oct 22 08:13:34 UTC 2023 [com.mchange.v2.resourcepool.BasicResourcePool@6383620e]
[2023-10-22 09:12:49.578] DEBUG com.mchange.v2.resourcepool.BasicResourcePool [C3P0PooledConnectionPoolManager[identityToken->rvn2r2aznyqbureaga4x|6c762ebf]-AdminTaskTimer]: Refurbishing idle resources - Sun Oct 22 09:12:49 UTC 2023 [com.mchange.v2.resourcepool.BasicResourcePool@52e8fb44]
Mule DB Connector: v1.14.4
Mule DB Connection Config: Generic Connection
Mule Runtime: v4.4.0 EE (Latest Patch)
Deployment: CloudHub 1.0
Worker Config: 0.2 vCore with 2 workers
Athena Simba JDBC Jar: v2.0.36.1000
[Edit-2]
<db:config name="Database_Config" doc:name="Database Config"
doc:id="2a143827-dd45-4f32-a555-a24df53b0264">
<db:generic-connection
url="#[vars.athenaConnectionUrl.url]"
driverClassName="com.simba.athena.jdbc.Driver" user="#[vars.athenaVaultVar.Athena.username]"
password="#[vars.athenaVaultVar.Athena.password]" >
<db:pooling-profile minPoolSize="${athena.db.minPoolSize}" testConnectionOnCheckout="false" maxPoolSize="${athena.db.maxPoolSize}" acquireIncrement="${athena.db.pooling.acquire.increment}" preparedStatementCacheSize="${athena.db.pooling.cache.size}" maxWait="${athena.db.connectionWaitTimeout}" maxIdleTime="${athena.db.standard.idleTimeout}" maxStatements="${athena.db.maxStatement}">
<db:additional-properties >
<db:additional-property key="idleConnectionTestPeriod" value="${athena.db.pooling.idleConnectionTestPeriod}" />
<db:additional-property key="initialPoolSize" value="${athena.db.pooling.initialPoolSize}" />
<db:additional-property key="testConnectionOnCheckin" value="${athena.db.pooling.testConnectionOnCheckin}" />
<db:additional-property key="debugUnreturnedConnectionStackTraces" value="${athena.db.pooling.debugUnreturnedConnectionStackTraces}" />
</db:additional-properties>
</db:pooling-profile>
</db:generic-connection>
</db:config>
[/Edit-2]