Uploaded image for project: 'Flink'
  1. Flink
  2. FLINK-20065

UnalignedCheckpointCompatibilityITCase.test failed with AskTimeoutException

    XMLWordPrintableJSON

Details

    Description

      https://dev.azure.com/apache-flink/apache-flink/_build/results?buildId=9362&view=logs&j=5c8e7682-d68f-54d1-16a2-a09310218a49&t=45cc9205-bdb7-5b54-63cd-89fdc0983323

      2020-11-09T22:19:47.2714024Z [ERROR] test[type: SAVEPOINT, startAligned: true](org.apache.flink.test.checkpointing.UnalignedCheckpointCompatibilityITCase)  Time elapsed: 1.293 s  <<< ERROR!
2020-11-09T22:19:47.2715260Z java.util.concurrent.ExecutionException: java.util.concurrent.TimeoutException: Invocation of public default java.util.concurrent.CompletableFuture org.apache.flink.runtime.webmonitor.RestfulGateway.stopWithSavepoint(org.apache.flink.api.common.JobID,java.lang.String,boolean,org.apache.flink.api.common.time.Time) timed out.
2020-11-09T22:19:47.2716743Z 	at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357)
2020-11-09T22:19:47.2718213Z 	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1908)
2020-11-09T22:19:47.2719166Z 	at org.apache.flink.test.checkpointing.UnalignedCheckpointCompatibilityITCase.runAndTakeSavepoint(UnalignedCheckpointCompatibilityITCase.java:113)
2020-11-09T22:19:47.2720278Z 	at org.apache.flink.test.checkpointing.UnalignedCheckpointCompatibilityITCase.test(UnalignedCheckpointCompatibilityITCase.java:97)
2020-11-09T22:19:47.2721126Z 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2020-11-09T22:19:47.2721771Z 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2020-11-09T22:19:47.2722773Z 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-11-09T22:19:47.2723479Z 	at java.lang.reflect.Method.invoke(Method.java:498)
2020-11-09T22:19:47.2724187Z 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
2020-11-09T22:19:47.2725026Z 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
2020-11-09T22:19:47.2725817Z 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
2020-11-09T22:19:47.2726595Z 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
2020-11-09T22:19:47.2727515Z 	at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48)
2020-11-09T22:19:47.2728192Z 	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
2020-11-09T22:19:47.2744089Z 	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
2020-11-09T22:19:47.2744907Z 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
2020-11-09T22:19:47.2745573Z 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
2020-11-09T22:19:47.2746037Z 	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
2020-11-09T22:19:47.2746445Z 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
2020-11-09T22:19:47.2746868Z 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
2020-11-09T22:19:47.2747443Z 	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
2020-11-09T22:19:47.2747876Z 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
2020-11-09T22:19:47.2748297Z 	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
2020-11-09T22:19:47.2748694Z 	at org.junit.runners.Suite.runChild(Suite.java:128)
2020-11-09T22:19:47.2749054Z 	at org.junit.runners.Suite.runChild(Suite.java:27)
2020-11-09T22:19:47.2749414Z 	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
2020-11-09T22:19:47.2749819Z 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
2020-11-09T22:19:47.2750373Z 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
2020-11-09T22:19:47.2750923Z 	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
2020-11-09T22:19:47.2751555Z 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
2020-11-09T22:19:47.2752148Z 	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
2020-11-09T22:19:47.2752938Z 	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365)
2020-11-09T22:19:47.3085383Z 	at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273)
2020-11-09T22:19:47.3086377Z 	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238)
2020-11-09T22:19:47.3087146Z 	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159)
2020-11-09T22:19:47.3088051Z 	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
2020-11-09T22:19:47.3088815Z 	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
2020-11-09T22:19:47.3089472Z 	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
2020-11-09T22:19:47.3090109Z 	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
2020-11-09T22:19:47.3091501Z Caused by: java.util.concurrent.TimeoutException: Invocation of public default java.util.concurrent.CompletableFuture org.apache.flink.runtime.webmonitor.RestfulGateway.stopWithSavepoint(org.apache.flink.api.common.JobID,java.lang.String,boolean,org.apache.flink.api.common.time.Time) timed out.
2020-11-09T22:19:47.3092730Z 	at com.sun.proxy.$Proxy33.stopWithSavepoint(Unknown Source)
2020-11-09T22:19:47.3093348Z 	at org.apache.flink.runtime.minicluster.MiniCluster.lambda$stopWithSavepoint$9(MiniCluster.java:599)
2020-11-09T22:19:47.3094052Z 	at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:616)
2020-11-09T22:19:47.3094682Z 	at java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:628)
2020-11-09T22:19:47.3095359Z 	at java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:1996)
2020-11-09T22:19:47.3096070Z 	at org.apache.flink.runtime.minicluster.MiniCluster.runDispatcherCommand(MiniCluster.java:621)
2020-11-09T22:19:47.3096926Z 	at org.apache.flink.runtime.minicluster.MiniCluster.stopWithSavepoint(MiniCluster.java:599)
2020-11-09T22:19:47.3097996Z 	at org.apache.flink.client.program.PerJobMiniClusterFactory$PerJobMiniClusterJobClient.stopWithSavepoint(PerJobMiniClusterFactory.java:169)
2020-11-09T22:19:47.3098985Z 	at org.apache.flink.test.checkpointing.UnalignedCheckpointCompatibilityITCase.runAndTakeSavepoint(UnalignedCheckpointCompatibilityITCase.java:112)
2020-11-09T22:19:47.3099640Z 	... 36 more
2020-11-09T22:19:47.3101706Z Caused by: akka.pattern.AskTimeoutException: Ask timed out on [Actor[akka://flink/user/rpc/dispatcher_18#-978053777]] after [10000 ms]. Message of type [org.apache.flink.runtime.rpc.messages.LocalFencedMessage]. A typical reason for `AskTimeoutException` is that the recipient actor didn't send a reply.
2020-11-09T22:19:47.3103053Z 	at akka.pattern.PromiseActorRef$$anonfun$2.apply(AskSupport.scala:635)
2020-11-09T22:19:47.3103640Z 	at akka.pattern.PromiseActorRef$$anonfun$2.apply(AskSupport.scala:635)
2020-11-09T22:19:47.3104114Z 	at akka.pattern.PromiseActorRef$$anonfun$1.apply$mcV$sp(AskSupport.scala:648)
2020-11-09T22:19:47.3104521Z 	at akka.actor.Scheduler$$anon$4.run(Scheduler.scala:205)
2020-11-09T22:19:47.3104994Z 	at akka.actor.LightArrayRevolverScheduler$TaskHolder.run(LightArrayRevolverScheduler.scala:337)
2020-11-09T22:19:47.3105546Z 	at akka.actor.LightArrayRevolverScheduler$$anonfun$close$1.apply(LightArrayRevolverScheduler.scala:141)
2020-11-09T22:19:47.3106140Z 	at akka.actor.LightArrayRevolverScheduler$$anonfun$close$1.apply(LightArrayRevolverScheduler.scala:140)
2020-11-09T22:19:47.3106646Z 	at scala.collection.Iterator$class.foreach(Iterator.scala:891)
2020-11-09T22:19:47.3107072Z 	at scala.collection.AbstractIterator.foreach(Iterator.scala:1334)
2020-11-09T22:19:47.3107770Z 	at scala.collection.IterableLike$class.foreach(IterableLike.scala:72)
2020-11-09T22:19:47.3108203Z 	at scala.collection.AbstractIterable.foreach(Iterable.scala:54)
2020-11-09T22:19:47.3108659Z 	at akka.actor.LightArrayRevolverScheduler.close(LightArrayRevolverScheduler.scala:139)
2020-11-09T22:19:47.3109107Z 	at akka.actor.ActorSystemImpl.stopScheduler(ActorSystem.scala:937)
2020-11-09T22:19:47.3109575Z 	at akka.actor.ActorSystemImpl$$anonfun$liftedTree2$1$1.apply$mcV$sp(ActorSystem.scala:872)
2020-11-09T22:19:47.3110253Z 	at akka.actor.ActorSystemImpl$$anonfun$liftedTree2$1$1.apply(ActorSystem.scala:872)
2020-11-09T22:19:47.3110724Z 	at akka.actor.ActorSystemImpl$$anonfun$liftedTree2$1$1.apply(ActorSystem.scala:872)
2020-11-09T22:19:47.3111176Z 	at akka.actor.ActorSystemImpl$$anon$3.run(ActorSystem.scala:892)
2020-11-09T22:19:47.3111666Z 	at akka.actor.ActorSystemImpl$TerminationCallbacks$$anonfun$addRec$1$1.applyOrElse(ActorSystem.scala:1068)
2020-11-09T22:19:47.3112220Z 	at akka.actor.ActorSystemImpl$TerminationCallbacks$$anonfun$addRec$1$1.applyOrElse(ActorSystem.scala:1068)
2020-11-09T22:19:47.3112970Z 	at scala.concurrent.Future$$anonfun$andThen$1.apply(Future.scala:436)
2020-11-09T22:19:47.3113403Z 	at scala.concurrent.Future$$anonfun$andThen$1.apply(Future.scala:435)
2020-11-09T22:19:47.3113915Z 	at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:36)
2020-11-09T22:19:47.3114373Z 	at akka.dispatch.BatchingExecutor$AbstractBatch.processBatch(BatchingExecutor.scala:55)
2020-11-09T22:19:47.3114909Z 	at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply$mcV$sp(BatchingExecutor.scala:91)
2020-11-09T22:19:47.3115439Z 	at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply(BatchingExecutor.scala:91)
2020-11-09T22:19:47.3115961Z 	at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply(BatchingExecutor.scala:91)
2020-11-09T22:19:47.3116507Z 	at scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:72)
2020-11-09T22:19:47.3116953Z 	at akka.dispatch.BatchingExecutor$BlockableBatch.run(BatchingExecutor.scala:90)
2020-11-09T22:19:47.3117501Z 	at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:40)
2020-11-09T22:19:47.3117989Z 	at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(ForkJoinExecutorConfigurator.scala:44)
2020-11-09T22:19:47.3118536Z 	at akka.dispatch.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
2020-11-09T22:19:47.3118985Z 	at akka.dispatch.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
2020-11-09T22:19:47.3119440Z 	at akka.dispatch.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
2020-11-09T22:19:47.3119872Z 	at akka.dispatch.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)

      Attachments

        1. debug.log
          41 kB
          Arvid Heise
        2. thread.dump
          94 kB
          Arvid Heise

        Issue Links

          is caused by

          Bug - A problem which impairs or prevents the functions of the product. FLINK-20033 Job fails when stopping JobMaster

          • Critical - Crashes, loss of data, severe memory leak.
          • Closed
          is related to

          Bug - A problem which impairs or prevents the functions of the product. FLINK-19585 UnalignedCheckpointCompatibilityITCase.test:97->runAndTakeSavepoint: "Not all required tasks are currently running."

          • Critical - Crashes, loss of data, severe memory leak.
          • Resolved

          Bug - A problem which impairs or prevents the functions of the product. FLINK-15152 Job running without periodic checkpoint for stop failed at the beginning

          • Critical - Crashes, loss of data, severe memory leak.
          • Closed
          links to

          Web Link Potential fix for the problem

          Activity

            People

              trohrmann Till Rohrmann
              dian.fu Dian Fu
              Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: