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

Fix random in TestSetPropertiesAction

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 10.3-SNAPSHOT
    • Fix Version/s: 10.10
    • Component/s: Bulk
    • Tags:
    • Sprint:
      nxcore 10.10.4
    • Story Points:
      1

      Description

      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]
      

        Attachments

          Activity

            People

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

              Dates

              • Created:
                Updated:
                Resolved:

                Time Tracking

                Estimated:
                Original Estimate - Not Specified
                Not Specified
                Remaining:
                Remaining Estimate - 0 minutes
                0m
                Logged:
                Time Spent - 1 day
                1d