[jira] [Created] (FLINK-17770) TPC-DS end-to-end test (Blink planner) fails with AskTimeoutException

[Shang Yuanchun (Jira)]

Robert Metzger created FLINK-17770:
--------------------------------------

             Summary: TPC-DS end-to-end test (Blink planner) fails with AskTimeoutException
                 Key: FLINK-17770
                 URL: https://issues.apache.org/jira/browse/FLINK-17770
             Project: Flink
          Issue Type: Bug
          Components: Runtime / Coordination, Table SQL / Planner, Tests
    Affects Versions: 1.11.0
            Reporter: Robert Metzger
             Fix For: 1.11.0


Hadoop 3.1.3 nightly profile: https://dev.azure.com/apache-flink/apache-flink/_build/results?buildId=1579&view=logs&j=91bf6583-3fb2-592f-e4d4-d79d79c3230a&t=94459a52-42b6-5bfc-5d74-690b5d3c6de8

{code}
2020-05-17T06:39:29.8582972Z [INFO]Run TPC-DS query 62 success.
2020-05-17T06:39:29.8584484Z [INFO]Run TPC-DS query 63 ...
2020-05-17T06:39:30.1995132Z Job has been submitted with JobID 92560393bbba78447aa14558d0b08014
2020-05-17T06:40:12.9847942Z
2020-05-17T06:40:12.9853097Z ------------------------------------------------------------
2020-05-17T06:40:12.9856909Z  The program finished with the following exception:
2020-05-17T06:40:12.9859275Z
2020-05-17T06:40:12.9885450Z org.apache.flink.client.program.ProgramInvocationException: The main method caused an error: org.apache.flink.client.program.ProgramInvocationException: Job failed (JobID: 92560393bbba78447aa14558d0b08014)
2020-05-17T06:40:12.9889713Z at org.apache.flink.client.program.PackagedProgram.callMainMethod(PackagedProgram.java:302)
2020-05-17T06:40:12.9890513Z at org.apache.flink.client.program.PackagedProgram.invokeInteractiveModeForExecution(PackagedProgram.java:198)
2020-05-17T06:40:12.9891153Z at org.apache.flink.client.ClientUtils.executeProgram(ClientUtils.java:148)
2020-05-17T06:40:12.9892141Z at org.apache.flink.client.cli.CliFrontend.executeProgram(CliFrontend.java:689)
2020-05-17T06:40:12.9893860Z at org.apache.flink.client.cli.CliFrontend.run(CliFrontend.java:227)
2020-05-17T06:40:12.9894484Z at org.apache.flink.client.cli.CliFrontend.parseParameters(CliFrontend.java:906)
2020-05-17T06:40:12.9899582Z at org.apache.flink.client.cli.CliFrontend.lambda$main$10(CliFrontend.java:982)
2020-05-17T06:40:12.9900278Z at org.apache.flink.runtime.security.contexts.NoOpSecurityContext.runSecured(NoOpSecurityContext.java:30)
2020-05-17T06:40:12.9901521Z at org.apache.flink.client.cli.CliFrontend.main(CliFrontend.java:982)
2020-05-17T06:40:12.9902541Z Caused by: java.util.concurrent.ExecutionException: org.apache.flink.client.program.ProgramInvocationException: Job failed (JobID: 92560393bbba78447aa14558d0b08014)
2020-05-17T06:40:12.9903292Z at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357)
2020-05-17T06:40:12.9905140Z at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1908)
2020-05-17T06:40:12.9905834Z at org.apache.flink.table.tpcds.TpcdsTestProgram.main(TpcdsTestProgram.java:109)
2020-05-17T06:40:12.9906355Z at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2020-05-17T06:40:12.9906880Z at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2020-05-17T06:40:12.9907468Z at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2020-05-17T06:40:12.9908022Z at java.lang.reflect.Method.invoke(Method.java:498)
2020-05-17T06:40:12.9908569Z at org.apache.flink.client.program.PackagedProgram.callMainMethod(PackagedProgram.java:288)
2020-05-17T06:40:12.9909098Z ... 8 more
2020-05-17T06:40:12.9909584Z Caused by: org.apache.flink.client.program.ProgramInvocationException: Job failed (JobID: 92560393bbba78447aa14558d0b08014)
2020-05-17T06:40:12.9910277Z at org.apache.flink.client.deployment.ClusterClientJobClientAdapter.lambda$null$6(ClusterClientJobClientAdapter.java:116)
2020-05-17T06:40:12.9910886Z at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:616)
2020-05-17T06:40:12.9912098Z at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591)
2020-05-17T06:40:12.9912767Z at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
2020-05-17T06:40:12.9913363Z at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1975)
2020-05-17T06:40:12.9914013Z at org.apache.flink.client.program.rest.RestClusterClient.lambda$pollResourceAsync$22(RestClusterClient.java:602)
2020-05-17T06:40:12.9915121Z at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774)
2020-05-17T06:40:12.9915848Z at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750)
2020-05-17T06:40:12.9916515Z at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
2020-05-17T06:40:12.9917245Z at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1975)
2020-05-17T06:40:12.9917955Z at org.apache.flink.runtime.concurrent.FutureUtils.lambda$retryOperationWithDelay$8(FutureUtils.java:307)
2020-05-17T06:40:12.9918660Z at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774)
2020-05-17T06:40:12.9919319Z at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750)
2020-05-17T06:40:12.9920093Z at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
2020-05-17T06:40:12.9920699Z at java.util.concurrent.CompletableFuture.postFire(CompletableFuture.java:575)
2020-05-17T06:40:12.9921307Z at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:943)
2020-05-17T06:40:12.9922063Z at java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:456)
2020-05-17T06:40:12.9922667Z at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
2020-05-17T06:40:12.9923462Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-05-17T06:40:12.9923999Z at java.lang.Thread.run(Thread.java:748)
2020-05-17T06:40:12.9924501Z Caused by: org.apache.flink.runtime.client.JobExecutionException: Job execution failed.
2020-05-17T06:40:12.9925396Z at org.apache.flink.runtime.jobmaster.JobResult.toJobExecutionResult(JobResult.java:147)
2020-05-17T06:40:12.9926107Z at org.apache.flink.client.deployment.ClusterClientJobClientAdapter.lambda$null$6(ClusterClientJobClientAdapter.java:114)
2020-05-17T06:40:12.9926633Z ... 19 more
2020-05-17T06:40:12.9927038Z Caused by: org.apache.flink.runtime.JobException: Recovery is suppressed by NoRestartBackoffTimeStrategy
2020-05-17T06:40:12.9927776Z at org.apache.flink.runtime.executiongraph.failover.flip1.ExecutionFailureHandler.handleFailure(ExecutionFailureHandler.java:116)
2020-05-17T06:40:12.9928622Z at org.apache.flink.runtime.executiongraph.failover.flip1.ExecutionFailureHandler.getFailureHandlingResult(ExecutionFailureHandler.java:78)
2020-05-17T06:40:12.9929434Z at org.apache.flink.runtime.scheduler.DefaultScheduler.handleTaskFailure(DefaultScheduler.java:192)
2020-05-17T06:40:12.9930161Z at org.apache.flink.runtime.scheduler.DefaultScheduler.maybeHandleTaskFailure(DefaultScheduler.java:185)
2020-05-17T06:40:12.9930893Z at org.apache.flink.runtime.scheduler.DefaultScheduler.updateTaskExecutionStateInternal(DefaultScheduler.java:179)
2020-05-17T06:40:12.9931640Z at org.apache.flink.runtime.scheduler.SchedulerBase.updateTaskExecutionState(SchedulerBase.java:501)
2020-05-17T06:40:12.9932626Z at org.apache.flink.runtime.scheduler.UpdateSchedulerNgOnInternalFailuresListener.notifyTaskFailure(UpdateSchedulerNgOnInternalFailuresListener.java:49)
2020-05-17T06:40:12.9933496Z at org.apache.flink.runtime.executiongraph.ExecutionGraph.notifySchedulerNgAboutInternalTaskFailure(ExecutionGraph.java:1718)
2020-05-17T06:40:12.9934232Z at org.apache.flink.runtime.executiongraph.Execution.processFail(Execution.java:1268)
2020-05-17T06:40:12.9934892Z at org.apache.flink.runtime.executiongraph.Execution.processFail(Execution.java:1236)
2020-05-17T06:40:12.9935711Z at org.apache.flink.runtime.executiongraph.Execution.markFailed(Execution.java:1067)
2020-05-17T06:40:12.9936353Z at org.apache.flink.runtime.executiongraph.Execution.lambda$deploy$10(Execution.java:765)
2020-05-17T06:40:12.9937011Z at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774)
2020-05-17T06:40:12.9937664Z at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750)
2020-05-17T06:40:12.9938337Z at java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:456)
2020-05-17T06:40:12.9938990Z at org.apache.flink.runtime.rpc.akka.AkkaRpcActor.handleRunAsync(AkkaRpcActor.java:402)
2020-05-17T06:40:12.9939633Z at org.apache.flink.runtime.rpc.akka.AkkaRpcActor.handleRpcMessage(AkkaRpcActor.java:195)
2020-05-17T06:40:12.9940335Z at org.apache.flink.runtime.rpc.akka.FencedAkkaRpcActor.handleRpcMessage(FencedAkkaRpcActor.java:74)
2020-05-17T06:40:12.9941013Z at org.apache.flink.runtime.rpc.akka.AkkaRpcActor.handleMessage(AkkaRpcActor.java:152)
2020-05-17T06:40:12.9941625Z at akka.japi.pf.UnitCaseStatement.apply(CaseStatements.scala:26)
2020-05-17T06:40:12.9942188Z at akka.japi.pf.UnitCaseStatement.apply(CaseStatements.scala:21)
2020-05-17T06:40:12.9942737Z at scala.PartialFunction$class.applyOrElse(PartialFunction.scala:123)
2020-05-17T06:40:12.9943416Z at akka.japi.pf.UnitCaseStatement.applyOrElse(CaseStatements.scala:21)
2020-05-17T06:40:12.9944104Z at scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:170)
2020-05-17T06:40:12.9944630Z at scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:171)
2020-05-17T06:40:12.9945175Z at scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:171)
2020-05-17T06:40:12.9992329Z at akka.actor.Actor$class.aroundReceive(Actor.scala:517)
2020-05-17T06:40:12.9993483Z at akka.actor.AbstractActor.aroundReceive(AbstractActor.scala:225)
2020-05-17T06:40:12.9994407Z at akka.actor.ActorCell.receiveMessage(ActorCell.scala:592)
2020-05-17T06:40:12.9994936Z at akka.actor.ActorCell.invoke(ActorCell.scala:561)
2020-05-17T06:40:12.9995446Z at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:258)
2020-05-17T06:40:12.9995941Z at akka.dispatch.Mailbox.run(Mailbox.scala:225)
2020-05-17T06:40:12.9996505Z at akka.dispatch.Mailbox.exec(Mailbox.scala:235)
2020-05-17T06:40:12.9997005Z at akka.dispatch.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
2020-05-17T06:40:12.9997564Z at akka.dispatch.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
2020-05-17T06:40:12.9998111Z at akka.dispatch.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
2020-05-17T06:40:12.9998691Z at akka.dispatch.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
2020-05-17T06:40:12.9999753Z Caused by: java.util.concurrent.CompletionException: java.util.concurrent.TimeoutException: Invocation of public abstract java.util.concurrent.CompletableFuture org.apache.flink.runtime.taskexecutor.TaskExecutorGateway.submitTask(org.apache.flink.runtime.deployment.TaskDeploymentDescriptor,org.apache.flink.runtime.jobmaster.JobMasterId,org.apache.flink.api.common.time.Time) timed out.
2020-05-17T06:40:13.0001008Z at java.util.concurrent.CompletableFuture.encodeRelay(CompletableFuture.java:326)
2020-05-17T06:40:13.0001631Z at java.util.concurrent.CompletableFuture.completeRelay(CompletableFuture.java:338)
2020-05-17T06:40:13.0002246Z at java.util.concurrent.CompletableFuture.uniRelay(CompletableFuture.java:925)
2020-05-17T06:40:13.0002844Z at java.util.concurrent.CompletableFuture$UniRelay.tryFire(CompletableFuture.java:913)
2020-05-17T06:40:13.0003622Z at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
2020-05-17T06:40:13.0004142Z at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
2020-05-17T06:40:13.0004688Z at org.apache.flink.runtime.rpc.akka.AkkaInvocationHandler.lambda$invokeRpc$0(AkkaInvocationHandler.java:227)
2020-05-17T06:40:13.0005417Z at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774)
2020-05-17T06:40:13.0005939Z at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750)
2020-05-17T06:40:13.0006421Z at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
2020-05-17T06:40:13.0006923Z at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
2020-05-17T06:40:13.0007428Z at org.apache.flink.runtime.concurrent.FutureUtils$1.onComplete(FutureUtils.java:888)
2020-05-17T06:40:13.0007835Z at akka.dispatch.OnComplete.internal(Future.scala:263)
2020-05-17T06:40:13.0008200Z at akka.dispatch.OnComplete.internal(Future.scala:261)
2020-05-17T06:40:13.0008558Z at akka.dispatch.japi$CallbackBridge.apply(Future.scala:191)
2020-05-17T06:40:13.0008952Z at akka.dispatch.japi$CallbackBridge.apply(Future.scala:188)
2020-05-17T06:40:13.0009355Z at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:36)
2020-05-17T06:40:13.0009813Z at org.apache.flink.runtime.concurrent.Executors$DirectExecutionContext.execute(Executors.java:74)
2020-05-17T06:40:13.0010313Z at scala.concurrent.impl.CallbackRunnable.executeWithValue(Promise.scala:44)
2020-05-17T06:40:13.0010887Z at scala.concurrent.impl.Promise$DefaultPromise.tryComplete(Promise.scala:252)
2020-05-17T06:40:13.0011503Z at akka.pattern.PromiseActorRef$$anonfun$1.apply$mcV$sp(AskSupport.scala:644)
2020-05-17T06:40:13.0011933Z at akka.actor.Scheduler$$anon$4.run(Scheduler.scala:205)
2020-05-17T06:40:13.0012400Z at scala.concurrent.Future$InternalCallbackExecutor$.unbatchedExecute(Future.scala:601)
2020-05-17T06:40:13.0012915Z at scala.concurrent.BatchingExecutor$class.execute(BatchingExecutor.scala:109)
2020-05-17T06:40:13.0013383Z at scala.concurrent.Future$InternalCallbackExecutor$.execute(Future.scala:599)
2020-05-17T06:40:13.0013929Z at akka.actor.LightArrayRevolverScheduler$TaskHolder.executeTask(LightArrayRevolverScheduler.scala:328)
2020-05-17T06:40:13.0014608Z at akka.actor.LightArrayRevolverScheduler$$anon$4.executeBucket$1(LightArrayRevolverScheduler.scala:279)
2020-05-17T06:40:13.0015200Z at akka.actor.LightArrayRevolverScheduler$$anon$4.nextTick(LightArrayRevolverScheduler.scala:283)
2020-05-17T06:40:13.0015771Z at akka.actor.LightArrayRevolverScheduler$$anon$4.run(LightArrayRevolverScheduler.scala:235)
2020-05-17T06:40:13.0016194Z at java.lang.Thread.run(Thread.java:748)
2020-05-17T06:40:13.0017051Z Caused by: java.util.concurrent.TimeoutException: Invocation of public abstract java.util.concurrent.CompletableFuture org.apache.flink.runtime.taskexecutor.TaskExecutorGateway.submitTask(org.apache.flink.runtime.deployment.TaskDeploymentDescriptor,org.apache.flink.runtime.jobmaster.JobMasterId,org.apache.flink.api.common.time.Time) timed out.
2020-05-17T06:40:13.0018031Z at org.apache.flink.runtime.jobmaster.RpcTaskManagerGateway.submitTask(RpcTaskManagerGateway.java:72)
2020-05-17T06:40:13.0018701Z at org.apache.flink.runtime.executiongraph.Execution.lambda$deploy$9(Execution.java:752)
2020-05-17T06:40:13.0019350Z at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1604)
2020-05-17T06:40:13.0019803Z at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
2020-05-17T06:40:13.0020337Z at java.util.concurrent.FutureTask.run(FutureTask.java:266)
2020-05-17T06:40:13.0020818Z at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
2020-05-17T06:40:13.0021378Z at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
2020-05-17T06:40:13.0021887Z at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
2020-05-17T06:40:13.0022316Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2020-05-17T06:40:13.0022623Z ... 1 more
2020-05-17T06:40:13.0024152Z Caused by: akka.pattern.AskTimeoutException: Ask timed out on [Actor[akka.tcp://flink@10.1.0.4:41387/user/rpc/taskmanager_0#-714774798]] after [20000 ms]. Message of type [org.apache.flink.runtime.rpc.messages.RemoteRpcInvocation]. A typical reason for `AskTimeoutException` is that the recipient actor didn't send a reply.
2020-05-17T06:40:13.0025376Z at akka.pattern.PromiseActorRef$$anonfun$2.apply(AskSupport.scala:635)
2020-05-17T06:40:13.0025790Z at akka.pattern.PromiseActorRef$$anonfun$2.apply(AskSupport.scala:635)
2020-05-17T06:40:13.0026213Z at akka.pattern.PromiseActorRef$$anonfun$1.apply$mcV$sp(AskSupport.scala:648)
2020-05-17T06:40:13.0026588Z at akka.actor.Scheduler$$anon$4.run(Scheduler.scala:205)
2020-05-17T06:40:13.0026999Z at scala.concurrent.Future$InternalCallbackExecutor$.unbatchedExecute(Future.scala:601)
2020-05-17T06:40:13.0027433Z at scala.concurrent.BatchingExecutor$class.execute(BatchingExecutor.scala:109)
2020-05-17T06:40:13.0027994Z at scala.concurrent.Future$InternalCallbackExecutor$.execute(Future.scala:599)
2020-05-17T06:40:13.0028512Z at akka.actor.LightArrayRevolverScheduler$TaskHolder.executeTask(LightArrayRevolverScheduler.scala:328)
2020-05-17T06:40:13.0029059Z at akka.actor.LightArrayRevolverScheduler$$anon$4.executeBucket$1(LightArrayRevolverScheduler.scala:279)
2020-05-17T06:40:13.0029614Z at akka.actor.LightArrayRevolverScheduler$$anon$4.nextTick(LightArrayRevolverScheduler.scala:283)
2020-05-17T06:40:13.0030127Z at akka.actor.LightArrayRevolverScheduler$$anon$4.run(LightArrayRevolverScheduler.scala:235)
2020-05-17T06:40:13.0030475Z ... 1 more
2020-05-17T06:40:13.0337076Z [FAIL] Test script contains errors.

[ ... ]

2020-05-17T06:41:02.0344875Z [FAIL] 'TPC-DS end-to-end test (Blink planner)' failed after 13 minutes and 55 seconds! Test exited with exit code 1 and the logs contained errors, exceptions or non-empty .out files

{code}



--
This message was sent by Atlassian Jira
(v8.3.4#803005)