Uploaded image for project: 'Opencast'
  1. MH-10711

OptimisticLockException after ingest

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Critical
    • Resolution: Fixed and reviewed
    • Affects versions: 1.6.1
    • Fix versions: 1.6.2, 2.0.0
    • Components: Backend Software
    • Labels:
      None
    • Severity:
      Crash/Hang
    • Steps to reproduce:
      Hide
      This stack trace can be seen multiple times throughout the logs:

      {noformat}
      2015-02-25 08:01:31 ERROR [848054369@qtp-1419719651-3469] (WorkflowServiceImpl:1290) - [>38fdcd02] Update of workflow job 40748396 in the service registry failed, service registry and workflow index may be out of sync
      2015-02-25 08:01:31 ERROR [848054369@qtp-1419719651-3469] (WorkflowRestService:707) - org.opencastproject.serviceregistry.api.ServiceRegistryException: javax.persistence.RollbackException: javax.persistence.OptimisticLockException: Exception [EclipseLink-5006] (Eclipse Persistence Services - 2.0.2.v20100323-r6872): org.eclipse.persistence.exceptions.OptimisticLockException
      Exception Description: The object [Job {id:40748396, version:43}] cannot be updated because it has changed or been deleted since it was last read.
      Class> org.opencastproject.serviceregistry.impl.JobJpaImpl Primary Key> [40748396]
      org.opencastproject.workflow.api.WorkflowDatabaseException: org.opencastproject.serviceregistry.api.ServiceRegistryException: javax.persistence.RollbackException: javax.persistence.OptimisticLockException: Exception [EclipseLink-5006] (Eclipse Persistence Services - 2.0.2.v20100323-r6872): org.eclipse.persistence.exceptions.OptimisticLockException
      Exception Description: The object [Job {id:40748396, version:43}] cannot be updated because it has changed or been deleted since it was last read.
      Class> org.opencastproject.serviceregistry.impl.JobJpaImpl Primary Key> [40748396]
      at org.opencastproject.workflow.impl.WorkflowServiceImpl.update(WorkflowServiceImpl.java:1293)
      at org.opencastproject.workflow.endpoint.WorkflowRestService.resume(WorkflowRestService.java:702)

      ...

      Caused by: org.opencastproject.serviceregistry.api.ServiceRegistryException: javax.persistence.RollbackException: javax.persistence.OptimisticLockException: Exception [EclipseLink-5006] (Eclipse Persistence Services - 2.0.2.v20100323-r6872): org.eclipse.persistence.exceptions.OptimisticLockException
      Exception Description: The object [Job {id:40748396, version:43}] cannot be updated because it has changed or been deleted since it was last read.
      Class> org.opencastproject.serviceregistry.impl.JobJpaImpl Primary Key> [40748396]
      at org.opencastproject.serviceregistry.impl.ServiceRegistryJpaImpl.updateJob(ServiceRegistryJpaImpl.java:766)
      at org.opencastproject.workflow.impl.WorkflowServiceImpl.update(WorkflowServiceImpl.java:1288)
      ... 114 more
      {noformat}

      This may have to do with the optimistic lock exception, as they can usually be seen right above the log statements in question. The operation may be set to "running", then the job is updated and that update fails.
      {noformat}
      2015-02-25 08:13:58 INFO [pool-18-thread-463] (VideoEditorServiceRemote:70) - Start proccessing smil 's-5b18e6e5-92b9-44be-ad3e-d87acd4c5cae' on remote videoeditor service
      2015-02-25 08:14:02 ERROR [pool-18-thread-462] (WorkflowOperationWorker:163) - Workflow operation 'operation:'editor', position:11, state:'RUNNING'' failed
      java.lang.IllegalStateException: Workflow operation 'operation:'editor', position:11, state:'RUNNING'' is in unexpected state 'RUNNING'
      at org.opencastproject.workflow.impl.WorkflowOperationWorker.execute(WorkflowOperationWorker.java:147)
      at org.opencastproject.workflow.impl.WorkflowServiceImpl.runWorkflowOperation(WorkflowServiceImpl.java:830)
      at org.opencastproject.workflow.impl.WorkflowServiceImpl.process(WorkflowServiceImpl.java:1853)
      at org.opencastproject.workflow.impl.WorkflowServiceImpl$JobRunner.call(WorkflowServiceImpl.java:2264)
      at org.opencastproject.workflow.impl.WorkflowServiceImpl$JobRunner.call(WorkflowServiceImpl.java:2230)
      at java.util.concurrent.FutureTask.run(FutureTask.java:262)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
      at java.lang.Thread.run(Thread.java:745)
      2015-02-25 08:14:02 WARN [pool-18-thread-462] (WorkflowServiceImpl:1883) - [>38fdcd02] Exception while accepting job Job {id:41042968, version:19}
      java.lang.IllegalStateException: Unexpected state 'RUNNING' found
      at org.opencastproject.workflow.impl.WorkflowServiceImpl.updateOperationJob(WorkflowServiceImpl.java:1933)
      at org.opencastproject.workflow.impl.WorkflowServiceImpl.runWorkflowOperation(WorkflowServiceImpl.java:838)
      at org.opencastproject.workflow.impl.WorkflowServiceImpl.process(WorkflowServiceImpl.java:1853)
      at org.opencastproject.workflow.impl.WorkflowServiceImpl$JobRunner.call(WorkflowServiceImpl.java:2264)
      at org.opencastproject.workflow.impl.WorkflowServiceImpl$JobRunner.call(WorkflowServiceImpl.java:2230)
      at java.util.concurrent.FutureTask.run(FutureTask.java:262)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
      at java.lang.Thread.run(Thread.java:745)
      2015-02-25 08:14:02 WARN [pool-18-thread-462] (WorkflowServiceImpl:1886) - [>38fdcd02] Marking workflow instance Workflow {41042156} as failed
      {noformat}
      Show
      This stack trace can be seen multiple times throughout the logs: {noformat} 2015-02-25 08:01:31 ERROR [ 848054369@qtp-1419719651-3469 ] (WorkflowServiceImpl:1290) - [>38fdcd02] Update of workflow job 40748396 in the service registry failed, service registry and workflow index may be out of sync 2015-02-25 08:01:31 ERROR [ 848054369@qtp-1419719651-3469 ] (WorkflowRestService:707) - org.opencastproject.serviceregistry.api.ServiceRegistryException: javax.persistence.RollbackException: javax.persistence.OptimisticLockException: Exception [EclipseLink-5006] (Eclipse Persistence Services - 2.0.2.v20100323-r6872): org.eclipse.persistence.exceptions.OptimisticLockException Exception Description: The object [Job {id:40748396, version:43}] cannot be updated because it has changed or been deleted since it was last read. Class> org.opencastproject.serviceregistry.impl.JobJpaImpl Primary Key> [40748396] org.opencastproject.workflow.api.WorkflowDatabaseException: org.opencastproject.serviceregistry.api.ServiceRegistryException: javax.persistence.RollbackException: javax.persistence.OptimisticLockException: Exception [EclipseLink-5006] (Eclipse Persistence Services - 2.0.2.v20100323-r6872): org.eclipse.persistence.exceptions.OptimisticLockException Exception Description: The object [Job {id:40748396, version:43}] cannot be updated because it has changed or been deleted since it was last read. Class> org.opencastproject.serviceregistry.impl.JobJpaImpl Primary Key> [40748396] at org.opencastproject.workflow.impl.WorkflowServiceImpl.update(WorkflowServiceImpl.java:1293) at org.opencastproject.workflow.endpoint.WorkflowRestService.resume(WorkflowRestService.java:702) ... Caused by: org.opencastproject.serviceregistry.api.ServiceRegistryException: javax.persistence.RollbackException: javax.persistence.OptimisticLockException: Exception [EclipseLink-5006] (Eclipse Persistence Services - 2.0.2.v20100323-r6872): org.eclipse.persistence.exceptions.OptimisticLockException Exception Description: The object [Job {id:40748396, version:43}] cannot be updated because it has changed or been deleted since it was last read. Class> org.opencastproject.serviceregistry.impl.JobJpaImpl Primary Key> [40748396] at org.opencastproject.serviceregistry.impl.ServiceRegistryJpaImpl.updateJob(ServiceRegistryJpaImpl.java:766) at org.opencastproject.workflow.impl.WorkflowServiceImpl.update(WorkflowServiceImpl.java:1288) ... 114 more {noformat} This may have to do with the optimistic lock exception, as they can usually be seen right above the log statements in question. The operation may be set to "running", then the job is updated and that update fails. {noformat} 2015-02-25 08:13:58 INFO [pool-18-thread-463] (VideoEditorServiceRemote:70) - Start proccessing smil 's-5b18e6e5-92b9-44be-ad3e-d87acd4c5cae' on remote videoeditor service 2015-02-25 08:14:02 ERROR [pool-18-thread-462] (WorkflowOperationWorker:163) - Workflow operation 'operation:'editor', position:11, state:'RUNNING'' failed java.lang.IllegalStateException: Workflow operation 'operation:'editor', position:11, state:'RUNNING'' is in unexpected state 'RUNNING' at org.opencastproject.workflow.impl.WorkflowOperationWorker.execute(WorkflowOperationWorker.java:147) at org.opencastproject.workflow.impl.WorkflowServiceImpl.runWorkflowOperation(WorkflowServiceImpl.java:830) at org.opencastproject.workflow.impl.WorkflowServiceImpl.process(WorkflowServiceImpl.java:1853) at org.opencastproject.workflow.impl.WorkflowServiceImpl$JobRunner.call(WorkflowServiceImpl.java:2264) at org.opencastproject.workflow.impl.WorkflowServiceImpl$JobRunner.call(WorkflowServiceImpl.java:2230) at java.util.concurrent.FutureTask.run(FutureTask.java:262) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 2015-02-25 08:14:02 WARN [pool-18-thread-462] (WorkflowServiceImpl:1883) - [>38fdcd02] Exception while accepting job Job {id:41042968, version:19} java.lang.IllegalStateException: Unexpected state 'RUNNING' found at org.opencastproject.workflow.impl.WorkflowServiceImpl.updateOperationJob(WorkflowServiceImpl.java:1933) at org.opencastproject.workflow.impl.WorkflowServiceImpl.runWorkflowOperation(WorkflowServiceImpl.java:838) at org.opencastproject.workflow.impl.WorkflowServiceImpl.process(WorkflowServiceImpl.java:1853) at org.opencastproject.workflow.impl.WorkflowServiceImpl$JobRunner.call(WorkflowServiceImpl.java:2264) at org.opencastproject.workflow.impl.WorkflowServiceImpl$JobRunner.call(WorkflowServiceImpl.java:2230) at java.util.concurrent.FutureTask.run(FutureTask.java:262) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 2015-02-25 08:14:02 WARN [pool-18-thread-462] (WorkflowServiceImpl:1886) - [>38fdcd02] Marking workflow instance Workflow {41042156} as failed {noformat}
    • Tags (folksonomy):

      TestRail: Results

        Attachments

          Issue links

            Activity

              People

              • Assignee:
                lrohner Lukas Rohner
                Reporter:
                lrohner Lukas Rohner
              • Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:

                  TestRail: Cases