Details
-
Bug
-
Resolution: Unresolved
-
Major
-
None
-
None
-
None
Description
There seems to be a race condition either in the JdbcJobRepository or in the PurgeBatchlet. I consistently see the PurgeJdbcRepositoryIT fail.
The following is a partial build log from where it fails. You can see from the query results that the job execution with an id of 12 was removed, but for some reason the job repository still sees the job. This may be due to the cache as it doesn't look like it's removed via the PurgeBatchlet.
************************* Entered ************************** Instance: 5 - purgeJdbcRepository Instance: 8 - purgeJdbcRepository Instance: 9 - prepurge Instance: 10 - prepurge2 Instance: 11 - purgeJdbcRepository Execution: 5 Execution: 8 Execution: 11 ***************************** ***************************** Apr 12, 2018 2:30:19 PM org.jberet.tools.AbstractJobXmlResolver resolveJobXml INFO: JBERET000030: Resolved job jar:file:/home/jperkins/.m2/repository/org/jberet/test-apps/purgeInMemoryRepository/1.3.0.Final-SNAPSHOT/purgeInMemoryRepository-1.3.0.Final-SNAPSHOT.jar!/META-INF/batch-jobs/prepurge.xml prepurge job execution id: 12, status: COMPLETED Apr 12, 2018 2:30:35 PM org.jberet.tools.AbstractJobXmlResolver resolveJobXml INFO: JBERET000030: Resolved job jar:file:/home/jperkins/.m2/repository/org/jberet/test-apps/purgeInMemoryRepository/1.3.0.Final-SNAPSHOT/purgeInMemoryRepository-1.3.0.Final-SNAPSHOT.jar!/META-INF/batch-jobs/prepurge2.xml Apr 12, 2018 2:30:35 PM org.jberet.tools.AbstractJobXmlResolver resolveJobXml INFO: JBERET000030: Resolved job jar:file:/home/jperkins/.m2/repository/org/jberet/test-apps/purgeInMemoryRepository/1.3.0.Final-SNAPSHOT/purgeInMemoryRepository-1.3.0.Final-SNAPSHOT.jar!/META-INF/batch-jobs/prepurge.xml prepurge2 job execution id: 13, status: COMPLETED ************************* Ran Two ************************** Instance: 5 - purgeJdbcRepository Instance: 8 - purgeJdbcRepository Instance: 9 - prepurge Instance: 10 - prepurge2 Instance: 11 - purgeJdbcRepository Instance: 12 - prepurge Instance: 13 - prepurge2 Execution: 5 Execution: 8 Execution: 11 Execution: 12 Execution: 13 ***************************** ***************************** Apr 12, 2018 2:31:03 PM org.jberet.tools.AbstractJobXmlResolver resolveJobXml INFO: JBERET000030: Resolved job file:/home/jperkins/projects/jboss/jberet/jsr352/test-apps/purgeJdbcRepository/target/classes/META-INF/batch-jobs/purgeJdbcRepository.xml Apr 12, 2018 2:31:19 PM org.jberet.repository.AbstractRepository removeJob INFO: JBERET000023: Removing Job prepurge2 Apr 12, 2018 2:31:19 PM org.jberet.repository.AbstractPersistentRepository removeJob INFO: JBERET000023: Removing javax.batch.runtime.JobInstance 4 Apr 12, 2018 2:31:19 PM org.jberet.repository.AbstractPersistentRepository removeJob INFO: JBERET000023: Removing javax.batch.runtime.JobInstance 7 Apr 12, 2018 2:31:19 PM org.jberet.repository.AbstractPersistentRepository removeJob INFO: JBERET000023: Removing javax.batch.runtime.JobInstance 10 Apr 12, 2018 2:31:19 PM org.jberet.repository.AbstractPersistentRepository removeJob INFO: JBERET000023: Removing javax.batch.runtime.JobInstance 13 Apr 12, 2018 2:31:19 PM org.jberet.repository.AbstractPersistentRepository removeJob INFO: JBERET000023: Removing javax.batch.runtime.JobExecution 13 ****************** startAndVerifyPurgeJob ****************** Instance: 5 - purgeJdbcRepository Instance: 8 - purgeJdbcRepository Instance: 11 - purgeJdbcRepository Instance: 14 - purgeJdbcRepository Execution: 5 Execution: 8 Execution: 11 Execution: 14 ***************************** ***************************** ************************* Complete ************************* Instance: 5 - purgeJdbcRepository Instance: 8 - purgeJdbcRepository Instance: 11 - purgeJdbcRepository Instance: 14 - purgeJdbcRepository Execution: 5 Execution: 8 Execution: 11 Execution: 14 ***************************** ***************************** Apr 12, 2018 2:31:35 PM org.jberet.tools.AbstractJobXmlResolver resolveJobXml INFO: JBERET000030: Resolved job jar:file:/home/jperkins/.m2/repository/org/jberet/test-apps/purgeInMemoryRepository/1.3.0.Final-SNAPSHOT/purgeInMemoryRepository-1.3.0.Final-SNAPSHOT.jar!/META-INF/batch-jobs/prepurge.xml prepurge job execution id: 15, status: COMPLETED Apr 12, 2018 2:32:03 PM org.jberet.tools.AbstractJobXmlResolver resolveJobXml INFO: JBERET000030: Resolved job jar:file:/home/jperkins/.m2/repository/org/jberet/test-apps/purgeInMemoryRepository/1.3.0.Final-SNAPSHOT/purgeInMemoryRepository-1.3.0.Final-SNAPSHOT.jar!/META-INF/batch-jobs/prepurge2.xml Apr 12, 2018 2:32:03 PM org.jberet.tools.AbstractJobXmlResolver resolveJobXml INFO: JBERET000030: Resolved job jar:file:/home/jperkins/.m2/repository/org/jberet/test-apps/purgeInMemoryRepository/1.3.0.Final-SNAPSHOT/purgeInMemoryRepository-1.3.0.Final-SNAPSHOT.jar!/META-INF/batch-jobs/prepurge.xml prepurge2 job execution id: 16, status: COMPLETED Apr 12, 2018 2:32:23 PM org.jberet.tools.AbstractJobXmlResolver resolveJobXml INFO: JBERET000030: Resolved job file:/home/jperkins/projects/jboss/jberet/jsr352/test-apps/purgeJdbcRepository/target/classes/META-INF/batch-jobs/purgeJdbcRepository.xml Apr 12, 2018 2:32:39 PM org.jberet.repository.AbstractPersistentRepository removeJobExecutions INFO: JBERET000023: Removing javax.batch.runtime.JobExecution 16 Apr 12, 2018 2:32:39 PM org.jberet.repository.AbstractPersistentRepository removeJobExecutions INFO: JBERET000023: Removing javax.batch.runtime.JobExecution 12 Apr 12, 2018 2:32:39 PM org.jberet.repository.AbstractPersistentRepository removeJobExecutions INFO: JBERET000023: Removing javax.batch.runtime.JobExecution 15 Got expected javax.batch.operations.NoSuchJobExecutionException: JBERET000604: No job execution with id 15 Got expected javax.batch.operations.NoSuchJobExecutionException: JBERET000604: No job execution with id 16 Got expected result: [] [ERROR] Tests run: 28, Failures: 1, Errors: 0, Skipped: 12, Time elapsed: 406.745 s <<< FAILURE! - in org.jberet.testapps.purgeJdbcRepository.PurgeJdbcRepositoryIT [ERROR] withSqlDeleteJobInstancesCascade(org.jberet.testapps.purgeJdbcRepository.PurgeJdbcRepositoryIT) Time elapsed: 79.955 s <<< FAILURE! java.lang.AssertionError: Expecting NoSuchJobExecutionException, but got org.jberet.runtime.JobExecutionImpl@c - 12 at org.junit.Assert.fail(Assert.java:88) at org.jberet.testapps.common.AbstractIT.assertNoSuchJobExecution(AbstractIT.java:151) at org.jberet.testapps.purgeJdbcRepository.PurgeJdbcRepositoryIT.withSqlDeleteJobInstancesCascade(PurgeJdbcRepositoryIT.java:266) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) 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.junit4.JUnit4Provider.execute(JUnit4Provider.java:365) at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159) at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:379) at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:340) at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:125) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:413) Weld SE container STATIC_INSTANCE shut down by shutdown hook [INFO] [INFO] Results: [INFO] [ERROR] Failures: [ERROR] PurgeJdbcRepositoryIT.withSqlDeleteJobInstancesCascade:266->AbstractIT.assertNoSuchJobExecution:151 Expecting NoSuchJobExecutionException, but got org.jberet.runtime.JobExecutionImpl@c - 12 [INFO] [ERROR] Tests run: 28, Failures: 1, Errors: 0, Skipped: 12