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

Fix random RestESDocumentsTest#iCanQueryESQLPageProviderAndFetchVariousAggregates failure

    XMLWordPrintable

    Details

    • Team:
      PLATFORM
    • Sprint:
      nxplatform #78
    • Story Points:
      1

      Description

      Seen in https://jenkins.platform.dev.nuxeo.com/blue/organizations/jenkins/nuxeo%2Flts%2Fnuxeo/detail/PR-775/13/pipeline/:

      [2023-01-05T10:10:46.487Z] [ERROR] Tests run: 5, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 23.675 s <<< FAILURE! - in org.nuxeo.elasticsearch.test.rest.RestESDocumentsTest
      
      [2023-01-05T10:10:46.487Z] [ERROR] iCanQueryESQLPageProviderAndFetchVariousAggregates(org.nuxeo.elasticsearch.test.rest.RestESDocumentsTest)  Time elapsed: 1.506 s  <<< ERROR!
      
      [2023-01-05T10:10:46.487Z] org.nuxeo.runtime.transaction.TransactionRuntimeException: Unable to commit: transaction marked for rollback
      
      [2023-01-05T10:10:46.487Z] 	at org.nuxeo.runtime.transaction.TransactionHelper.commitOrRollbackTransaction(TransactionHelper.java:443)
      
      [2023-01-05T10:10:46.487Z] 	at org.nuxeo.elasticsearch.test.rest.RestESDocumentsTest.iCanQueryESQLPageProviderAndFetchVariousAggregates(RestESDocumentsTest.java:315)
      
      [2023-01-05T10:10:46.487Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      
      [2023-01-05T10:10:46.487Z] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      
      [2023-01-05T10:10:46.487Z] 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      
      [2023-01-05T10:10:46.487Z] 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
      
      [2023-01-05T10:10:46.487Z] 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
      
      [2023-01-05T10:10:46.487Z] 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
      
      [2023-01-05T10:10:46.487Z] 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
      
      [2023-01-05T10:10:46.487Z] 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
      
      [2023-01-05T10:10:46.487Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeMethodRunStatement.evaluate(FeaturesRunner.java:457)
      
      [2023-01-05T10:10:46.487Z] 	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
      
      [2023-01-05T10:10:46.487Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeSetupStatement.evaluate(FeaturesRunner.java:471)
      
      [2023-01-05T10:10:46.487Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner.evaluateRunnable(FeaturesRunner.java:328)
      
      [2023-01-05T10:10:46.487Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterMethodRunStatement.evaluate(FeaturesRunner.java:493)
      
      [2023-01-05T10:10:46.487Z] 	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
      
      [2023-01-05T10:10:46.487Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner.evaluateRunnable(FeaturesRunner.java:328)
      
      [2023-01-05T10:10:46.487Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterTeardownStatement.evaluate(FeaturesRunner.java:506)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$RulesFactory$1.evaluate(FeaturesRunner.java:576)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.runtime.test.runner.RuntimeDeployment$DeploymentStatement.evaluate(RuntimeDeployment.java:303)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterClassStatement.evaluate(FeaturesRunner.java:404)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$RulesFactory$1.evaluate(FeaturesRunner.java:576)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeClassStatement.evaluate(FeaturesRunner.java:387)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.Suite.runChild(Suite.java:128)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.Suite.runChild(Suite.java:27)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
      
      [2023-01-05T10:10:46.488Z] 	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:107)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:83)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:158)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
      
      [2023-01-05T10:10:46.488Z] Caused by: javax.transaction.RollbackException: Unable to commit: transaction marked for rollback
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.geronimo.transaction.manager.TransactionImpl.commit(TransactionImpl.java:294)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.geronimo.transaction.manager.TransactionManagerImpl.commit(TransactionManagerImpl.java:252)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.runtime.jtajca.NuxeoContainer$UserTransactionImpl.commit(NuxeoContainer.java:418)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.runtime.transaction.TransactionHelper.commitOrRollbackTransaction(TransactionHelper.java:428)
      
      [2023-01-05T10:10:46.488Z] 	... 54 more
      
      [2023-01-05T10:10:46.488Z] Caused by: org.apache.geronimo.transaction.manager.SetRollbackOnlyException: setRollbackOnly() called.  See stacktrace for origin
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.geronimo.transaction.manager.TransactionImpl.setRollbackOnly(TransactionImpl.java:147)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.geronimo.transaction.manager.TransactionManagerImpl.setRollbackOnly(TransactionManagerImpl.java:243)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.runtime.jtajca.NuxeoContainer$UserTransactionImpl.setRollbackOnly(NuxeoContainer.java:358)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.runtime.transaction.TransactionHelper.setTransactionRollbackOnly(TransactionHelper.java:531)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.ecm.core.storage.sql.SessionImpl.end(SessionImpl.java:1262)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.ecm.core.storage.sql.coremodel.SQLSession.end(SQLSession.java:870)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.ecm.core.repository.RepositoryService$SessionSynchronization.beforeCompletion(RepositoryService.java:344)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.geronimo.transaction.manager.TransactionImpl.beforeCompletion(TransactionImpl.java:549)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.geronimo.transaction.manager.TransactionImpl.beforeCompletion(TransactionImpl.java:533)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.geronimo.transaction.manager.TransactionImpl.beforePrepare(TransactionImpl.java:435)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.geronimo.transaction.manager.TransactionImpl.commit(TransactionImpl.java:283)
      
      [2023-01-05T10:10:46.488Z] 	... 57 more
      
      [2023-01-05T10:10:46.488Z] Caused by: org.nuxeo.ecm.core.api.ConcurrentUpdateException: Concurrent update
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCConnection.checkConcurrentUpdate(JDBCConnection.java:172)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCRowMapper.insertSimpleRows(JDBCRowMapper.java:543)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCRowMapper.writeCreates(JDBCRowMapper.java:454)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCRowMapper.write(JDBCRowMapper.java:431)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.ecm.core.storage.sql.SoftRefCachingRowMapper.write(SoftRefCachingRowMapper.java:364)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.ecm.core.storage.sql.SessionImpl.doFlush(SessionImpl.java:277)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.ecm.core.storage.sql.SessionImpl.flush(SessionImpl.java:249)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.ecm.core.storage.sql.SessionImpl.end(SessionImpl.java:1260)
      
      [2023-01-05T10:10:46.488Z] 	... 63 more
      
      [2023-01-05T10:10:46.488Z] Caused by: java.sql.BatchUpdateException: Batch entry 98 INSERT INTO "hierarchy" ("id", "parentid", "pos", "name", "isproperty", "primarytype", "mixintypes", "ischeckedin", "baseversionid", "majorversion", "minorversion", "isversion", "isrecord", "retainuntil", "haslegalhold", "isretentionactive", "istrashed", "systemchangetoken", "changetoken") VALUES ('c3f408bc-35fb-405f-a585-de2b69aba578', '3fa99065-601f-4c86-94f8-a1be2ee8b46b', NULL, 'aggTest1.1672913438150', 'FALSE', 'File', NULL, NULL, NULL, 0, 0, NULL, NULL, NULL, NULL, NULL, NULL, 0, 0) was aborted: ERROR: duplicate key value violates unique constraint "hierarchy_unique_child"
      
      [2023-01-05T10:10:46.488Z]   Detail: Key (parentid, name)=(3fa99065-601f-4c86-94f8-a1be2ee8b46b, aggTest1.1672913438150) already exists.  Call getNextException to see other errors in the batch.
      
      [2023-01-05T10:10:46.488Z] 	at org.postgresql.jdbc.BatchResultHandler.handleError(BatchResultHandler.java:165)
      
      [2023-01-05T10:10:46.488Z] 	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2366)
      
      [2023-01-05T10:10:46.488Z] 	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:559)
      
      [2023-01-05T10:10:46.488Z] 	at org.postgresql.jdbc.PgStatement.internalExecuteBatch(PgStatement.java:887)
      
      [2023-01-05T10:10:46.488Z] 	at org.postgresql.jdbc.PgStatement.executeBatch(PgStatement.java:910)
      
      [2023-01-05T10:10:46.488Z] 	at org.postgresql.jdbc.PgPreparedStatement.executeBatch(PgPreparedStatement.java:1649)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.commons.dbcp2.DelegatingStatement.executeBatch(DelegatingStatement.java:242)
      
      [2023-01-05T10:10:46.488Z] 	at org.apache.commons.dbcp2.DelegatingStatement.executeBatch(DelegatingStatement.java:242)
      
      [2023-01-05T10:10:46.488Z] 	at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCRowMapper.insertSimpleRows(JDBCRowMapper.java:527)
      
      [2023-01-05T10:10:46.488Z] 	... 69 more
      
      [2023-01-05T10:10:46.488Z] Caused by: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "hierarchy_unique_child"
      
      [2023-01-05T10:10:46.488Z]   Detail: Key (parentid, name)=(3fa99065-601f-4c86-94f8-a1be2ee8b46b, aggTest1.1672913438150) already exists.
      
      [2023-01-05T10:10:46.488Z] 	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2675)
      
      [2023-01-05T10:10:46.488Z] 	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2365)
      
      [2023-01-05T10:10:46.488Z] 	... 76 more
      

      It is a concurrent insert with the same doc name:

      [2023-01-05T10:10:46.488Z] Caused by: java.sql.BatchUpdateException: Batch entry 98 INSERT INTO "hierarchy" ("id", "parentid", "pos", "name", "isproperty", "primarytype", "mixintypes", "ischeckedin", "baseversionid", "majorversion", "minorversion", "isversion", "isrecord", "retainuntil", "haslegalhold", "isretentionactive", "istrashed", "systemchangetoken", "changetoken") VALUES ('c3f408bc-35fb-405f-a585-de2b69aba578', '3fa99065-601f-4c86-94f8-a1be2ee8b46b', NULL, 'aggTest1.1672913438150', 'FALSE', 'File', NULL, NULL, NULL, 0, 0, NULL, NULL, NULL, NULL, NULL, NULL, 0, 0) was aborted: ERROR: duplicate key value violates unique constraint "hierarchy_unique_child"
      

        Attachments

          Activity

            People

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

              Dates

              • Created:
                Updated:
                Resolved: