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

XML

Word

Printable

JSON

Details

Type: Bug
Status: Closed
Priority: Critical
Resolution: Duplicate
Affects Version/s: 1.11.0
Fix Version/s: None
Component/s: Runtime / Coordination, Table SQL / Planner, Tests
Labels:
- test-stability

Description

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

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

Attachments

Issue Links

duplicates

FLINK-17194 TPC-DS end-to-end test fails due to missing execution attempt

Closed

Activity

People

Assignee:: Unassigned

Reporter:: Robert Metzger

Votes:: 0 Vote for this issue

Watchers:: 2 Start watching this issue

Dates

Created:: 17/May/20 08:57

Updated:: 18/May/20 09:20

Resolved:: 18/May/20 09:20