Uploaded image for project: 'Nuxeo Platform'
  1. Nuxeo Platform
  2. NXP-28983

Fix CanMonitorTransactionsTest.logContainsTxKey randomy failing

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Minor
    • Resolution: Cannot Reproduce
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: CI/CD

      Description

      Seen https://jenkins.platform.dev.nuxeo.com/job/nuxeo/job/nuxeo/job/PR-3930/35/

      [2020-04-23T03:10:56.144Z] [INFO] Running org.nuxeo.ecm.core.management.jtajca.CanMonitorTransactionsTest
      [2020-04-23T03:10:57.081Z] 2020-04-23 03:10:57,063 [main] WARN  [ComputationPool] bulk/setSystemProperties: Timeout on wait for pool termination
      [2020-04-23T03:10:57.081Z] 2020-04-23 03:10:57,063 [bulk/setSystemPropertiesPool-01,in:0,inCheckpoint:0,out:0,lastRead:1587611455804,lastTimer:0,wm:0,loop:1,rebalance revoked] ERROR [KafkaConsumer] [Consumer clientId=nuxeo-test-1587611437797-bulk-setSystemProperties-85, groupId=nuxeo-test-1587611437797-bulk-setSystemProperties] Failed to close coordinator
      [2020-04-23T03:10:57.082Z] org.apache.kafka.common.errors.InterruptException: java.lang.InterruptedException
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.maybeThrowInterruptException(ConsumerNetworkClient.java:496) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:278) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:233) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:224) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.awaitPendingRequests(ConsumerNetworkClient.java:314) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.AbstractCoordinator.close(AbstractCoordinator.java:861) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.close(ConsumerCoordinator.java:590) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.KafkaConsumer.close(KafkaConsumer.java:2208) [kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.KafkaConsumer.close(KafkaConsumer.java:2176) [kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.KafkaConsumer.close(KafkaConsumer.java:2127) [kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.nuxeo.lib.stream.log.kafka.KafkaLogTailer.close(KafkaLogTailer.java:416) [nuxeo-stream-PR-3930-11.1-SNAPSHOT.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.nuxeo.lib.stream.computation.log.ComputationRunner.closeTailer(ComputationRunner.java:248) [nuxeo-stream-PR-3930-11.1-SNAPSHOT.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.nuxeo.lib.stream.computation.log.ComputationRunner.run(ComputationRunner.java:214) [nuxeo-stream-PR-3930-11.1-SNAPSHOT.jar:?]
      [2020-04-23T03:10:57.082Z] 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
      [2020-04-23T03:10:57.082Z] 	at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
      [2020-04-23T03:10:57.082Z] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
      [2020-04-23T03:10:57.082Z] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
      [2020-04-23T03:10:57.082Z] 	at java.lang.Thread.run(Thread.java:834) [?:?]
      [2020-04-23T03:10:57.082Z] Caused by: java.lang.InterruptedException
      [2020-04-23T03:10:57.082Z] 	... 18 more
      [2020-04-23T03:10:57.082Z] 2020-04-23 03:10:57,065 [bulk/setSystemPropertiesPool-00,in:0,inCheckpoint:0,out:0,lastRead:1587611455803,lastTimer:0,wm:0,loop:1,rebalance revoked] ERROR [KafkaConsumer] [Consumer clientId=nuxeo-test-1587611437797-bulk-setSystemProperties-84, groupId=nuxeo-test-1587611437797-bulk-setSystemProperties] Failed to close coordinator
      [2020-04-23T03:10:57.082Z] org.apache.kafka.common.errors.InterruptException: java.lang.InterruptedException
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.maybeThrowInterruptException(ConsumerNetworkClient.java:496) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:278) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:233) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:224) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.awaitPendingRequests(ConsumerNetworkClient.java:314) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.AbstractCoordinator.close(AbstractCoordinator.java:861) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.close(ConsumerCoordinator.java:590) ~[kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.KafkaConsumer.close(KafkaConsumer.java:2208) [kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.KafkaConsumer.close(KafkaConsumer.java:2176) [kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.apache.kafka.clients.consumer.KafkaConsumer.close(KafkaConsumer.java:2127) [kafka-clients-2.3.1.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.nuxeo.lib.stream.log.kafka.KafkaLogTailer.close(KafkaLogTailer.java:416) [nuxeo-stream-PR-3930-11.1-SNAPSHOT.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.nuxeo.lib.stream.computation.log.ComputationRunner.closeTailer(ComputationRunner.java:248) [nuxeo-stream-PR-3930-11.1-SNAPSHOT.jar:?]
      [2020-04-23T03:10:57.082Z] 	at org.nuxeo.lib.stream.computation.log.ComputationRunner.run(ComputationRunner.java:214) [nuxeo-stream-PR-3930-11.1-SNAPSHOT.jar:?]
      [2020-04-23T03:10:57.082Z] 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
      [2020-04-23T03:10:57.082Z] 	at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
      [2020-04-23T03:10:57.082Z] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
      [2020-04-23T03:10:57.082Z] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
      [2020-04-23T03:10:57.340Z] 	at java.lang.Thread.run(Thread.java:834) [?:?]
      [2020-04-23T03:10:57.340Z] Caused by: java.lang.InterruptedException
      [2020-04-23T03:10:57.340Z] 	... 18 more
      [2020-04-23T03:10:57.907Z] [ERROR] Tests run: 6, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 1.919 s <<< FAILURE! - in org.nuxeo.ecm.core.management.jtajca.CanMonitorTransactionsTest
      [2020-04-23T03:10:57.907Z] [ERROR] logContainsTxKey(org.nuxeo.ecm.core.management.jtajca.CanMonitorTransactionsTest)  Time elapsed: 0.03 s  <<< FAILURE!
      [2020-04-23T03:10:57.907Z] org.nuxeo.runtime.test.runner.LogCaptureFeature$NoLogCaptureFilterException
      [2020-04-23T03:10:57.907Z] 	at org.nuxeo.runtime.test.runner.LogCaptureFeature$Result.assertHasEvent(LogCaptureFeature.java:133)
      [2020-04-23T03:10:57.907Z] 	at org.nuxeo.ecm.core.management.jtajca.CanMonitorTransactionsTest.logContainsTxKey(CanMonitorTransactionsTest.java:220)
      [2020-04-23T03:10:57.907Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      [2020-04-23T03:10:57.907Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      [2020-04-23T03:10:57.907Z] 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      [2020-04-23T03:10:57.907Z] 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
      [2020-04-23T03:10:57.907Z] 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
      [2020-04-23T03:10:57.907Z] 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
      [2020-04-23T03:10:57.907Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeMethodRunStatement.evaluate(FeaturesRunner.java:308)
      [2020-04-23T03:10:57.907Z] 	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
      [2020-04-23T03:10:57.907Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeSetupStatement.evaluate(FeaturesRunner.java:322)
      [2020-04-23T03:10:57.907Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterMethodRunStatement.evaluate(FeaturesRunner.java:345)
      [2020-04-23T03:10:57.907Z] 	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
      [2020-04-23T03:10:57.907Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterTeardownStatement.evaluate(FeaturesRunner.java:362)
      [2020-04-23T03:10:57.907Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$RulesFactory$1.evaluate(FeaturesRunner.java:435)
      [2020-04-23T03:10:57.907Z] 	at org.nuxeo.runtime.test.runner.RuntimeDeployment$DeploymentStatement.evaluate(RuntimeDeployment.java:326)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
      [2020-04-23T03:10:57.907Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterClassStatement.evaluate(FeaturesRunner.java:251)
      [2020-04-23T03:10:57.907Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$RulesFactory$1.evaluate(FeaturesRunner.java:435)
      [2020-04-23T03:10:57.907Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeClassStatement.evaluate(FeaturesRunner.java:234)
      [2020-04-23T03:10:57.907Z] 	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.Suite.runChild(Suite.java:128)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.Suite.runChild(Suite.java:27)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
      [2020-04-23T03:10:57.907Z] 	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
      [2020-04-23T03:10:57.907Z] 	at org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55)
      [2020-04-23T03:10:57.907Z] 	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137)
      [2020-04-23T03:10:57.907Z] 	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:107)
      [2020-04-23T03:10:57.907Z] 	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:83)
      [2020-04-23T03:10:57.907Z] 	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75)
      [2020-04-23T03:10:57.907Z] 	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:158)
      [2020-04-23T03:10:57.907Z] 	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
      [2020-04-23T03:10:57.907Z] 	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
      [2020-04-23T03:10:57.907Z] 	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
      [2020-04-23T03:10:57.907Z] 	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
      

        Attachments

          Issue Links

            Activity

              People

              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: