[ https://issues.apache.org/jira/browse/FLINK-20254?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17321008#comment-17321008 ]
Leonard Xu commented on FLINK-20254: ------------------------------------ {quote} Is this the same issue? https://dev.azure.com/apache-flink/apache-flink/_build/results?buildId=15915&view=logs&j=fc5181b0-e452-5c8f-68de-1097947f6483&t=62110053-334f-5295-a0ab-80dd7e2babbf It's a different unit test but in the same file, with very similar name and the same symptom [ERROR] Errors: [ERROR] HiveTableSourceITCase.testStreamPartitionReadByPartitionTime:703->fetchRows:712 » TestTimedOut {quote} I think these case are same issue and the timeout reason should not relate to hive tests. > HiveTableSourceITCase.testStreamPartitionReadByCreateTime times out > ------------------------------------------------------------------- > > Key: FLINK-20254 > URL: https://issues.apache.org/jira/browse/FLINK-20254 > Project: Flink > Issue Type: Bug > Components: Connectors / Hive > Affects Versions: 1.12.0, 1.13.0 > Reporter: Robert Metzger > Assignee: Leonard Xu > Priority: Critical > Labels: pull-request-available, test-stability > Fix For: 1.13.0 > > > [https://dev.azure.com/apache-flink/apache-flink/_build/results?buildId=9808&view=logs&j=fc5181b0-e452-5c8f-68de-1097947f6483&t=62110053-334f-5295-a0ab-80dd7e2babbf] > {code:java} > 2020-11-19T10:34:23.5591765Z [ERROR] Tests run: 18, Failures: 0, Errors: 1, > Skipped: 0, Time elapsed: 192.243 s <<< FAILURE! - in > org.apache.flink.connectors.hive.HiveTableSourceITCase > 2020-11-19T10:34:23.5593193Z [ERROR] > testStreamPartitionReadByCreateTime(org.apache.flink.connectors.hive.HiveTableSourceITCase) > Time elapsed: 120.075 s <<< ERROR! > 2020-11-19T10:34:23.5593929Z org.junit.runners.model.TestTimedOutException: > test timed out after 120000 milliseconds > 2020-11-19T10:34:23.5594321Z at java.lang.Thread.sleep(Native Method) > 2020-11-19T10:34:23.5594777Z at > org.apache.flink.streaming.api.operators.collect.CollectResultFetcher.sleepBeforeRetry(CollectResultFetcher.java:231) > 2020-11-19T10:34:23.5595378Z at > org.apache.flink.streaming.api.operators.collect.CollectResultFetcher.next(CollectResultFetcher.java:119) > 2020-11-19T10:34:23.5596001Z at > org.apache.flink.streaming.api.operators.collect.CollectResultIterator.nextResultFromFetcher(CollectResultIterator.java:103) > 2020-11-19T10:34:23.5596610Z at > org.apache.flink.streaming.api.operators.collect.CollectResultIterator.hasNext(CollectResultIterator.java:77) > 2020-11-19T10:34:23.5597218Z at > org.apache.flink.table.planner.sinks.SelectTableSinkBase$RowIteratorWrapper.hasNext(SelectTableSinkBase.java:115) > 2020-11-19T10:34:23.5597811Z at > org.apache.flink.table.api.internal.TableResultImpl$CloseableRowIteratorWrapper.hasNext(TableResultImpl.java:355) > 2020-11-19T10:34:23.5598555Z at > org.apache.flink.connectors.hive.HiveTableSourceITCase.fetchRows(HiveTableSourceITCase.java:653) > 2020-11-19T10:34:23.5599407Z at > org.apache.flink.connectors.hive.HiveTableSourceITCase.testStreamPartitionReadByCreateTime(HiveTableSourceITCase.java:594) > 2020-11-19T10:34:23.5599982Z at > sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > 2020-11-19T10:34:23.5600393Z at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) > 2020-11-19T10:34:23.5600865Z at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > 2020-11-19T10:34:23.5601300Z at > java.lang.reflect.Method.invoke(Method.java:498) > 2020-11-19T10:34:23.5601713Z at > org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) > 2020-11-19T10:34:23.5602211Z at > org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) > 2020-11-19T10:34:23.5602688Z at > org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) > 2020-11-19T10:34:23.5603181Z at > org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) > 2020-11-19T10:34:23.5603753Z at > org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298) > 2020-11-19T10:34:23.5604308Z at > org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292) > 2020-11-19T10:34:23.5604780Z at > java.util.concurrent.FutureTask.run(FutureTask.java:266) > 2020-11-19T10:34:23.5605114Z at java.lang.Thread.run(Thread.java:748) > 2020-11-19T10:34:23.5605299Z > 2020-11-19T10:34:24.4180149Z [INFO] Running > org.apache.flink.connectors.hive.TableEnvHiveConnectorITCase > {code} > > I've spent some time to debug this case in local env, but unfortunately I > didn't find the root cause. I think this is the same case with FLINK-22129, > FLINK-22100, but after the debug, Ithe failed test in *HiveTableSourceITCase* > should not exist bugs, and the root cause may be related to FLINK-21996. > Given some debug results: > * 1. Run HiveTableSourceITCase.testStreamPartitionReadByCreateTime times out > repeatedly in IDE, it mostly failed in the aboud the 36th round > * 2. The thread usually hang on > {code:java} > org.apache.flink.streaming.api.operators.collect.CollectResultFetcher.next(CollectResultFetcher.java:119){code} > {code:java} > org.apache.flink.streaming.api.operators.collect.CollectResultFetcher.sendRequest(CollectResultFetcher.java:155){code} > I try to add timeout for CompletableFutures in CollectResultFetcher, but > looks it doesn't help > > * 3. When the thread stuck, the SourceReaderBase#addSplits may recieve split > or may not(I reproduced multiple round), but before the test failed, there're > a checkpoint ERRORR which may related to the case. > {code:java} > INFO org.apache.flink.runtime.jobmaster.JobMaster [] - > Running initialization on master for job collect > (3572e9cf6c0829ebc9f765555327388d). > INFO org.apache.flink.runtime.checkpoint.CheckpointCoordinator [] - No > checkpoint found during restore. > INFO org.apache.flink.runtime.jobmaster.JobMaster [] - Using > failover strategy > org.apache.flink.runtime.executiongraph.failover.flip1.RestartPipelinedRegionFailoverStrategy@76f98551 > for collect (3572e9cf6c0829ebc9f765555327388d). > INFO > org.apache.flink.runtime.highavailability.nonha.embedded.EmbeddedLeaderService > [] - Received confirmation of leadership for leader > akka://flink/user/rpc/jobmanager_147 , session=0d15d532-d739-410f-9 > ..... > WARN org.apache.flink.runtime.checkpoint.CheckpointCoordinator [] - > Failed to trigger checkpoint for job 3572e9cf6c0829ebc9f765555327388d.) > org.apache.flink.runtime.checkpoint.CheckpointException: Checkpoint > triggering task Source: HiveSource-source_db.stream_create_time_test -> > SinkConversionToTuple2 -> Sink: Select table sink (1/1) of job > 3572e9cf6c0829ebc9f765555327388d has not being executed at the moment. > Aborting checkpoint. Failure reason: Not all required tasks are currently > running. > at > org.apache.flink.runtime.checkpoint.DefaultCheckpointPlanCalculator.checkTasksStarted(DefaultCheckpointPlanCalculator.java:152) > ~[classes/:?] > at > org.apache.flink.runtime.checkpoint.DefaultCheckpointPlanCalculator.lambda$calculateCheckpointPlan$1(DefaultCheckpointPlanCalculator.java:114) > ~[classes/:?] > at > java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1590) > ~[?:1.8.0_172] > at > org.apache.flink.runtime.rpc.akka.AkkaRpcActor.handleRunAsync(AkkaRpcActor.java:440) > ~[classes/:?] > at > org.apache.flink.runtime.rpc.akka.AkkaRpcActor.handleRpcMessage(AkkaRpcActor.java:208) > ~[classes/:?] > at > org.apache.flink.runtime.rpc.akka.FencedAkkaRpcActor.handleRpcMessage(FencedAkkaRpcActor.java:77) > ~[classes/:?] > at > org.apache.flink.runtime.rpc.akka.AkkaRpcActor.handleMessage(AkkaRpcActor.java:158) > ~[classes/:?] > 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]{code} -- This message was sent by Atlassian Jira (v8.3.4#803005)