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)
