You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@flink.apache.org by "Aljoscha Krettek (Jira)" <ji...@apache.org> on 2020/05/18 10:23:00 UTC

[jira] [Closed] (FLINK-17378) KafkaProducerExactlyOnceITCase>KafkaProducerTestBase.testExactlyOnceCustomOperator unstable

     [ https://issues.apache.org/jira/browse/FLINK-17378?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Aljoscha Krettek closed FLINK-17378.
------------------------------------
    Resolution: Duplicate

> KafkaProducerExactlyOnceITCase>KafkaProducerTestBase.testExactlyOnceCustomOperator unstable
> -------------------------------------------------------------------------------------------
>
>                 Key: FLINK-17378
>                 URL: https://issues.apache.org/jira/browse/FLINK-17378
>             Project: Flink
>          Issue Type: Bug
>          Components: Connectors / Kafka, Tests
>    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)