You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ignite.apache.org by "Ignite TC Bot (Jira)" <ji...@apache.org> on 2022/10/13 05:13:00 UTC

[jira] [Commented] (IGNITE-15245) JDBC connection leak with cache.invoke() over cache store with external JDBC storage

    [ https://issues.apache.org/jira/browse/IGNITE-15245?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17616777#comment-17616777 ] 

Ignite TC Bot commented on IGNITE-15245:
----------------------------------------

{panel:title=Branch: [pull/10302/head] Base: [master] : Possible Blockers (1)|borderStyle=dashed|borderColor=#ccc|titleBGColor=#F7D6C1}
{color:#d04437}Control Utility 2{color} [[tests 1|https://ci2.ignite.apache.org/viewLog.html?buildId=6816585]]
* IgniteControlUtilityTestSuite2: GridCommandHandlerDefragmentationTest.testDefragmentationStatus - History for base branch is absent.

{panel}
{panel:title=Branch: [pull/10302/head] Base: [master] : New Tests (436)|borderStyle=dashed|borderColor=#ccc|titleBGColor=#D6F7C1}
{color:#00008b}Control Utility 2{color} [[tests 429|https://ci2.ignite.apache.org/viewLog.html?buildId=6816585]]
* {color:#013220}IgniteControlUtilityTestSuite2: GridCommandHandlerConsistencyTest.testAtomicAndTxValueAndVersion[strategy=REMOVE, explicitGrp=false, callByGrp=false] - PASSED{color}
* {color:#013220}IgniteControlUtilityTestSuite2: GridCommandHandlerConsistencyTest.testAtomicAndTxVersionOnly[strategy=RELATIVE_MAJORITY, explicitGrp=true, callByGrp=false] - PASSED{color}
* {color:#013220}IgniteControlUtilityTestSuite2: GridCommandHandlerConsistencyTest.testCacheFilter[strategy=RELATIVE_MAJORITY, explicitGrp=true, callByGrp=false] - PASSED{color}
* {color:#013220}IgniteControlUtilityTestSuite2: GridCommandHandlerConsistencyTest.testRepairNonExistentCache[strategy=RELATIVE_MAJORITY, explicitGrp=true, callByGrp=false] - PASSED{color}
* {color:#013220}IgniteControlUtilityTestSuite2: GridCommandHandlerConsistencyTest.testAtomicAndTxValueAndVersion[strategy=REMOVE, explicitGrp=true, callByGrp=true] - PASSED{color}
* {color:#013220}IgniteControlUtilityTestSuite2: GridCommandHandlerConsistencyTest.testAtomicAndTxVersionOnly[strategy=REMOVE, explicitGrp=false, callByGrp=false] - PASSED{color}
* {color:#013220}IgniteControlUtilityTestSuite2: GridCommandHandlerConsistencyTest.testCacheFilter[strategy=REMOVE, explicitGrp=false, callByGrp=false] - PASSED{color}
* {color:#013220}IgniteControlUtilityTestSuite2: GridCommandHandlerConsistencyTest.testRepairNonExistentCache[strategy=REMOVE, explicitGrp=false, callByGrp=false] - PASSED{color}
* {color:#013220}IgniteControlUtilityTestSuite2: GridCommandHandlerConsistencyTest.testAtomicAndTxValueAndVersion[strategy=REMOVE, explicitGrp=true, callByGrp=false] - PASSED{color}
* {color:#013220}IgniteControlUtilityTestSuite2: GridCommandHandlerConsistencyTest.testAtomicAndTxVersionOnly[strategy=REMOVE, explicitGrp=true, callByGrp=true] - PASSED{color}
* {color:#013220}IgniteControlUtilityTestSuite2: GridCommandHandlerConsistencyTest.testCacheFilter[strategy=REMOVE, explicitGrp=true, callByGrp=true] - PASSED{color}
... and 418 new tests

{color:#00008b}Platform .NET (Windows){color} [[tests 2|https://ci2.ignite.apache.org/viewLog.html?buildId=6816545]]
* {color:#013220}exe: ClientConnectionTest.TestExceptionInRetryPolicyPropagatesToCaller(True) - PASSED{color}
* {color:#013220}exe: ClientConnectionTest.TestExceptionInRetryPolicyPropagatesToCaller(False) - PASSED{color}

{color:#00008b}Cache 1{color} [[tests 1|https://ci2.ignite.apache.org/viewLog.html?buildId=6816472]]
* {color:#013220}IgniteBinaryCacheTestSuite: CacheJdbcPojoWriteBehindConnectionLeakTest.testInvoke - PASSED{color}

{color:#00008b}Thin Client: Java{color} [[tests 4|https://ci2.ignite.apache.org/viewLog.html?buildId=6816566]]
* {color:#013220}ClientTestSuite: ReliabilityTestPartitionAwareAsync.testExceptionInRetryPolicyPropagatesToCaller - PASSED{color}
* {color:#013220}ClientTestSuite: ReliabilityTestPartitionAware.testExceptionInRetryPolicyPropagatesToCaller - PASSED{color}
* {color:#013220}ClientTestSuite: ReliabilityTestAsync.testExceptionInRetryPolicyPropagatesToCaller - PASSED{color}
* {color:#013220}ClientTestSuite: ReliabilityTest.testExceptionInRetryPolicyPropagatesToCaller - PASSED{color}

{panel}
[TeamCity *--&gt; Run :: All* Results|https://ci2.ignite.apache.org/viewLog.html?buildId=6816577&amp;buildTypeId=IgniteTests24Java8_RunAll]

> JDBC connection leak with cache.invoke() over cache store with external JDBC storage
> ------------------------------------------------------------------------------------
>
>                 Key: IGNITE-15245
>                 URL: https://issues.apache.org/jira/browse/IGNITE-15245
>             Project: Ignite
>          Issue Type: Bug
>          Components: cache
>    Affects Versions: 2.10
>            Reporter: Ilya Korol
>            Assignee: Pavel Pereslegin
>            Priority: Major
>          Time Spent: 10m
>  Remaining Estimate: 0h
>
> Given following snippet:
> {code:java}
> try (Transaction tx = ignite.transactions().txStart(TransactionConcurrency.PESSIMISTIC, TransactionIsolation.REPEATABLE_READ)) {
>     cache.invoke(pojo.getId(), entryProcessor, pojo);
>     tx.commit();
> }
> {code}
> If we run this over the cache that uses external storage (e.g. mysql), we may get exceptions like:
> {code:java}
> org.apache.ignite.IgniteCheckedException: Failed to load object ...
>  at org.apache.ignite.internal.processors.cache.store.GridCacheStoreManagerAdapter.loadFromStore(GridCacheStoreManagerAdapter.java:334)
>  at org.apache.ignite.internal.processors.cache.store.GridCacheStoreManagerAdapter.load(GridCacheStoreManagerAdapter.java:292)
>  at org.apache.ignite.internal.processors.cache.store.GridCacheStoreManagerAdapter.loadAllFromStore(GridCacheStoreManagerAdapter.java:433)
>  at org.apache.ignite.internal.processors.cache.store.GridCacheStoreManagerAdapter.loadAll(GridCacheStoreManagerAdapter.java:399)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.loadMissingFromStore(GridDhtLockFuture.java:1111)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.onComplete(GridDhtLockFuture.java:790)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.onDone(GridDhtLockFuture.java:758)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.onDone(GridDhtLockFuture.java:91)
>  at org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:475)
>  at org.apache.ignite.internal.util.future.GridCompoundFuture.checkComplete(GridCompoundFuture.java:284)
>  at org.apache.ignite.internal.util.future.GridCompoundFuture.markInitialized(GridCompoundFuture.java:273)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.map(GridDhtLockFuture.java:1052)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.onOwnerChanged(GridDhtLockFuture.java:709)
>  at org.apache.ignite.internal.processors.cache.GridCacheMvccManager.notifyOwnerChanged(GridCacheMvccManager.java:226)
>  at org.apache.ignite.internal.processors.cache.GridCacheMvccManager.access$200(GridCacheMvccManager.java:81)
>  at org.apache.ignite.internal.processors.cache.GridCacheMvccManager$3.onOwnerChanged(GridCacheMvccManager.java:163)
>  at org.apache.ignite.internal.processors.cache.GridCacheMapEntry.checkOwnerChanged(GridCacheMapEntry.java:5043)
>  at org.apache.ignite.internal.processors.cache.GridCacheMapEntry.checkOwnerChanged(GridCacheMapEntry.java:4995)
>  at org.apache.ignite.internal.processors.cache.distributed.GridDistributedCacheEntry.readyLock(GridDistributedCacheEntry.java:515)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.readyLocks(GridDhtLockFuture.java:617)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtLockFuture.map(GridDhtLockFuture.java:825)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTransactionalCacheAdapter.lockAllAsyncInternal(GridDhtTransactionalCacheAdapter.java:1027)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTxLocalAdapter.obtainLockAsync(GridDhtTxLocalAdapter.java:720)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTxLocalAdapter.lockAllAsync(GridDhtTxLocalAdapter.java:665)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTransactionalCacheAdapter.lockAllAsync(GridDhtTransactionalCacheAdapter.java:1238)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTransactionalCacheAdapter.processNearLockRequest0(GridDhtTransactionalCacheAdapter.java:823)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTransactionalCacheAdapter.processNearLockRequest(GridDhtTransactionalCacheAdapter.java:801)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTransactionalCacheAdapter.access$000(GridDhtTransactionalCacheAdapter.java:113)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTransactionalCacheAdapter$3.apply(GridDhtTransactionalCacheAdapter.java:159)
>  at org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtTransactionalCacheAdapter$3.apply(GridDhtTransactionalCacheAdapter.java:157)
>  at org.apache.ignite.internal.processors.cache.GridCacheIoManager.processMessage(GridCacheIoManager.java:1142)
>  at org.apache.ignite.internal.processors.cache.GridCacheIoManager.onMessage0(GridCacheIoManager.java:591)
>  at org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:392)
>  at org.apache.ignite.internal.processors.cache.GridCacheIoManager.handleMessage(GridCacheIoManager.java:318)
>  at org.apache.ignite.internal.processors.cache.GridCacheIoManager.access$100(GridCacheIoManager.java:109)
>  at org.apache.ignite.internal.processors.cache.GridCacheIoManager$1.onMessage(GridCacheIoManager.java:308)
>  at org.apache.ignite.internal.managers.communication.GridIoManager.invokeListener(GridIoManager.java:1719)
>  at org.apache.ignite.internal.managers.communication.GridIoManager.processRegularMessage0(GridIoManager.java:1326)
>  at org.apache.ignite.internal.managers.communication.GridIoManager.access$4600(GridIoManager.java:157)
>  at org.apache.ignite.internal.managers.communication.GridIoManager$8.execute(GridIoManager.java:1211)
>  at org.apache.ignite.internal.managers.communication.TraceRunnable.run(TraceRunnable.java:54)
>  at org.apache.ignite.internal.util.StripedExecutor$Stripe.body(StripedExecutor.java:564)
>  at org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:119)
>  at java.lang.Thread.run(Thread.java:748)
> Caused by: javax.cache.integration.CacheLoaderException: Failed to load object ...
>  at org.apache.ignite.cache.store.jdbc.CacheAbstractJdbcStore.load(CacheAbstractJdbcStore.java:853)
>  at org.apache.ignite.internal.processors.cache.store.GridCacheWriteBehindStore.load(GridCacheWriteBehindStore.java:530)
>  at org.apache.ignite.internal.processors.cache.CacheStoreBalancingWrapper.load(CacheStoreBalancingWrapper.java:97)
>  at org.apache.ignite.internal.processors.cache.store.GridCacheStoreManagerAdapter.loadFromStore(GridCacheStoreManagerAdapter.java:326)
>  ... 43 more
> Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30008ms.
>  at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:695)
>  at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:197)
>  at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162)
>  at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128)
>  at org.apache.ignite.cache.store.jdbc.CacheAbstractJdbcStore.openConnection(CacheAbstractJdbcStore.java:324)
>  at org.apache.ignite.cache.store.jdbc.CacheAbstractJdbcStore.connection(CacheAbstractJdbcStore.java
> {code}
> This exception was caught when Hikari data source is used for pooling, but this case is also true if we use plain Mysql data source implementation.
> This happens because when transaction is commited Ignite opens JDBC connection to underlying storage but doesn't close it when there is a transaction. Check the code of GridCacheWriteBehindStore.closeConnection(connection):
> {code:java}
> protected void closeConnection(@Nullable Connection conn) {
>     CacheStoreSession ses = session();
>     // Close connection right away if there is no transaction.
>     if (ses.transaction() == null)
>         U.closeQuiet(conn);
> }
> {code}
> I guess that because connection release should be done somewhere else.  GridCacheWriteBehindStore.sessionEnd() is quite obvious place for this purpose, but its 'noop' somewhy. I suspect that it is because sessionEnd() was declared as deprecated, but logic for closing cache session was lost during refactoring. It looks like we can fix this issue If we add a call to underlying cache store:
> {code:java}
> @Override public void sessionEnd(boolean commit) {
>     --- // No-op
>     +++ store.sessionEnd(commit);
> }
> {code}
> I've created a test to reproduce this issue, and looks like proposed fix do the job, but I guess that this solution may be insufficient because I do not have enough knowledge about  involved components so I may miss something and also because sessionEnd() now considered as deprecated.
> [TEST/REPRODUCER|https://github.com/solveme/ignite/blob/ignite-15245/modules/core/src/test/java/org/apache/ignite/internal/processors/cache/store/LeakedConnectionTest.java]
>   



--
This message was sent by Atlassian Jira
(v8.20.10#820010)