Loading...

XML

Word

Printable

Details

Type: Bug
Resolution: Unresolved
Priority: Major
Fix Version/s: None
Affects Version/s: None
Component/s: jberet-core
Labels:
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

Attachments

Activity

People

Assignee:: Weinan Li

Reporter:: James Perkins

Votes:: 0 Vote for this issue

Watchers:: 1 Start watching this issue

Dates

Created:: 2018/04/12 5:38 PM

Updated:: 2023/10/05 9:56 PM