[
https://issues.apache.org/jira/browse/FLINK-22464?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17350895#comment-17350895
]
Robert Metzger commented on FLINK-22464:
----------------------------------------
The issue is reproducible 100% of the time locally with current master.
The job is in a restart loop due to this error:
{code}
22:48:45,251 [ Checkpoint Timer] INFO
org.apache.flink.runtime.checkpoint.CheckpointCoordinator [] - Triggering
checkpoint 2 (type=CHECKPOINT) @ 1621896525250 for job
566fd0f105339e3cecdfb994df6e1cf9.
22:48:45,251 [flink-akka.actor.default-dispatcher-2] INFO
org.apache.flink.runtime.operators.coordination.OperatorCoordinatorHolder [] -
Coordinator checkpoint 2 for coordinator cbc357ccb763df2852fee8c4fc7d55f2 is
awaiting 1 pending events
22:48:45,704 [ Checkpoint Timer] WARN
org.apache.flink.runtime.checkpoint.CheckpointCoordinator [] - Failed to
trigger checkpoint 2 for job 566fd0f105339e3cecdfb994df6e1cf9. (1 consecutive
failed attempts so far)
org.apache.flink.util.FlinkException: Failing OperatorCoordinator checkpoint
because some OperatorEvents before this checkpoint barrier were not received by
the target tasks.
at
org.apache.flink.runtime.operators.coordination.OperatorCoordinatorHolder.lambda$completeCheckpointOnceEventsAreDone$4(OperatorCoordinatorHolder.java:344)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:?]
at
java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774)
~[?:1.8.0_282]
at
java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750)
~[?:1.8.0_282]
at
java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
~[?:1.8.0_282]
at
java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
~[?:1.8.0_282]
at
org.apache.flink.runtime.concurrent.FutureUtils$WaitingConjunctFuture.handleCompletedFuture(FutureUtils.java:905)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:1.14-SNAPSHOT]
at
java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774)
~[?:1.8.0_282]
at
java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750)
~[?:1.8.0_282]
at
java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
~[?:1.8.0_282]
at
java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
~[?:1.8.0_282]
at
org.apache.flink.runtime.concurrent.FutureUtils.lambda$forwardTo$23(FutureUtils.java:1356)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:1.14-SNAPSHOT]
at
java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774)
~[?:1.8.0_282]
at
java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750)
~[?:1.8.0_282]
at
java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
~[?:1.8.0_282]
at
java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
~[?:1.8.0_282]
at
org.apache.flink.runtime.concurrent.FutureUtils$Timeout.run(FutureUtils.java:1255)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:1.14-SNAPSHOT]
at
org.apache.flink.runtime.concurrent.DirectExecutorService.execute(DirectExecutorService.java:217)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:1.14-SNAPSHOT]
at
org.apache.flink.runtime.concurrent.FutureUtils.lambda$orTimeout$15(FutureUtils.java:582)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:1.14-SNAPSHOT]
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[?:1.8.0_282]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[?:1.8.0_282]
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
[?:1.8.0_282]
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
[?:1.8.0_282]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[?:1.8.0_282]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[?:1.8.0_282]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_282]
22:48:45,706 [flink-akka.actor.default-dispatcher-3] INFO
org.apache.flink.runtime.executiongraph.ExecutionGraph [] - Source:
numbers -> Map -> Sink: Data stream collect sink (1/1)
(fe486f6c9a46e270c73a9832d6e2aab5) switched from RUNNING to FAILED on
1072e91c-cd0e-4c5a-99fe-46fa9f65f579 @ localhost (dataPort=-1).
org.apache.flink.util.FlinkException: An OperatorEvent from an
OperatorCoordinator to a task was lost. Triggering task failover to ensure
consistency. Event: 'AddSplitEvents[[[B@57ec5d1f]]', targetTask: Source:
numbers -> Map -> Sink: Data stream collect sink (1/1) - execution #0
at
org.apache.flink.runtime.operators.coordination.SubtaskGatewayImpl.lambda$sendEvent$0(SubtaskGatewayImpl.java:81)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:?]
at
java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:836)
~[?:1.8.0_282]
at
java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:811)
~[?:1.8.0_282]
at
java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:456)
~[?:1.8.0_282]
at
org.apache.flink.runtime.rpc.akka.AkkaRpcActor.handleRunAsync(AkkaRpcActor.java:440)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:1.14-SNAPSHOT]
at
org.apache.flink.runtime.rpc.akka.AkkaRpcActor.handleRpcMessage(AkkaRpcActor.java:208)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:1.14-SNAPSHOT]
at
org.apache.flink.runtime.rpc.akka.FencedAkkaRpcActor.handleRpcMessage(FencedAkkaRpcActor.java:77)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:1.14-SNAPSHOT]
at
org.apache.flink.runtime.rpc.akka.AkkaRpcActor.handleMessage(AkkaRpcActor.java:158)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:1.14-SNAPSHOT]
at akka.japi.pf.UnitCaseStatement.apply(CaseStatements.scala:26)
[akka-actor_2.11-2.5.21.jar:2.5.21]
at akka.japi.pf.UnitCaseStatement.apply(CaseStatements.scala:21)
[akka-actor_2.11-2.5.21.jar:2.5.21]
at scala.PartialFunction$class.applyOrElse(PartialFunction.scala:123)
[scala-library-2.11.12.jar:?]
at akka.japi.pf.UnitCaseStatement.applyOrElse(CaseStatements.scala:21)
[akka-actor_2.11-2.5.21.jar:2.5.21]
at scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:170)
[scala-library-2.11.12.jar:?]
at scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:171)
[scala-library-2.11.12.jar:?]
at scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:171)
[scala-library-2.11.12.jar:?]
at akka.actor.Actor$class.aroundReceive(Actor.scala:517)
[akka-actor_2.11-2.5.21.jar:2.5.21]
at akka.actor.AbstractActor.aroundReceive(AbstractActor.scala:225)
[akka-actor_2.11-2.5.21.jar:2.5.21]
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:592)
[akka-actor_2.11-2.5.21.jar:2.5.21]
at akka.actor.ActorCell.invoke(ActorCell.scala:561)
[akka-actor_2.11-2.5.21.jar:2.5.21]
at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:258)
[akka-actor_2.11-2.5.21.jar:2.5.21]
at akka.dispatch.Mailbox.run(Mailbox.scala:225)
[akka-actor_2.11-2.5.21.jar:2.5.21]
at akka.dispatch.Mailbox.exec(Mailbox.scala:235)
[akka-actor_2.11-2.5.21.jar:2.5.21]
at akka.dispatch.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
[akka-actor_2.11-2.5.21.jar:2.5.21]
at
akka.dispatch.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
[akka-actor_2.11-2.5.21.jar:2.5.21]
at
akka.dispatch.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
[akka-actor_2.11-2.5.21.jar:2.5.21]
at
akka.dispatch.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
[akka-actor_2.11-2.5.21.jar:2.5.21]
Caused by: java.util.concurrent.TimeoutException
at
org.apache.flink.runtime.concurrent.FutureUtils$Timeout.run(FutureUtils.java:1255)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:1.14-SNAPSHOT]
at
org.apache.flink.runtime.concurrent.DirectExecutorService.execute(DirectExecutorService.java:217)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:1.14-SNAPSHOT]
at
org.apache.flink.runtime.concurrent.FutureUtils.lambda$orTimeout$15(FutureUtils.java:582)
~[flink-runtime_2.11-1.14-SNAPSHOT.jar:1.14-SNAPSHOT]
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
~[?:1.8.0_282]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
~[?:1.8.0_282]
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
~[?:1.8.0_282]
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
~[?:1.8.0_282]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
~[?:1.8.0_282]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
~[?:1.8.0_282]
at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_282]
22:48:45,707 [flink-akka.actor.default-dispatcher-3] INFO
org.apache.flink.runtime.executiongraph.ExecutionGraph [] - Discarding
the results produced by task execution fe486f6c9a46e270c73a9832d6e2aab5.
22:48:45,707 [flink-akka.actor.default-dispatcher-2] INFO
org.apache.flink.runtime.taskmanager.Task [] - Attempting to
cancel task Source: numbers -> Map -> Sink: Data stream collect sink (1/1)#0
(fe486f6c9a46e270c73a9832d6e2aab5).
22:48:45,707 [flink-akka.actor.default-dispatcher-2] INFO
org.apache.flink.runtime.taskmanager.Task [] - Source:
numbers -> Map -> Sink: Data stream collect sink (1/1)#0
(fe486f6c9a46e270c73a9832d6e2aab5) switched from RUNNING to CANCELING.
22:48:45,707 [flink-akka.actor.default-dispatcher-2] INFO
org.apache.flink.runtime.taskmanager.Task [] - Triggering
cancellation of task code Source: numbers -> Map -> Sink: Data stream collect
sink (1/1)#0 (fe486f6c9a46e270c73a9832d6e2aab5).
22:48:45,707 [flink-akka.actor.default-dispatcher-3] INFO
org.apache.flink.runtime.scheduler.adaptive.AdaptiveScheduler [] - Restarting
job.
{code}
> OperatorEventSendingCheckpointITCase.testOperatorEventLostWithReaderFailure
> hangs with `AdaptiveScheduler`
> ----------------------------------------------------------------------------------------------------------
>
> Key: FLINK-22464
> URL: https://issues.apache.org/jira/browse/FLINK-22464
> Project: Flink
> Issue Type: Bug
> Components: Runtime / Coordination, Tests
> Affects Versions: 1.14.0
> Reporter: Guowei Ma
> Assignee: Robert Metzger
> Priority: Critical
> Labels: stale-critical, test-stability
>
> https://dev.azure.com/apache-flink/apache-flink/_build/results?buildId=17178&view=logs&j=8fd9202e-fd17-5b26-353c-ac1ff76c8f28&t=a0a633b8-47ef-5c5a-2806-3c13b9e48228&l=8171
> {code:java}
> 2021-05-10T02:56:09.3603584Z "main" #1 prio=5 os_prio=0
> tid=0x00007f677000b800 nid=0x40e4 waiting on condition [0x00007f6776cc8000]
> 2021-05-10T02:56:09.3604176Z java.lang.Thread.State: TIMED_WAITING
> (sleeping)
> 2021-05-10T02:56:09.3604468Z at java.lang.Thread.sleep(Native Method)
> 2021-05-10T02:56:09.3604925Z at
> org.apache.flink.streaming.api.operators.collect.CollectResultFetcher.sleepBeforeRetry(CollectResultFetcher.java:237)
> 2021-05-10T02:56:09.3605582Z at
> org.apache.flink.streaming.api.operators.collect.CollectResultFetcher.next(CollectResultFetcher.java:113)
> 2021-05-10T02:56:09.3606205Z at
> org.apache.flink.streaming.api.operators.collect.CollectResultIterator.nextResultFromFetcher(CollectResultIterator.java:106)
> 2021-05-10T02:56:09.3606924Z at
> org.apache.flink.streaming.api.operators.collect.CollectResultIterator.hasNext(CollectResultIterator.java:80)
> 2021-05-10T02:56:09.3607469Z at
> org.apache.flink.streaming.api.datastream.DataStream.executeAndCollect(DataStream.java:1320)
> 2021-05-10T02:56:09.3607996Z at
> org.apache.flink.streaming.api.datastream.DataStream.executeAndCollect(DataStream.java:1303)
> 2021-05-10T02:56:09.3608616Z at
> org.apache.flink.runtime.operators.coordination.OperatorEventSendingCheckpointITCase.runTest(OperatorEventSendingCheckpointITCase.java:223)
> 2021-05-10T02:56:09.3609378Z at
> org.apache.flink.runtime.operators.coordination.OperatorEventSendingCheckpointITCase.testOperatorEventLostWithReaderFailure(OperatorEventSendingCheckpointITCase.java:135)
> 2021-05-10T02:56:09.3609968Z at
> sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 2021-05-10T02:56:09.3610386Z at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 2021-05-10T02:56:09.3610858Z at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 2021-05-10T02:56:09.3611295Z at
> java.lang.reflect.Method.invoke(Method.java:498)
> 2021-05-10T02:56:09.3611703Z at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> 2021-05-10T02:56:09.3612207Z at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> 2021-05-10T02:56:09.3612774Z at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> 2021-05-10T02:56:09.3613470Z at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> 2021-05-10T02:56:09.3613930Z at
> org.apache.flink.util.TestNameProvider$1.evaluate(TestNameProvider.java:45)
> 2021-05-10T02:56:09.3614401Z at
> org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
> 2021-05-10T02:56:09.3614770Z at
> org.junit.rules.RunRules.evaluate(RunRules.java:20)
> 2021-05-10T02:56:09.3615138Z at
> org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
> 2021-05-10T02:56:09.3615584Z at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
> 2021-05-10T02:56:09.3616070Z at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
> 2021-05-10T02:56:09.3616487Z at
> org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> 2021-05-10T02:56:09.3616962Z at
> org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> 2021-05-10T02:56:09.3617361Z at
> org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> 2021-05-10T02:56:09.3617785Z at
> org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> 2021-05-10T02:56:09.3618209Z at
> org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> 2021-05-10T02:56:09.3618635Z at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
> 2021-05-10T02:56:09.3619101Z at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> 2021-05-10T02:56:09.3619507Z at
> org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> 2021-05-10T02:56:09.3619879Z at
> org.junit.runners.Suite.runChild(Suite.java:128)
> 2021-05-10T02:56:09.3620239Z at
> org.junit.runners.Suite.runChild(Suite.java:27)
> 2021-05-10T02:56:09.3620596Z at
> org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> 2021-05-10T02:56:09.3621009Z at
> org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> 2021-05-10T02:56:09.3621406Z at
> org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> 2021-05-10T02:56:09.3621906Z at
> org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> 2021-05-10T02:56:09.3622319Z at
> org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> 2021-05-10T02:56:09.3622843Z at
> org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> 2021-05-10T02:56:09.3623263Z at
> org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55)
> 2021-05-10T02:56:09.3623739Z at
> org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137)
> 2021-05-10T02:56:09.3624332Z at
> org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:107)
> 2021-05-10T02:56:09.3624854Z at
> org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:83)
> 2021-05-10T02:56:09.3625342Z at
> org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75)
> 2021-05-10T02:56:09.3625851Z at
> org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:158)
> 2021-05-10T02:56:09.3626385Z at
> org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
> 2021-05-10T02:56:09.3626978Z at
> org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
> 2021-05-10T02:56:09.3627473Z at
> org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
> 2021-05-10T02:56:09.3627912Z at
> org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
> {code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
