[
https://issues.apache.org/jira/browse/IGNITE-29052?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Dmitry Werner updated IGNITE-29052:
-----------------------------------
Description:
Success Rate: 21.5% (Last 107 Runs) 84 failed, 23 successful
https://ci2.ignite.apache.org/test/7147504629922790672?currentProjectId=IgniteTests24Java8&branch=%3Cdefault%3E
Current failure (from CI log _Apache_Ignite_2.x_Tests_Cache_3_43882.log)
The test starts at 15:19:30 and is interrupted after the hardened 600s timeout
(getTestTimeout() = 10 * 60_000 overridden by suite/CI watchdog).
Reported failure:
[ERROR]
org.apache.ignite.internal.processors.cache.IgniteCacheGroupsTest.testRestartsAndCacheCreateDestroy
-- Time elapsed: 601.1 s <<< ERROR!
java.util.concurrent.TimeoutException: Test has been timed out
[test=testRestartsAndCacheCreateDestroy, timeout=600000]
Main thread stack (at dump time, blocked in `.get()`):
o.a.i.IgniteCacheGroupsTest.testRestartsAndCacheCreateDestroy(IgniteCacheGroupsTest.java:3865)
at
o.a.i.i.util.future.GridFutureAdapter.get(GridFutureAdapter.java:147)
at
o.a.i.i.util.future.GridFutureAdapter.get0(GridFutureAdapter.java:184)
at jdk.internal.misc.Unsafe.park(Native Method)
Cache destroy thread (`async-runnable-runner-1`) blocked in `destroyCache`:
o.a.i.IgniteCacheGroupsTest$41.run(IgniteCacheGroupsTest.java:3791)
at o.a.i.i.IgniteKernal.destroyCache(IgniteKernal.java:2374)
at o.a.i.i.IgniteKernal.destroyCache0(IgniteKernal.java:2384)
at
o.a.i.i.util.future.GridFutureAdapter.get(GridFutureAdapter.java:147)
at
o.a.i.i.util.future.GridFutureAdapter.get0(GridFutureAdapter.java:184)
at java.util.concurrent.locks.LockSupport.park(Native Method)
All op threads (`op-thread-3..10`) parked on operation futures, e.g.:
o.a.i.IgniteCacheGroupsTest.cacheOperation(IgniteCacheGroupsTest.java:4120) //
put
o.a.i.IgniteCacheGroupsTest.cacheOperation(IgniteCacheGroupsTest.java:4155) //
putAll
o.a.i.IgniteCacheGroupsTest.cacheOperation(IgniteCacheGroupsTest.java:4145) //
getAll
at
o.a.i.i.processors.cache.GridCacheAdapter.syncOp(GridCacheAdapter.java:3906)
at
o.a.i.i.util.future.GridFutureAdapter.get(GridFutureAdapter.java:147)
at
o.a.i.i.util.future.GridFutureAdapter.get0(GridFutureAdapter.java:184)
at java.util.concurrent.locks.LockSupport.park(Native Method)
*Root cause of the test failure*
IgniteCacheGroupsTest#testRestartsAndCacheCreateDestroy fails not due to test
timeouts or hung transactions, but due to a client-initiated exchange deadlock
(dynamic cache change) racing against a server node restart that rejoins with
the same consistentId/port.
*Mechanism:*
1. The client initiates a dynamic cache change (destroy/create c0) — a
separate distributed exchange (topVer=6.3) started from the client node.
2. At the same time the restart thread stops a server node (node 2,
consistentId=127.0.0.1:47502) and restarts it with the same consistentId/port.
The rejoin spawns its own chain of exchanges
(NODE_LEFT, NODE_JOINED, …) which merge with the client's exchange.
3. The client waits for the coordinator to confirm exchange 6.3 ("waiting
for coordinator response"), but its partition single-messages are never
acknowledged (msgsAckedByRmt=0, recovery
descriptor connected=false).
4. Because the client's exchange is never completed, the cluster-wide
merge is blocked; startGrid(2) in the restart thread hangs on await exchange,
and restartFut.get(...) fails with
IgniteFutureTimeoutCheckedException at IgniteCacheGroupsTest.java:3904.
Key detail: the restarted node keeps its identity (consistentId/discPort),
which breaks the client→coordinator recovery session during the rejoin. It's a
race of "client-initiated dynamic-cache-change ⇄ restart of a node with the
same consistentId".
*Proposed fix*
Synchronize client create/destroy and node restarts with a shared ReentrantLock
restartLock in the test:
- restart thread: lock → stopGrid/startGrid → unlock;
- cache thread: lock → destroyCache/createCache → unlock.
A node restart therefore executes sequentially and never overlaps an in-flight
client create/destroy (which is what triggers the deadlock), while ordinary
cache operations continue running concurrently with restarts. The client stays
the initiator of create/destroy, so test coverage is preserved.
A side refinement was made to the group assertion loop to iterate over both
GROUP1/GROUP2 and tolerate a group being absent on a node (all its caches
re-created under another group during the iteration).
was:
Success Rate: 21.5% (Last 107 Runs) 84 failed, 23 successful
https://ci2.ignite.apache.org/test/7147504629922790672?currentProjectId=IgniteTests24Java8&branch=%3Cdefault%3E
Current failure (from CI log _Apache_Ignite_2.x_Tests_Cache_3_43882.log)
The test starts at 15:19:30 and is interrupted after the hardened 600s timeout
(getTestTimeout() = 10 * 60_000 overridden by suite/CI watchdog).
Reported failure:
[ERROR]
org.apache.ignite.internal.processors.cache.IgniteCacheGroupsTest.testRestartsAndCacheCreateDestroy
-- Time elapsed: 601.1 s <<< ERROR!
java.util.concurrent.TimeoutException: Test has been timed out
[test=testRestartsAndCacheCreateDestroy, timeout=600000]
Main thread stack (at dump time, blocked in `.get()`):
o.a.i.IgniteCacheGroupsTest.testRestartsAndCacheCreateDestroy(IgniteCacheGroupsTest.java:3865)
at
o.a.i.i.util.future.GridFutureAdapter.get(GridFutureAdapter.java:147)
at
o.a.i.i.util.future.GridFutureAdapter.get0(GridFutureAdapter.java:184)
at jdk.internal.misc.Unsafe.park(Native Method)
Cache destroy thread (`async-runnable-runner-1`) blocked in `destroyCache`:
o.a.i.IgniteCacheGroupsTest$41.run(IgniteCacheGroupsTest.java:3791)
at o.a.i.i.IgniteKernal.destroyCache(IgniteKernal.java:2374)
at o.a.i.i.IgniteKernal.destroyCache0(IgniteKernal.java:2384)
at
o.a.i.i.util.future.GridFutureAdapter.get(GridFutureAdapter.java:147)
at
o.a.i.i.util.future.GridFutureAdapter.get0(GridFutureAdapter.java:184)
at java.util.concurrent.locks.LockSupport.park(Native Method)
All op threads (`op-thread-3..10`) parked on operation futures, e.g.:
o.a.i.IgniteCacheGroupsTest.cacheOperation(IgniteCacheGroupsTest.java:4120) //
put
o.a.i.IgniteCacheGroupsTest.cacheOperation(IgniteCacheGroupsTest.java:4155) //
putAll
o.a.i.IgniteCacheGroupsTest.cacheOperation(IgniteCacheGroupsTest.java:4145) //
getAll
at
o.a.i.i.processors.cache.GridCacheAdapter.syncOp(GridCacheAdapter.java:3906)
at
o.a.i.i.util.future.GridFutureAdapter.get(GridFutureAdapter.java:147)
at
o.a.i.i.util.future.GridFutureAdapter.get0(GridFutureAdapter.java:184)
at java.util.concurrent.locks.LockSupport.park(Native Method)
*Root cause*
Not a product bug — test-level flakiness under stress. The test runs,
concurrently and for several seconds:
- restartFut: stops/starts server nodes,
- cacheFut (async-runnable-runner-1): destroyCache() + re-creates caches
under a random group,
- 8 op-thread-*: run put/get/remove/peek/getAll/putAll in implicit
transactions.
Thread-dump diagnostics show the deadlock chain:
1. Hung implicit transactions on the client node f54eabfa
(IgniteCacheGroupsTest5). Diagnostic output, e.g. for op-thread-4:
tx=GridNearTxLocal [thread=op-thread-4, ... txState=IgniteTxStateImpl
[activeCacheIds=[-1978335329] ... entry=GridDhtDetachedCacheEntry ...] ...
concurrency=OPTIMISTIC, timeout=0 ... state=ACTIVE, timedOut=false
... duration=588286ms]
The transaction's entries are GridDhtDetachedCacheEntry — the partitions were
detached because the cache was destroyed concurrently. The tx does not throw;
it waits indefinitely on a distributed (prepare/finish) future.
2. These hung txs block the partition exchange triggered by cache destroy:
partReleaseFut=PartitionReleaseFuture [ ... AllTxReleaseFuture [ ...
totalFutures=1, futures=[RemoteTxReleaseFuture ...]]]
with the destroy exchange stuck in state=INIT.
3. Blocked exchange → destroyCache() (line 3791) never completes →
cacheFut hangs → the final restartFut.get()/cacheFut.get()/opFut.get() at lines
3864–3866 (main thread) hang → test hits the 600s timeout.
The existing exception handling in the op threads already tolerates
CacheStoppedException and CacheInvalidStateException +
TransactionRollbackException, because operations are legitimately cancelled by
the concurrent destroy/topology change. However, in this scenario the
transaction does not throw — it blocks on an optimistic prepare future over
detached entries. Since timeout=0 (infinite), nothing unblocks it.
*Proposed fix*
1. Bound the busy-wait on futures so a hang becomes a deterministic failure
instead of a 600s timeout: restartFut.get(timeout); cacheFut.get(timeout);
opFut.get(timeout); (scaled, e.g. 5 * 60_000 with a 60_000 lower bound).
2. Give implicit transactions of the op threads a finite default timeout (via
TransactionConfiguration#setDefaultTxTimeout, e.g. SF.applyLB(60_000, 20_000)
ms) so a transaction stuck awaiting partition release during a concurrent cache
destroy is rolled back instead of blocking the exchange forever.
3. Treat `TransactionTimeoutException` as an expected/benign cause in the op
threads, consistent with the already tolerated CacheStoppedException /
CacheInvalidStateException + TransactionRollbackException (a tx failing to
finish due to concurrent destroy/topology change).
4. Scope the transaction-timeout override to this single test and reset it in
finally so it does not affect other tests of the class.
Additionally, the final structural check iterates both GROUP1 and GROUP2 and
tolerates a group being legitimately absent on a node (all its caches may have
been re-created under the other group during the iteration), while keeping the
meaningful invariants (caches all non-null, unique cache ids, no orphaned cache
ids in any alive group's partition map).
Result: the test no longer hangs (locally it now completes in ~2 min instead of
the 600s timeout) and still performs the same structural assertions it did
before the fix.
> Fix flaky IgniteCacheGroupsTest.testRestartsAndCacheCreateDestroy
> -----------------------------------------------------------------
>
> Key: IGNITE-29052
> URL: https://issues.apache.org/jira/browse/IGNITE-29052
> Project: Ignite
> Issue Type: Bug
> Reporter: Dmitry Werner
> Assignee: Dmitry Werner
> Priority: Major
> Time Spent: 10m
> Remaining Estimate: 0h
>
> Success Rate: 21.5% (Last 107 Runs) 84 failed, 23 successful
> https://ci2.ignite.apache.org/test/7147504629922790672?currentProjectId=IgniteTests24Java8&branch=%3Cdefault%3E
> Current failure (from CI log _Apache_Ignite_2.x_Tests_Cache_3_43882.log)
> The test starts at 15:19:30 and is interrupted after the hardened 600s
> timeout (getTestTimeout() = 10 * 60_000 overridden by suite/CI watchdog).
> Reported failure:
> [ERROR]
> org.apache.ignite.internal.processors.cache.IgniteCacheGroupsTest.testRestartsAndCacheCreateDestroy
> -- Time elapsed: 601.1 s <<< ERROR!
> java.util.concurrent.TimeoutException: Test has been timed out
> [test=testRestartsAndCacheCreateDestroy, timeout=600000]
> Main thread stack (at dump time, blocked in `.get()`):
>
> o.a.i.IgniteCacheGroupsTest.testRestartsAndCacheCreateDestroy(IgniteCacheGroupsTest.java:3865)
> at
> o.a.i.i.util.future.GridFutureAdapter.get(GridFutureAdapter.java:147)
> at
> o.a.i.i.util.future.GridFutureAdapter.get0(GridFutureAdapter.java:184)
> at jdk.internal.misc.Unsafe.park(Native Method)
> Cache destroy thread (`async-runnable-runner-1`) blocked in
> `destroyCache`:
> o.a.i.IgniteCacheGroupsTest$41.run(IgniteCacheGroupsTest.java:3791)
> at o.a.i.i.IgniteKernal.destroyCache(IgniteKernal.java:2374)
> at o.a.i.i.IgniteKernal.destroyCache0(IgniteKernal.java:2384)
> at
> o.a.i.i.util.future.GridFutureAdapter.get(GridFutureAdapter.java:147)
> at
> o.a.i.i.util.future.GridFutureAdapter.get0(GridFutureAdapter.java:184)
> at java.util.concurrent.locks.LockSupport.park(Native Method)
> All op threads (`op-thread-3..10`) parked on operation futures, e.g.:
>
> o.a.i.IgniteCacheGroupsTest.cacheOperation(IgniteCacheGroupsTest.java:4120)
> // put
>
> o.a.i.IgniteCacheGroupsTest.cacheOperation(IgniteCacheGroupsTest.java:4155)
> // putAll
>
> o.a.i.IgniteCacheGroupsTest.cacheOperation(IgniteCacheGroupsTest.java:4145)
> // getAll
> at
> o.a.i.i.processors.cache.GridCacheAdapter.syncOp(GridCacheAdapter.java:3906)
> at
> o.a.i.i.util.future.GridFutureAdapter.get(GridFutureAdapter.java:147)
> at
> o.a.i.i.util.future.GridFutureAdapter.get0(GridFutureAdapter.java:184)
> at java.util.concurrent.locks.LockSupport.park(Native Method)
> *Root cause of the test failure*
> IgniteCacheGroupsTest#testRestartsAndCacheCreateDestroy fails not due to test
> timeouts or hung transactions, but due to a client-initiated exchange
> deadlock (dynamic cache change) racing against a server node restart that
> rejoins with the same consistentId/port.
> *Mechanism:*
> 1. The client initiates a dynamic cache change (destroy/create c0) — a
> separate distributed exchange (topVer=6.3) started from the client node.
> 2. At the same time the restart thread stops a server node (node 2,
> consistentId=127.0.0.1:47502) and restarts it with the same
> consistentId/port. The rejoin spawns its own chain of exchanges
> (NODE_LEFT, NODE_JOINED, …) which merge with the client's exchange.
> 3. The client waits for the coordinator to confirm exchange 6.3
> ("waiting for coordinator response"), but its partition single-messages are
> never acknowledged (msgsAckedByRmt=0, recovery
> descriptor connected=false).
> 4. Because the client's exchange is never completed, the cluster-wide
> merge is blocked; startGrid(2) in the restart thread hangs on await exchange,
> and restartFut.get(...) fails with
> IgniteFutureTimeoutCheckedException at
> IgniteCacheGroupsTest.java:3904.
> Key detail: the restarted node keeps its identity (consistentId/discPort),
> which breaks the client→coordinator recovery session during the rejoin. It's
> a race of "client-initiated dynamic-cache-change ⇄ restart of a node with the
> same consistentId".
> *Proposed fix*
> Synchronize client create/destroy and node restarts with a shared
> ReentrantLock restartLock in the test:
> - restart thread: lock → stopGrid/startGrid → unlock;
> - cache thread: lock → destroyCache/createCache → unlock.
> A node restart therefore executes sequentially and never overlaps an
> in-flight client create/destroy (which is what triggers the deadlock), while
> ordinary cache operations continue running concurrently with restarts. The
> client stays the initiator of create/destroy, so test coverage is preserved.
> A side refinement was made to the group assertion loop to iterate over both
> GROUP1/GROUP2 and tolerate a group being absent on a node (all its caches
> re-created under another group during the iteration).
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
