This random shows a leaked session detected in the feature runner and close it.
But the session was used by the Bulk Scroller computation and the computation complains with the warn that someone else closed the session.
This means that async processing is still running while we go into the test teardown.
org.nuxeo.ecm.core.bulk.TestSetPropertiesAction.org.nuxeo.ecm.core.bulk.TestSetPropertiesAction Failing for the past 1 build (Since Failed#1153 ) Took 0.6 sec. add description This test was not claimed. Claim it. Error Message invoke on features error [Holder [type=class org.nuxeo.ecm.core.test.CoreFeature], Holder [type=class org.nuxeo.ecm.core.bulk.CoreBulkFeature], Holder [type=class org.nuxeo.ecm.core.io.CoreIOFeature], Holder [type=class org.nuxeo.ecm.core.work.WorkManagerFeature], Holder [type=class org.nuxeo.runtime.stream.RuntimeStreamFeature], Holder [type=class org.nuxeo.runtime.test.runner.TransactionalFeature], Holder [type=class org.nuxeo.runtime.test.runner.RuntimeFeature], Holder [type=class org.nuxeo.runtime.test.runner.RandomBug$Feature], Holder [type=class org.nuxeo.runtime.test.runner.ConditionalIgnoreRule$Feature], Holder [type=class org.nuxeo.runtime.test.runner.MDCFeature]] Stacktrace java.lang.AssertionError: invoke on features error [Holder [type=class org.nuxeo.ecm.core.test.CoreFeature], Holder [type=class org.nuxeo.ecm.core.bulk.CoreBulkFeature], Holder [type=class org.nuxeo.ecm.core.io.CoreIOFeature], Holder [type=class org.nuxeo.ecm.core.work.WorkManagerFeature], Holder [type=class org.nuxeo.runtime.stream.RuntimeStreamFeature], Holder [type=class org.nuxeo.runtime.test.runner.TransactionalFeature], Holder [type=class org.nuxeo.runtime.test.runner.RuntimeFeature], Holder [type=class org.nuxeo.runtime.test.runner.RandomBug$Feature], Holder [type=class org.nuxeo.runtime.test.runner.ConditionalIgnoreRule$Feature], Holder [type=class org.nuxeo.runtime.test.runner.MDCFeature]] at org.nuxeo.runtime.test.runner.FeaturesLoader.apply(FeaturesLoader.java:123) at org.nuxeo.runtime.test.runner.FeaturesLoader.apply(FeaturesLoader.java:113) at org.nuxeo.runtime.test.runner.FeaturesRunner.afterRun(FeaturesRunner.java:167) at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterClassStatement.evaluate(FeaturesRunner.java:237) at org.nuxeo.runtime.test.runner.FeaturesRunner$RulesFactory$1.evaluate(FeaturesRunner.java:429) at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeClassStatement.evaluate(FeaturesRunner.java:218) ... Suppressed: java.lang.AssertionError: leaked 1 sessions at org.nuxeo.ecm.core.test.CoreFeature.afterRun(CoreFeature.java:212) at org.nuxeo.runtime.test.runner.FeaturesRunner.lambda$afterRun$4(FeaturesRunner.java:167) at org.nuxeo.runtime.test.runner.FeaturesLoader.apply(FeaturesLoader.java:126) ... 25 more Suppressed: org.nuxeo.ecm.core.api.CoreSessionService$CoreSessionRegistrationInfo: DEBUG: opening stacktrace, sessionId=test/Administrator#500, thread=scrollerPool-00,in:1,inCheckpoint:1,out:1,lastRead:1543369143468,lastTimer:0,wm:202292480369491969,loop:3,checkpoint at org.nuxeo.ecm.core.api.CoreSessionServiceImpl.createCoreSession(CoreSessionServiceImpl.java:57) at org.nuxeo.ecm.core.api.CoreInstance.openCoreSession(CoreInstance.java:112) at org.nuxeo.ecm.core.api.CoreInstance.openCoreSession(CoreInstance.java:53) at org.nuxeo.ecm.core.bulk.computation.BulkScrollerComputation.processRecord(BulkScrollerComputation.java:130) at org.nuxeo.ecm.core.bulk.computation.BulkScrollerComputation.lambda$processRecord$0(BulkScrollerComputation.java:106) at org.nuxeo.runtime.transaction.TransactionHelper.lambda$runInTransaction$3(TransactionHelper.java:569) at org.nuxeo.runtime.transaction.TransactionHelper.runInTransaction(TransactionHelper.java:589) at org.nuxeo.runtime.transaction.TransactionHelper.runInTransaction(TransactionHelper.java:569) at org.nuxeo.ecm.core.bulk.computation.BulkScrollerComputation.processRecord(BulkScrollerComputation.java:106) at org.nuxeo.lib.stream.computation.log.ComputationRunner.lambda$processRecordWithRetry$10(ComputationRunner.java:313) at net.jodah.failsafe.Functions$10.call(Functions.java:252) at net.jodah.failsafe.SyncFailsafe.call(SyncFailsafe.java:145) at net.jodah.failsafe.SyncFailsafe.run(SyncFailsafe.java:81) at org.nuxeo.lib.stream.computation.log.ComputationRunner.processRecordWithRetry(ComputationRunner.java:313) at org.nuxeo.lib.stream.computation.log.ComputationRunner.processRecord(ComputationRunner.java:298) at org.nuxeo.lib.stream.computation.log.ComputationRunner.processLoop(ComputationRunner.java:199) at org.nuxeo.lib.stream.computation.log.ComputationRunner.run(ComputationRunner.java:158) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Suppressed: java.lang.Exception: DEBUG: closing stacktrace, sessionId=test/Administrator#500, thread=main at org.nuxeo.ecm.core.api.CoreSessionServiceImpl.releaseCoreSession(CoreSessionServiceImpl.java:81) at org.nuxeo.ecm.core.api.CoreInstance.closeCoreSession(CoreInstance.java:133) at org.nuxeo.ecm.core.api.local.LocalSession.close(LocalSession.java:154) at org.nuxeo.ecm.core.test.CoreFeature.afterRun(CoreFeature.java:215) at org.nuxeo.runtime.test.runner.FeaturesRunner.lambda$afterRun$4(FeaturesRunner.java:167) at org.nuxeo.runtime.test.runner.FeaturesLoader.apply(FeaturesLoader.java:126) at org.nuxeo.runtime.test.runner.FeaturesLoader.apply(FeaturesLoader.java:113) at org.nuxeo.runtime.test.runner.FeaturesRunner.afterRun(FeaturesRunner.java:167) at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterClassStatement.evaluate(FeaturesRunner.java:237) at org.nuxeo.runtime.test.runner.FeaturesRunner$RulesFactory$1.evaluate(FeaturesRunner.java:429) at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeClassStatement.evaluate(FeaturesRunner.java:218) at org.junit.rules.RunRules.evaluate(RunRules.java:20) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at org.junit.runners.Suite.runChild(Suite.java:128) at org.junit.runners.Suite.runChild(Suite.java:27) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55) at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137) at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:107) at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:83) at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75) at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:158) at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:383) at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:344) at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:125) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:417)
std output
2018-11-28 01:39:05,737 [scrollerPool-00,in:1,inCheckpoint:1,out:1,lastRead:1543369143468,lastTimer:0,wm:202292480369491969,loop:3,checkpoint] WARN [CoreSessionServiceImpl] Closing already closed CoreSession java.lang.Exception: DEBUG: spurious closing stacktrace, sessionId=test/Administrator#500, thread=scrollerPool-00,in:1,inCheckpoint:1,out:1,lastRead:1543369143468,lastTimer:0,wm:202292480369491969,loop:3,checkpoint at org.nuxeo.ecm.core.api.CoreSessionServiceImpl.releaseCoreSession(CoreSessionServiceImpl.java:75) ~[nuxeo-core-10.10-I20181128_0125.jar:?] at org.nuxeo.ecm.core.api.CoreInstance.closeCoreSession(CoreInstance.java:133) ~[nuxeo-core-api-10.10-I20181128_0125.jar:?] at org.nuxeo.ecm.core.api.local.LocalSession.close(LocalSession.java:154) ~[nuxeo-core-10.10-I20181128_0125.jar:?] at org.nuxeo.ecm.core.bulk.computation.BulkScrollerComputation.processRecord(BulkScrollerComputation.java:155) ~[nuxeo-core-bulk-10.10-I20181128_0125.jar:?] at org.nuxeo.ecm.core.bulk.computation.BulkScrollerComputation.lambda$processRecord$0(BulkScrollerComputation.java:106) ~[nuxeo-core-bulk-10.10-I20181128_0125.jar:?] at org.nuxeo.runtime.transaction.TransactionHelper.lambda$runInTransaction$3(TransactionHelper.java:569) ~[nuxeo-runtime-jtajca-10.10-I20181128_0125.jar:?] at org.nuxeo.runtime.transaction.TransactionHelper.runInTransaction(TransactionHelper.java:589) ~[nuxeo-runtime-jtajca-10.10-I20181128_0125.jar:?] at org.nuxeo.runtime.transaction.TransactionHelper.runInTransaction(TransactionHelper.java:569) ~[nuxeo-runtime-jtajca-10.10-I20181128_0125.jar:?] at org.nuxeo.ecm.core.bulk.computation.BulkScrollerComputation.processRecord(BulkScrollerComputation.java:106) ~[nuxeo-core-bulk-10.10-I20181128_0125.jar:?] at org.nuxeo.lib.stream.computation.log.ComputationRunner.lambda$processRecordWithRetry$10(ComputationRunner.java:313) ~[nuxeo-stream-10.10-I20181128_0125.jar:?] at net.jodah.failsafe.Functions$10.call(Functions.java:252) [failsafe-1.1.0.jar:1.1.0] at net.jodah.failsafe.SyncFailsafe.call(SyncFailsafe.java:145) [failsafe-1.1.0.jar:1.1.0] at net.jodah.failsafe.SyncFailsafe.run(SyncFailsafe.java:81) [failsafe-1.1.0.jar:1.1.0] at org.nuxeo.lib.stream.computation.log.ComputationRunner.processRecordWithRetry(ComputationRunner.java:313) [nuxeo-stream-10.10-I20181128_0125.jar:?] at org.nuxeo.lib.stream.computation.log.ComputationRunner.processRecord(ComputationRunner.java:298) [nuxeo-stream-10.10-I20181128_0125.jar:?] at org.nuxeo.lib.stream.computation.log.ComputationRunner.processLoop(ComputationRunner.java:199) [nuxeo-stream-10.10-I20181128_0125.jar:?] at org.nuxeo.lib.stream.computation.log.ComputationRunner.run(ComputationRunner.java:158) [nuxeo-stream-10.10-I20181128_0125.jar:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_191] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_191] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_191] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_191] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191] Suppressed: org.nuxeo.ecm.core.api.CoreSessionService$CoreSessionRegistrationInfo: DEBUG: opening stacktrace, sessionId=test/Administrator#500, thread=scrollerPool-00,in:1,inCheckpoint:1,out:1,lastRead:1543369143468,lastTimer:0,wm:202292480369491969,loop:3,checkpoint at org.nuxeo.ecm.core.api.CoreSessionServiceImpl.createCoreSession(CoreSessionServiceImpl.java:57) ~[nuxeo-core-10.10-I20181128_0125.jar:?] at org.nuxeo.ecm.core.api.CoreInstance.openCoreSession(CoreInstance.java:112) ~[nuxeo-core-api-10.10-I20181128_0125.jar:?] at org.nuxeo.ecm.core.api.CoreInstance.openCoreSession(CoreInstance.java:53) ~[nuxeo-core-api-10.10-I20181128_0125.jar:?] at org.nuxeo.ecm.core.bulk.computation.BulkScrollerComputation.processRecord(BulkScrollerComputation.java:130) ~[nuxeo-core-bulk-10.10-I20181128_0125.jar:?] at org.nuxeo.ecm.core.bulk.computation.BulkScrollerComputation.lambda$processRecord$0(BulkScrollerComputation.java:106) ~[nuxeo-core-bulk-10.10-I20181128_0125.jar:?] at org.nuxeo.runtime.transaction.TransactionHelper.lambda$runInTransaction$3(TransactionHelper.java:569) ~[nuxeo-runtime-jtajca-10.10-I20181128_0125.jar:?] at org.nuxeo.runtime.transaction.TransactionHelper.runInTransaction(TransactionHelper.java:589) ~[nuxeo-runtime-jtajca-10.10-I20181128_0125.jar:?] at org.nuxeo.runtime.transaction.TransactionHelper.runInTransaction(TransactionHelper.java:569) ~[nuxeo-runtime-jtajca-10.10-I20181128_0125.jar:?] at org.nuxeo.ecm.core.bulk.computation.BulkScrollerComputation.processRecord(BulkScrollerComputation.java:106) ~[nuxeo-core-bulk-10.10-I20181128_0125.jar:?] at org.nuxeo.lib.stream.computation.log.ComputationRunner.lambda$processRecordWithRetry$10(ComputationRunner.java:313) ~[nuxeo-stream-10.10-I20181128_0125.jar:?] at net.jodah.failsafe.Functions$10.call(Functions.java:252) [failsafe-1.1.0.jar:1.1.0] at net.jodah.failsafe.SyncFailsafe.call(SyncFailsafe.java:145) [failsafe-1.1.0.jar:1.1.0] at net.jodah.failsafe.SyncFailsafe.run(SyncFailsafe.java:81) [failsafe-1.1.0.jar:1.1.0] at org.nuxeo.lib.stream.computation.log.ComputationRunner.processRecordWithRetry(ComputationRunner.java:313) [nuxeo-stream-10.10-I20181128_0125.jar:?] at org.nuxeo.lib.stream.computation.log.ComputationRunner.processRecord(ComputationRunner.java:298) [nuxeo-stream-10.10-I20181128_0125.jar:?] at org.nuxeo.lib.stream.computation.log.ComputationRunner.processLoop(ComputationRunner.java:199) [nuxeo-stream-10.10-I20181128_0125.jar:?] at org.nuxeo.lib.stream.computation.log.ComputationRunner.run(ComputationRunner.java:158) [nuxeo-stream-10.10-I20181128_0125.jar:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_191] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_191] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_191] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_191] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191] Suppressed: java.lang.Exception: DEBUG: closing stacktrace, sessionId=test/Administrator#500, thread=main at org.nuxeo.ecm.core.api.CoreSessionServiceImpl.releaseCoreSession(CoreSessionServiceImpl.java:81) ~[nuxeo-core-10.10-I20181128_0125.jar:?] at org.nuxeo.ecm.core.api.CoreInstance.closeCoreSession(CoreInstance.java:133) ~[nuxeo-core-api-10.10-I20181128_0125.jar:?] at org.nuxeo.ecm.core.api.local.LocalSession.close(LocalSession.java:154) ~[nuxeo-core-10.10-I20181128_0125.jar:?] at org.nuxeo.ecm.core.test.CoreFeature.afterRun(CoreFeature.java:215) ~[classes/:?] at org.nuxeo.runtime.test.runner.FeaturesRunner.lambda$afterRun$4(FeaturesRunner.java:167) ~[nuxeo-runtime-test-10.10-I20181128_0125.jar:?] at org.nuxeo.runtime.test.runner.FeaturesLoader.apply(FeaturesLoader.java:126) ~[nuxeo-runtime-test-10.10-I20181128_0125.jar:?] at org.nuxeo.runtime.test.runner.FeaturesLoader.apply(FeaturesLoader.java:113) ~[nuxeo-runtime-test-10.10-I20181128_0125.jar:?] at org.nuxeo.runtime.test.runner.FeaturesRunner.afterRun(FeaturesRunner.java:167) ~[nuxeo-runtime-test-10.10-I20181128_0125.jar:?] at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterClassStatement.evaluate(FeaturesRunner.java:237) ~[nuxeo-runtime-test-10.10-I20181128_0125.jar:?] at org.nuxeo.runtime.test.runner.FeaturesRunner$RulesFactory$1.evaluate(FeaturesRunner.java:429) ~[nuxeo-runtime-test-10.10-I20181128_0125.jar:?] at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeClassStatement.evaluate(FeaturesRunner.java:218) ~[nuxeo-runtime-test-10.10-I20181128_0125.jar:?] at org.junit.rules.RunRules.evaluate(RunRules.java:20) ~[junit-4.12.jar:4.12] at org.junit.runners.ParentRunner.run(ParentRunner.java:363) ~[junit-4.12.jar:4.12] at org.junit.runners.Suite.runChild(Suite.java:128) ~[junit-4.12.jar:4.12] at org.junit.runners.Suite.runChild(Suite.java:27) ~[junit-4.12.jar:4.12] at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) ~[junit-4.12.jar:4.12] at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) ~[junit-4.12.jar:4.12] at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) ~[junit-4.12.jar:4.12] at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) ~[junit-4.12.jar:4.12] at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) ~[junit-4.12.jar:4.12] at org.junit.runners.ParentRunner.run(ParentRunner.java:363) ~[junit-4.12.jar:4.12] at org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55) ~[surefire-junit47-2.22.0.jar:2.22.0] at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137) ~[surefire-junit47-2.22.0.jar:2.22.0] at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:107) ~[surefire-junit47-2.22.0.jar:2.22.0] at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:83) ~[surefire-junit47-2.22.0.jar:2.22.0] at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75) ~[surefire-junit47-2.22.0.jar:2.22.0] at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:158) ~[surefire-junit47-2.22.0.jar:2.22.0] at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:383) ~[surefire-booter-2.22.0.jar:2.22.0] at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:344) ~[surefire-booter-2.22.0.jar:2.22.0] at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:125) ~[surefire-booter-2.22.0.jar:2.22.0] at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:417) ~[surefire-booter-2.22.0.jar:2.22.0]