-
Type: Bug
-
Status: Resolved
-
Priority: Minor
-
Resolution: Cannot Reproduce
-
Affects Version/s: None
-
Fix Version/s: None
-
Component/s: CI/CD
-
Tags:
-
Team:PLATFORM
After NXP-28579 was merged we notice this random test on Jenkins X: TestSQLRepositoryFulltextWork.testFulltextWithConcurrentDelete
Let's see if it happens again and try to understand...
[INFO] Running org.nuxeo.ecm.core.TestSQLRepositoryFulltextWork [2020-03-02T15:16:06.892Z] RuntimeStreamFeature: Deploying Nuxeo Stream using Chronicle [2020-03-02T15:16:06.893Z] WorkManagerFeature: Deploying WorkManager using default implementation [2020-03-02T15:16:06.893Z] StorageConfiguration: Deploying JDBC using DatabasePostgreSQL [2020-03-02T15:16:06.893Z] StorageConfiguration: Deploying a VCS repository [2020-03-02T15:16:07.829Z] 2020-03-02 15:16:07,511 [main] WARN [TransientStorageComponent] Missing configuration for default transient store, using in-memory [2020-03-02T15:16:07.830Z] 2020-03-02 15:16:07,530 [main] ERROR [OSGiRuntimeService] Nuxeo Platform Started [2020-03-02T15:16:07.830Z] ====================================================================== [2020-03-02T15:16:07.830Z] = Component Loading Warnings: [2020-03-02T15:16:07.830Z] * Missing configuration for default transient store, using in-memory [2020-03-02T15:16:07.830Z] ====================================================================== [2020-03-02T15:16:07.830Z] = Component Loading Status: Pending: 0 / Missing: 1 / Unstarted: 0 / Total: 112 [2020-03-02T15:16:07.830Z] * service:org.nuxeo.runtime.stream.service.managment.contrib references missing [target=org.nuxeo.ecm.core.management.CoreManagementComponent;point=probes, target=org.nuxeo.ecm.core.management.CoreManagementComponent;point=healthCheck] [2020-03-02T15:16:07.830Z] ====================================================================== [2020-03-02T15:16:07.830Z] [ERROR] Tests run: 2, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 3.73 s <<< FAILURE! - in org.nuxeo.ecm.core.TestSQLRepositoryFulltextWork [2020-03-02T15:16:07.830Z] [ERROR] testFulltextWithConcurrentDelete(org.nuxeo.ecm.core.TestSQLRepositoryFulltextWork) Time elapsed: 1.251 s <<< ERROR! [2020-03-02T15:16:07.830Z] org.nuxeo.ecm.core.api.ConcurrentUpdateException: Failed to remove document e199f95d-18fe-477a-8396-b03a446c38c1, Concurrent update [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCConnection.checkConcurrentUpdate(JDBCConnection.java:183) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCRowMapper.deleteRowsDirect(JDBCRowMapper.java:829) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCRowMapper.remove(JDBCRowMapper.java:1262) [2020-03-02T15:16:07.830Z] at jdk.internal.reflect.GeneratedMethodAccessor28.invoke(Unknown Source) [2020-03-02T15:16:07.830Z] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [2020-03-02T15:16:07.830Z] at java.base/java.lang.reflect.Method.invoke(Method.java:566) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCMapperConnector.doInvoke(JDBCMapperConnector.java:111) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCMapperConnector.lambda$doConnectAndInvoke$0(JDBCMapperConnector.java:98) [2020-03-02T15:16:07.830Z] at org.nuxeo.runtime.transaction.TransactionHelper.runInTransaction(TransactionHelper.java:607) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCMapperConnector.doConnectAndInvoke(JDBCMapperConnector.java:95) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCMapperConnector.invoke(JDBCMapperConnector.java:84) [2020-03-02T15:16:07.830Z] at com.sun.proxy.$Proxy179.remove(Unknown Source) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.SoftRefCachingRowMapper.remove(SoftRefCachingRowMapper.java:449) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.PersistenceContext.removeNode(PersistenceContext.java:992) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.SessionImpl.removeNode(SessionImpl.java:1018) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.ra.ConnectionImpl.removeNode(ConnectionImpl.java:256) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.coremodel.SQLSession.remove(SQLSession.java:624) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.coremodel.SQLDocumentLive.remove(SQLDocumentLive.java:165) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.storage.sql.coremodel.SQLDocumentLive.remove(SQLDocumentLive.java:171) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.api.AbstractSession.removeNotifyOneDoc(AbstractSession.java:1431) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.api.AbstractSession.removeDocument(AbstractSession.java:1403) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.api.AbstractSession.removeDocument(AbstractSession.java:1393) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.TestSQLRepositoryFulltextWork.createAndDeleteFile(TestSQLRepositoryFulltextWork.java:84) [2020-03-02T15:16:07.830Z] at org.nuxeo.ecm.core.TestSQLRepositoryFulltextWork.testFulltextWithConcurrentDelete(TestSQLRepositoryFulltextWork.java:94) [2020-03-02T15:16:07.830Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [2020-03-02T15:16:07.830Z] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [2020-03-02T15:16:07.830Z] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [2020-03-02T15:16:07.830Z] at java.base/java.lang.reflect.Method.invoke(Method.java:566) [2020-03-02T15:16:07.830Z] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59) [2020-03-02T15:16:07.830Z] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [2020-03-02T15:16:07.830Z] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56) [2020-03-02T15:16:07.830Z] at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) [2020-03-02T15:16:07.830Z] at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeMethodRunStatement.evaluate(FeaturesRunner.java:308) [2020-03-02T15:16:07.830Z] at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeSetupStatement.evaluate(FeaturesRunner.java:322) [2020-03-02T15:16:07.830Z] at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterMethodRunStatement.evaluate(FeaturesRunner.java:345) [2020-03-02T15:16:07.830Z] at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterTeardownStatement.evaluate(FeaturesRunner.java:362) [2020-03-02T15:16:07.830Z] at org.nuxeo.runtime.test.runner.FeaturesRunner$RulesFactory$1.evaluate(FeaturesRunner.java:435) [2020-03-02T15:16:07.830Z] at org.nuxeo.runtime.test.runner.RuntimeDeployment$DeploymentStatement.evaluate(RuntimeDeployment.java:326) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306) [2020-03-02T15:16:07.830Z] at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366) [2020-03-02T15:16:07.830Z] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103) [2020-03-02T15:16:07.830Z] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293) [2020-03-02T15:16:07.830Z] at org.nuxeo.runtime.test.runner.FeaturesRunner$AfterClassStatement.evaluate(FeaturesRunner.java:251) [2020-03-02T15:16:07.830Z] at org.nuxeo.runtime.test.runner.FeaturesRunner$RulesFactory$1.evaluate(FeaturesRunner.java:435) [2020-03-02T15:16:07.830Z] at org.nuxeo.runtime.test.runner.FeaturesRunner$BeforeClassStatement.evaluate(FeaturesRunner.java:234) [2020-03-02T15:16:07.830Z] at org.junit.rules.RunRules.evaluate(RunRules.java:20) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner.run(ParentRunner.java:413) [2020-03-02T15:16:07.830Z] at org.junit.runners.Suite.runChild(Suite.java:128) [2020-03-02T15:16:07.830Z] at org.junit.runners.Suite.runChild(Suite.java:27) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306) [2020-03-02T15:16:07.830Z] at org.junit.runners.ParentRunner.run(ParentRunner.java:413) [2020-03-02T15:16:07.830Z] at org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55) [2020-03-02T15:16:07.830Z] at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137) [2020-03-02T15:16:07.830Z] at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:107) [2020-03-02T15:16:07.830Z] at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:83) [2020-03-02T15:16:07.830Z] at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75) [2020-03-02T15:16:07.830Z] at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:158) [2020-03-02T15:16:07.830Z] at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384) [2020-03-02T15:16:07.830Z] at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345) [2020-03-02T15:16:07.830Z] at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126) [2020-03-02T15:16:07.830Z] at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418) [2020-03-02T15:16:07.830Z] Caused by: org.postgresql.util.PSQLException: ERROR: deadlock detected [2020-03-02T15:16:07.830Z] Detail: Process 4573 waits for ShareLock on transaction 35373; blocked by process 4572. [2020-03-02T15:16:07.830Z] Process 4572 waits for ShareLock on transaction 35372; blocked by process 4573. [2020-03-02T15:16:07.830Z] Hint: See server log for query details. [2020-03-02T15:16:07.830Z] Where: while deleting tuple (0,13) in relation "fulltext" [2020-03-02T15:16:07.831Z] SQL statement "DELETE FROM ONLY "public"."fulltext" WHERE $1::pg_catalog.text OPERATOR(pg_catalog.=) "id"::pg_catalog.text" [2020-03-02T15:16:07.831Z] at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2505) [2020-03-02T15:16:07.831Z] at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2241) [2020-03-02T15:16:07.831Z] at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:310) [2020-03-02T15:16:07.831Z] at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:447) [2020-03-02T15:16:07.831Z] at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:368) [2020-03-02T15:16:07.831Z] at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:158) [2020-03-02T15:16:07.831Z] at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:124) [2020-03-02T15:16:07.831Z] at org.tranql.connector.jdbc.PreparedStatementHandle.executeUpdate(PreparedStatementHandle.java:186) [2020-03-02T15:16:07.831Z] at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCRowMapper.deleteRowsDirect(JDBCRowMapper.java:825) [2020-03-02T15:16:07.831Z] ... 71 more
- is related to
-
NXP-28579 Run Nuxeo Platform unit tests against MongoDB and PostgreSQL
- Resolved