[
https://issues.apache.org/jira/browse/IGNITE-25206?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Denis Chudov updated IGNITE-25206:
----------------------------------
Description:
LeaseGrantedMessage handling sometimes fails with TimeoutExceptions:
{code:java}
[14:57:15]W:
[2025-04-21T10:57:15,004][ERROR][CompletableFutureDelayScheduler][FailureManager]
Critical system error detected. Will be handled accordingly to configured
handler [hnd=NoOpFailureHandler [super=AbstractFailureHandler
[ignoredFailureTypes=UnmodifiableSet [SYSTEM_WORKER_BLOCKED,
SYSTEM_CRITICAL_OPERATION_TIMEOUT]]], failureCtx=CRITICAL_ERROR]
[14:57:15]W: org.apache.ignite.internal.failure.StackTraceCapturingException:
Failed to process the lease granted message [msg=LeaseGrantedMessageImpl
[force=false, groupId=19_part_1, leaseExpirationTime=HybridTimestamp
[physical=2025-04-21 10:57:15:003 +0000, logical=0,
composite=114375592181956608], leaseStartTime=HybridTimestamp
[physical=2025-04-21 10:55:15:003 +0000, logical=2,
composite=114375584317636610]]].
[14:57:15]W: at
org.apache.ignite.internal.failure.FailureManager.process(FailureManager.java:161)
~[ignite-failure-handler-3.1.0-SNAPSHOT.jar:?]
[14:57:15]W: at
org.apache.ignite.internal.failure.FailureManager.process(FailureManager.java:138)
~[ignite-failure-handler-3.1.0-SNAPSHOT.jar:?]
[14:57:15]W: at
org.apache.ignite.internal.replicator.PlacementDriverMessageProcessor.lambda$processPlacementDriverMessage$0(PlacementDriverMessageProcessor.java:145)
~[ignite-replicator-3.1.0-SNAPSHOT.jar:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2162)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture$Timeout.run(CompletableFuture.java:2874)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
[14:57:15]W: at
java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[?:?]
[14:57:15]W: at java.base/java.lang.Thread.run(Thread.java:833) [?:?]
[14:57:15]W: Caused by: java.util.concurrent.CompletionException:
java.util.concurrent.TimeoutException
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:332)
~[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:347)
~[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1141)
~[?:?]
[14:57:15]W: ... 9 more
[14:57:15]W: Caused by: java.util.concurrent.TimeoutException
[14:57:15]W: ... 7 more{code}
It doesn't seem to ever fail any test to fail, so currently TimeoutException is
just suppressed if called in
PlacementDriverMessageProcessor#processPlacementDriverMessage() (see the TODO),
but it seems that an investigation is needed to either prove that this is safe
(in such a case, the TODO is to be replaced with a comment explaining why it's
safe), or to fix this if this is a bug.
was:
LeaseGrantedMessage handling sometimes fails with TimeoutExceptions:
[14:57:15]W:
[2025-04-21T10:57:15,004][ERROR][CompletableFutureDelayScheduler][FailureManager]
Critical system error detected. Will be handled accordingly to configured
handler [hnd=NoOpFailureHandler [super=AbstractFailureHandler
[ignoredFailureTypes=UnmodifiableSet [SYSTEM_WORKER_BLOCKED,
SYSTEM_CRITICAL_OPERATION_TIMEOUT]]], failureCtx=CRITICAL_ERROR]
[14:57:15]W: org.apache.ignite.internal.failure.StackTraceCapturingException:
Failed to process the lease granted message [msg=LeaseGrantedMessageImpl
[force=false, groupId=19_part_1, leaseExpirationTime=HybridTimestamp
[physical=2025-04-21 10:57:15:003 +0000, logical=0,
composite=114375592181956608], leaseStartTime=HybridTimestamp
[physical=2025-04-21 10:55:15:003 +0000, logical=2,
composite=114375584317636610]]].
[14:57:15]W: at
org.apache.ignite.internal.failure.FailureManager.process(FailureManager.java:161)
~[ignite-failure-handler-3.1.0-SNAPSHOT.jar:?]
[14:57:15]W: at
org.apache.ignite.internal.failure.FailureManager.process(FailureManager.java:138)
~[ignite-failure-handler-3.1.0-SNAPSHOT.jar:?]
[14:57:15]W: at
org.apache.ignite.internal.replicator.PlacementDriverMessageProcessor.lambda$processPlacementDriverMessage$0(PlacementDriverMessageProcessor.java:145)
~[ignite-replicator-3.1.0-SNAPSHOT.jar:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2162)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture$Timeout.run(CompletableFuture.java:2874)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
[14:57:15]W: at
java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[?:?]
[14:57:15]W: at java.base/java.lang.Thread.run(Thread.java:833) [?:?]
[14:57:15]W: Caused by: java.util.concurrent.CompletionException:
java.util.concurrent.TimeoutException
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:332)
~[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:347)
~[?:?]
[14:57:15]W: at
java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1141)
~[?:?]
[14:57:15]W: ... 9 more
[14:57:15]W: Caused by: java.util.concurrent.TimeoutException
[14:57:15]W: ... 7 more
It doesn't seem to ever fail any test to fail, so currently TimeoutException is
just suppressed if called in
PlacementDriverMessageProcessor#processPlacementDriverMessage() (see the TODO),
but it seems that an investigation is needed to either prove that this is safe
(in such a case, the TODO is to be replaced with a comment explaining why it's
safe), or to fix this if this is a bug.
> Lease granted message not handled due to timeout
> ------------------------------------------------
>
> Key: IGNITE-25206
> URL: https://issues.apache.org/jira/browse/IGNITE-25206
> Project: Ignite
> Issue Type: Bug
> Reporter: Roman Puchkovskiy
> Priority: Major
> Labels: ignite-3
> Attachments: _Integration_Tests_Module_Transactions_17300.log.zip
>
>
> LeaseGrantedMessage handling sometimes fails with TimeoutExceptions:
>
> {code:java}
> [14:57:15]W:
> [2025-04-21T10:57:15,004][ERROR][CompletableFutureDelayScheduler][FailureManager]
> Critical system error detected. Will be handled accordingly to configured
> handler [hnd=NoOpFailureHandler [super=AbstractFailureHandler
> [ignoredFailureTypes=UnmodifiableSet [SYSTEM_WORKER_BLOCKED,
> SYSTEM_CRITICAL_OPERATION_TIMEOUT]]], failureCtx=CRITICAL_ERROR]
> [14:57:15]W: org.apache.ignite.internal.failure.StackTraceCapturingException:
> Failed to process the lease granted message [msg=LeaseGrantedMessageImpl
> [force=false, groupId=19_part_1, leaseExpirationTime=HybridTimestamp
> [physical=2025-04-21 10:57:15:003 +0000, logical=0,
> composite=114375592181956608], leaseStartTime=HybridTimestamp
> [physical=2025-04-21 10:55:15:003 +0000, logical=2,
> composite=114375584317636610]]].
> [14:57:15]W: at
> org.apache.ignite.internal.failure.FailureManager.process(FailureManager.java:161)
> ~[ignite-failure-handler-3.1.0-SNAPSHOT.jar:?]
> [14:57:15]W: at
> org.apache.ignite.internal.failure.FailureManager.process(FailureManager.java:138)
> ~[ignite-failure-handler-3.1.0-SNAPSHOT.jar:?]
> [14:57:15]W: at
> org.apache.ignite.internal.replicator.PlacementDriverMessageProcessor.lambda$processPlacementDriverMessage$0(PlacementDriverMessageProcessor.java:145)
> ~[ignite-replicator-3.1.0-SNAPSHOT.jar:?]
> [14:57:15]W: at
> java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
> [?:?]
> [14:57:15]W: at
> java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)
> [?:?]
> [14:57:15]W: at
> java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
> [?:?]
> [14:57:15]W: at
> java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2162)
> [?:?]
> [14:57:15]W: at
> java.base/java.util.concurrent.CompletableFuture$Timeout.run(CompletableFuture.java:2874)
> [?:?]
> [14:57:15]W: at
> java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
> [?:?]
> [14:57:15]W: at
> java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
> [14:57:15]W: at
> java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
> [?:?]
> [14:57:15]W: at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
> [?:?]
> [14:57:15]W: at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
> [?:?]
> [14:57:15]W: at java.base/java.lang.Thread.run(Thread.java:833) [?:?]
> [14:57:15]W: Caused by: java.util.concurrent.CompletionException:
> java.util.concurrent.TimeoutException
> [14:57:15]W: at
> java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:332)
> ~[?:?]
> [14:57:15]W: at
> java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:347)
> ~[?:?]
> [14:57:15]W: at
> java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1141)
> ~[?:?]
> [14:57:15]W: ... 9 more
> [14:57:15]W: Caused by: java.util.concurrent.TimeoutException
> [14:57:15]W: ... 7 more{code}
>
> It doesn't seem to ever fail any test to fail, so currently TimeoutException
> is just suppressed if called in
> PlacementDriverMessageProcessor#processPlacementDriverMessage() (see the
> TODO), but it seems that an investigation is needed to either prove that this
> is safe (in such a case, the TODO is to be replaced with a comment explaining
> why it's safe), or to fix this if this is a bug.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
