Uploaded image for project: 'JBeret'
  1. JBeret
  2. JBERET-404

JobRepository has a remove race condition

    Details

    • Type: Bug
    • Status: Coding In Progress (View Workflow)
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: None
    • Fix 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
      

        Gliffy Diagrams

          Attachments

            Activity

              People

              • Assignee:
                cfang Cheng Fang
                Reporter:
                jamezp James Perkins
              • Votes:
                0 Vote for this issue
                Watchers:
                1 Start watching this issue

                Dates

                • Created:
                  Updated: