[ https://issues.apache.org/jira/browse/FLINK-17378?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17104367#comment-17104367 ]
Robert Metzger commented on FLINK-17378: ---------------------------------------- https://dev.azure.com/apache-flink/apache-flink/_build/results?buildId=970&view=logs&j=c5f0071e-1851-543e-9a45-9ac140befc32&t=684b1416-4c17-504e-d5ab-97ee44e08a20 > KafkaProducerExactlyOnceITCase>KafkaProducerTestBase.testExactlyOnceCustomOperator > unstable > ------------------------------------------------------------------------------------------- > > Key: FLINK-17378 > URL: https://issues.apache.org/jira/browse/FLINK-17378 > Project: Flink > Issue Type: Bug > Components: Connectors / Kafka > Affects Versions: 1.11.0 > Reporter: Robert Metzger > Priority: Major > Labels: test-stability > > CI run: > https://dev.azure.com/apache-flink/apache-flink/_build/results?buildId=221&view=logs&j=c5f0071e-1851-543e-9a45-9ac140befc32&t=684b1416-4c17-504e-d5ab-97ee44e08a20 > {code} > 2020-04-25T00:41:01.4191956Z 00:41:01,418 [Source: Custom Source -> Map -> > Sink: Unnamed (1/1)] INFO > org.apache.flink.streaming.connectors.kafka.internal.FlinkKafkaInternalProducer > [] - Flushing new partitions > 2020-04-25T00:41:01.4194268Z 00:41:01,418 [FailingIdentityMapper Status > Printer] INFO > org.apache.flink.streaming.connectors.kafka.testutils.FailingIdentityMapper > [] - ============================> Failing mapper 0: count=690, > totalCount=1000 > 2020-04-25T00:41:01.4589519Z > org.apache.flink.runtime.client.JobExecutionException: Job execution failed. > 2020-04-25T00:41:01.4590089Z at > org.apache.flink.runtime.jobmaster.JobResult.toJobExecutionResult(JobResult.java:147) > 2020-04-25T00:41:01.4590748Z at > org.apache.flink.runtime.minicluster.MiniCluster.executeJobBlocking(MiniCluster.java:659) > 2020-04-25T00:41:01.4591524Z at > org.apache.flink.streaming.util.TestStreamEnvironment.execute(TestStreamEnvironment.java:77) > 2020-04-25T00:41:01.4592062Z at > org.apache.flink.streaming.api.environment.StreamExecutionEnvironment.execute(StreamExecutionEnvironment.java:1643) > 2020-04-25T00:41:01.4592597Z at > org.apache.flink.test.util.TestUtils.tryExecute(TestUtils.java:35) > 2020-04-25T00:41:01.4593092Z at > org.apache.flink.streaming.connectors.kafka.KafkaProducerTestBase.testExactlyOnce(KafkaProducerTestBase.java:370) > 2020-04-25T00:41:01.4593680Z at > org.apache.flink.streaming.connectors.kafka.KafkaProducerTestBase.testExactlyOnceCustomOperator(KafkaProducerTestBase.java:317) > 2020-04-25T00:41:01.4594450Z at > sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > 2020-04-25T00:41:01.4595076Z at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) > 2020-04-25T00:41:01.4595794Z at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > 2020-04-25T00:41:01.4596622Z at > java.lang.reflect.Method.invoke(Method.java:498) > 2020-04-25T00:41:01.4597501Z at > org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) > 2020-04-25T00:41:01.4598396Z at > org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) > 2020-04-25T00:41:01.4602222Z at > org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) > 2020-04-25T00:41:01.4603082Z at > org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) > 2020-04-25T00:41:01.4604023Z at > org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55) > 2020-04-25T00:41:01.4604590Z at > org.junit.rules.RunRules.evaluate(RunRules.java:20) > 2020-04-25T00:41:01.4605225Z at > org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > 2020-04-25T00:41:01.4605902Z at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) > 2020-04-25T00:41:01.4606591Z at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) > 2020-04-25T00:41:01.4607468Z at > org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > 2020-04-25T00:41:01.4608577Z at > org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > 2020-04-25T00:41:01.4609030Z at > org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > 2020-04-25T00:41:01.4609460Z at > org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > 2020-04-25T00:41:01.4609842Z at > org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > 2020-04-25T00:41:01.4610270Z at > org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) > 2020-04-25T00:41:01.4610727Z at > org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) > 2020-04-25T00:41:01.4611147Z at > org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48) > 2020-04-25T00:41:01.4611628Z at > org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48) > 2020-04-25T00:41:01.4612011Z at > org.junit.rules.RunRules.evaluate(RunRules.java:20) > 2020-04-25T00:41:01.4612415Z at > org.junit.runners.ParentRunner.run(ParentRunner.java:363) > 2020-04-25T00:41:01.4612841Z at > org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365) > 2020-04-25T00:41:01.4613325Z at > org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273) > 2020-04-25T00:41:01.4613810Z at > org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238) > 2020-04-25T00:41:01.4614300Z at > org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159) > 2020-04-25T00:41:01.4614801Z at > org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384) > 2020-04-25T00:41:01.4615291Z at > org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345) > 2020-04-25T00:41:01.4615761Z at > org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126) > 2020-04-25T00:41:01.4616204Z at > org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418) > 2020-04-25T00:41:01.4616727Z Caused by: > org.apache.flink.runtime.JobException: Recovery is suppressed by > FixedDelayRestartBackoffTimeStrategy(maxNumberRestartAttempts=1, > backoffTimeMS=0) > 2020-04-25T00:41:01.4617490Z at > org.apache.flink.runtime.executiongraph.failover.flip1.ExecutionFailureHandler.handleFailure(ExecutionFailureHandler.java:112) > 2020-04-25T00:41:01.4618277Z at > org.apache.flink.runtime.executiongraph.failover.flip1.ExecutionFailureHandler.getFailureHandlingResult(ExecutionFailureHandler.java:78) > 2020-04-25T00:41:01.4618874Z at > org.apache.flink.runtime.scheduler.DefaultScheduler.handleTaskFailure(DefaultScheduler.java:189) > 2020-04-25T00:41:01.4619502Z at > org.apache.flink.runtime.scheduler.DefaultScheduler.maybeHandleTaskFailure(DefaultScheduler.java:183) > 2020-04-25T00:41:01.4620331Z at > org.apache.flink.runtime.scheduler.DefaultScheduler.updateTaskExecutionStateInternal(DefaultScheduler.java:177) > 2020-04-25T00:41:01.4620932Z at > org.apache.flink.runtime.scheduler.SchedulerBase.updateTaskExecutionState(SchedulerBase.java:497) > 2020-04-25T00:41:01.4621418Z at > org.apache.flink.runtime.jobmaster.JobMaster.updateTaskExecutionState(JobMaster.java:384) > 2020-04-25T00:41:01.4621834Z at > sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > 2020-04-25T00:41:01.4622211Z at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) > 2020-04-25T00:41:01.4623159Z at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > 2020-04-25T00:41:01.4623781Z at > java.lang.reflect.Method.invoke(Method.java:498) > 2020-04-25T00:41:01.4624563Z at > org.apache.flink.runtime.rpc.akka.AkkaRpcActor.handleRpcInvocation(AkkaRpcActor.java:284) > 2020-04-25T00:41:01.4625326Z at > org.apache.flink.runtime.rpc.akka.AkkaRpcActor.handleRpcMessage(AkkaRpcActor.java:199) > 2020-04-25T00:41:01.4626109Z at > org.apache.flink.runtime.rpc.akka.FencedAkkaRpcActor.handleRpcMessage(FencedAkkaRpcActor.java:74) > 2020-04-25T00:41:01.4627018Z at > org.apache.flink.runtime.rpc.akka.AkkaRpcActor.handleMessage(AkkaRpcActor.java:152) > 2020-04-25T00:41:01.4627816Z at > akka.japi.pf.UnitCaseStatement.apply(CaseStatements.scala:26) > 2020-04-25T00:41:01.4628451Z at > akka.japi.pf.UnitCaseStatement.apply(CaseStatements.scala:21) > 2020-04-25T00:41:01.4629044Z at > scala.PartialFunction$class.applyOrElse(PartialFunction.scala:123) > 2020-04-25T00:41:01.4629656Z at > akka.japi.pf.UnitCaseStatement.applyOrElse(CaseStatements.scala:21) > 2020-04-25T00:41:01.4630283Z at > scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:170) > 2020-04-25T00:41:01.4630869Z at > scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:171) > 2020-04-25T00:41:01.4631520Z at > scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:171) > 2020-04-25T00:41:01.4632123Z at > akka.actor.Actor$class.aroundReceive(Actor.scala:517) > 2020-04-25T00:41:01.4632663Z at > akka.actor.AbstractActor.aroundReceive(AbstractActor.scala:225) > 2020-04-25T00:41:01.4633263Z at > akka.actor.ActorCell.receiveMessage(ActorCell.scala:592) > 2020-04-25T00:41:01.4633823Z at > akka.actor.ActorCell.invoke(ActorCell.scala:561) > 2020-04-25T00:41:01.4634357Z at > akka.dispatch.Mailbox.processMailbox(Mailbox.scala:258) > 2020-04-25T00:41:01.4634860Z at akka.dispatch.Mailbox.run(Mailbox.scala:225) > 2020-04-25T00:41:01.4635333Z at akka.dispatch.Mailbox.exec(Mailbox.scala:235) > 2020-04-25T00:41:01.4635896Z at > akka.dispatch.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260) > 2020-04-25T00:41:01.4636559Z at > akka.dispatch.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339) > 2020-04-25T00:41:01.4637389Z at > akka.dispatch.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979) > 2020-04-25T00:41:01.4638153Z at > akka.dispatch.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107) > 2020-04-25T00:41:01.4638794Z Caused by: java.lang.RuntimeException: Error > while confirming checkpoint > 2020-04-25T00:41:01.4639705Z at > org.apache.flink.streaming.runtime.tasks.StreamTask.notifyCheckpointComplete(StreamTask.java:891) > 2020-04-25T00:41:01.4640597Z at > org.apache.flink.streaming.runtime.tasks.StreamTask.lambda$notifyCheckpointCompleteAsync$6(StreamTask.java:866) > 2020-04-25T00:41:01.4641398Z at > org.apache.flink.util.function.FunctionUtils.lambda$asCallable$5(FunctionUtils.java:125) > 2020-04-25T00:41:01.4642088Z at > java.util.concurrent.FutureTask.run(FutureTask.java:266) > 2020-04-25T00:41:01.4642940Z at > org.apache.flink.streaming.runtime.tasks.StreamTaskActionExecutor$SynchronizedStreamTaskActionExecutor.runThrowing(StreamTaskActionExecutor.java:92) > 2020-04-25T00:41:01.4643841Z at > org.apache.flink.streaming.runtime.tasks.mailbox.Mail.run(Mail.java:78) > 2020-04-25T00:41:01.4644608Z at > org.apache.flink.streaming.runtime.tasks.mailbox.MailboxExecutorImpl.tryYield(MailboxExecutorImpl.java:79) > 2020-04-25T00:41:01.4645571Z at > org.apache.flink.streaming.runtime.tasks.StreamOperatorWrapper.quiesceTimeServiceAndCloseOperator(StreamOperatorWrapper.java:138) > 2020-04-25T00:41:01.4646510Z at > org.apache.flink.streaming.runtime.tasks.StreamOperatorWrapper.close(StreamOperatorWrapper.java:113) > 2020-04-25T00:41:01.4647503Z at > org.apache.flink.streaming.runtime.tasks.StreamOperatorWrapper.close(StreamOperatorWrapper.java:117) > 2020-04-25T00:41:01.4648419Z at > org.apache.flink.streaming.runtime.tasks.StreamOperatorWrapper.close(StreamOperatorWrapper.java:117) > 2020-04-25T00:41:01.4649203Z at > org.apache.flink.streaming.runtime.tasks.StreamOperatorWrapper.close(StreamOperatorWrapper.java:78) > 2020-04-25T00:41:01.4650244Z at > org.apache.flink.streaming.runtime.tasks.OperatorChain.closeOperators(OperatorChain.java:299) > 2020-04-25T00:41:01.4651021Z at > org.apache.flink.streaming.runtime.tasks.StreamTask.afterInvoke(StreamTask.java:514) > 2020-04-25T00:41:01.4651917Z at > org.apache.flink.streaming.runtime.tasks.StreamTask.invoke(StreamTask.java:493) > 2020-04-25T00:41:01.4652613Z at > org.apache.flink.runtime.taskmanager.Task.doRun(Task.java:720) > 2020-04-25T00:41:01.4653247Z at > org.apache.flink.runtime.taskmanager.Task.run(Task.java:544) > 2020-04-25T00:41:01.4653793Z at java.lang.Thread.run(Thread.java:748) > 2020-04-25T00:41:01.4654472Z Caused by: > org.apache.flink.util.FlinkRuntimeException: Committing one of transactions > failed, logging first encountered failure > 2020-04-25T00:41:01.4655416Z at > org.apache.flink.streaming.api.functions.sink.TwoPhaseCommitSinkFunction.notifyCheckpointComplete(TwoPhaseCommitSinkFunction.java:302) > 2020-04-25T00:41:01.4656411Z at > org.apache.flink.streaming.api.operators.AbstractUdfStreamOperator.notifyCheckpointComplete(AbstractUdfStreamOperator.java:130) > 2020-04-25T00:41:01.4657631Z at > org.apache.flink.streaming.runtime.tasks.StreamTask.notifyCheckpointComplete(StreamTask.java:877) > 2020-04-25T00:41:01.4658241Z ... 17 more > 2020-04-25T00:41:01.4658665Z Caused by: java.lang.IllegalStateException: The > producer has already been closed > 2020-04-25T00:41:01.4659475Z at > org.apache.flink.streaming.connectors.kafka.internal.FlinkKafkaInternalProducer.ensureNotClosed(FlinkKafkaInternalProducer.java:251) > 2020-04-25T00:41:01.4660516Z at > org.apache.flink.streaming.connectors.kafka.internal.FlinkKafkaInternalProducer.commitTransaction(FlinkKafkaInternalProducer.java:102) > 2020-04-25T00:41:01.4661411Z at > org.apache.flink.streaming.connectors.kafka.FlinkKafkaProducer.commit(FlinkKafkaProducer.java:906) > 2020-04-25T00:41:01.4662267Z at > org.apache.flink.streaming.connectors.kafka.FlinkKafkaProducer.commit(FlinkKafkaProducer.java:98) > 2020-04-25T00:41:01.4663188Z at > org.apache.flink.streaming.api.functions.sink.TwoPhaseCommitSinkFunction.notifyCheckpointComplete(TwoPhaseCommitSinkFunction.java:289) > 2020-04-25T00:41:01.4663838Z ... 19 more > 2020-04-25T00:41:01.4665284Z 00:41:01,458 [ main] ERROR > org.apache.flink.streaming.connectors.kafka.KafkaProducerExactlyOnceITCase [] > - > 2020-04-25T00:41:01.4666356Z > -------------------------------------------------------------------------------- > 2020-04-25T00:41:01.4667329Z Test > testExactlyOnceCustomOperator(org.apache.flink.streaming.connectors.kafka.KafkaProducerExactlyOnceITCase) > failed with: > 2020-04-25T00:41:01.4668247Z java.lang.AssertionError: Test failed: Job > execution failed. > 2020-04-25T00:41:01.4668808Z at org.junit.Assert.fail(Assert.java:88) > 2020-04-25T00:41:01.4669370Z at > org.apache.flink.test.util.TestUtils.tryExecute(TestUtils.java:45) > 2020-04-25T00:41:01.4670189Z at > org.apache.flink.streaming.connectors.kafka.KafkaProducerTestBase.testExactlyOnce(KafkaProducerTestBase.java:370) > 2020-04-25T00:41:01.4671165Z at > org.apache.flink.streaming.connectors.kafka.KafkaProducerTestBase.testExactlyOnceCustomOperator(KafkaProducerTestBase.java:317) > 2020-04-25T00:41:01.4671937Z at > sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > 2020-04-25T00:41:01.4672588Z at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) > 2020-04-25T00:41:01.4673367Z at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > 2020-04-25T00:41:01.4674015Z at > java.lang.reflect.Method.invoke(Method.java:498) > 2020-04-25T00:41:01.4674710Z at > org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) > 2020-04-25T00:41:01.4675487Z at > org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) > 2020-04-25T00:41:01.4676243Z at > org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) > 2020-04-25T00:41:01.4677086Z at > org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) > 2020-04-25T00:41:01.4678089Z at > org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55) > 2020-04-25T00:41:01.4678627Z at > org.junit.rules.RunRules.evaluate(RunRules.java:20) > 2020-04-25T00:41:01.4679181Z at > org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > 2020-04-25T00:41:01.4680022Z at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) > 2020-04-25T00:41:01.4680757Z at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) > 2020-04-25T00:41:01.4681448Z at > org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > 2020-04-25T00:41:01.4682049Z at > org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > 2020-04-25T00:41:01.4682685Z at > org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > 2020-04-25T00:41:01.4683350Z at > org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > 2020-04-25T00:41:01.4683979Z at > org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > 2020-04-25T00:41:01.4684689Z at > org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) > 2020-04-25T00:41:01.4685394Z at > org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) > 2020-04-25T00:41:01.4686080Z at > org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48) > 2020-04-25T00:41:01.4686777Z at > org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48) > 2020-04-25T00:41:01.4687709Z at > org.junit.rules.RunRules.evaluate(RunRules.java:20) > 2020-04-25T00:41:01.4688285Z at > org.junit.runners.ParentRunner.run(ParentRunner.java:363) > 2020-04-25T00:41:01.4688971Z at > org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365) > 2020-04-25T00:41:01.4689746Z at > org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273) > 2020-04-25T00:41:01.4690555Z at > org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238) > 2020-04-25T00:41:01.4691322Z at > org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159) > 2020-04-25T00:41:01.4692137Z at > org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384) > 2020-04-25T00:41:01.4692975Z at > org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345) > 2020-04-25T00:41:01.4693685Z at > org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126) > 2020-04-25T00:41:01.4694344Z at > org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418) > 2020-04-25T00:41:01.4694736Z > {code} -- This message was sent by Atlassian Jira (v8.3.4#803005)