Concurrent requests to permanently delete study throws OptimisticLockException

[vrindanayak]

Note : Reported & tested for (CT/MR) studies with large number of instances (300+)

Steps to Reproduce

• Store a (CT/MR) study with large number of instances (300+)
• Trigger concurrent Delete Study Permanently REST service
• Fails with following in server log

09:09:18,504 INFO  [org.dcm4chee.arc.iocm.rs.StudyMgtRS] (default task-1) Process DELETE /dcm4chee-arc/aets/DCM4CHEE/rs/studies/1.2.124.113532.80.22166.20879.20201207.211625.126275554 from [email protected]
09:09:18,528 INFO  [org.dcm4chee.arc.delete.impl.DeletionServiceImpl] (default task-1) Start deleting Study[pk=2611, uid=1.2.124.113532.80.22166.20879.20201207.211625.126275554, id=14572] from database
09:09:18,820 INFO  [org.dcm4chee.arc.iocm.rs.StudyMgtRS] (default task-2) Process DELETE /dcm4chee-arc/aets/DCM4CHEE/rs/studies/1.2.124.113532.80.22166.20879.20201207.211625.126275554 from [email protected]
09:09:18,835 INFO  [org.dcm4chee.arc.delete.impl.DeletionServiceImpl] (default task-2) Start deleting Study[pk=2611, uid=1.2.124.113532.80.22166.20879.20201207.211625.126275554, id=14572] from database
09:09:20,363 ERROR [org.jboss.as.ejb3.invocation] (default task-2) WFLYEJB0034: Jakarta Enterprise Beans Invocation failed on component DeletionServiceEJB for method public java.util.List org.dcm4chee.arc.delete.impl.DeletionServiceEJB.deleteStudy(org.dcm4chee.arc.delete.StudyDeleteContext,int,boolean): jakarta.ejb.EJBException: jakarta.persistence.OptimisticLockException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [org.dcm4chee.arc.entity.Instance#68429]
        at [email protected]//org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:268)
        .........
        .........
        at deployment.dcm4chee-arc-ear-5.32.0-psql.ear.dcm4chee-arc-delete-5.32.0.jar//org.dcm4chee.arc.delete.impl.DeletionServiceEJB$$$view31.deleteStudy(Unknown Source)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        .........
        .........
        at deployment.dcm4chee-arc-ear-5.32.0-psql.ear.dcm4chee-arc-delete-5.32.0.jar//org.dcm4chee.arc.delete.impl.DeletionServiceEJB$Proxy$_$$_Weld$EnterpriseProxy$.deleteStudy(Unknown Source)
        at deployment.dcm4chee-arc-ear-5.32.0-psql.ear.dcm4chee-arc-delete-5.32.0.jar//org.dcm4chee.arc.delete.impl.DeletionServiceImpl.deleteStudy(DeletionServiceImpl.java:240)
        at deployment.dcm4chee-arc-ear-5.32.0-psql.ear.dcm4chee-arc-delete-5.32.0.jar//org.dcm4chee.arc.delete.impl.DeletionServiceImpl.deleteStudy(DeletionServiceImpl.java:171)
        at deployment.dcm4chee-arc-ear-5.32.0-psql.ear.dcm4chee-arc-delete-5.32.0.jar//org.dcm4chee.arc.delete.impl.DeletionServiceImpl.deleteStudy(DeletionServiceImpl.java:146)
        at deployment.dcm4chee-arc-ear-5.32.0-psql.ear.dcm4chee-arc-delete-5.32.0.jar//org.dcm4chee.arc.delete.impl.DeletionServiceImpl$Proxy$_$$_WeldClientProxy.deleteStudy(Unknown Source)
        at deployment.dcm4chee-arc-ear-5.32.0-psql.ear.dcm4chee-arc-war-5.32.0-unsecure.war//org.dcm4chee.arc.iocm.rs.StudyMgtRS.deleteStudy(StudyMgtRS.java:158)
        at deployment.dcm4chee-arc-ear-5.32.0-psql.ear.dcm4chee-arc-war-5.32.0-unsecure.war//org.dcm4chee.arc.iocm.rs.StudyMgtRS$Proxy$_$$_WeldSubclass.deleteStudy$$super(Unknown Source)
        .........
        .........
        at deployment.dcm4chee-arc-ear-5.32.0-psql.ear.dcm4chee-arc-war-5.32.0-unsecure.war//org.dcm4chee.arc.iocm.rs.StudyMgtRS$Proxy$_$$_WeldSubclass.deleteStudy(Unknown Source)
        at deployment.dcm4chee-arc-ear-5.32.0-psql.ear.dcm4chee-arc-war-5.32.0-unsecure.war//org.dcm4chee.arc.iocm.rs.StudyMgtRS$Proxy$_$$_WeldClientProxy.deleteStudy(Unknown Source)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        .........
        .........
Caused by: jakarta.persistence.OptimisticLockException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [org.dcm4chee.arc.entity.Instance#68429]
        at [email protected]//org.hibernate.internal.ExceptionConverterImpl.wrapStaleStateException(ExceptionConverterImpl.java:204)
        .........
        .........
        at deployment.dcm4chee-arc-ear-5.32.0-psql.ear.dcm4chee-arc-delete-5.32.0.jar//org.dcm4chee.arc.delete.impl.DeletionServiceEJB.countInstancesOfSeries(DeletionServiceEJB.java:615)
        at deployment.dcm4chee-arc-ear-5.32.0-psql.ear.dcm4chee-arc-delete-5.32.0.jar//org.dcm4chee.arc.delete.impl.DeletionServiceEJB.deleteInstances(DeletionServiceEJB.java:548)
        at deployment.dcm4chee-arc-ear-5.32.0-psql.ear.dcm4chee-arc-delete-5.32.0.jar//org.dcm4chee.arc.delete.impl.DeletionServiceEJB.deleteStudy(DeletionServiceEJB.java:330)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        .........
        .........
        ... 149 more
Caused by: org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [org.dcm4chee.arc.entity.Instance#68429]
        at [email protected]//org.hibernate.engine.jdbc.mutation.internal.ModelMutationHelper.identifiedResultsCheck(ModelMutationHelper.java:75)
        .........
        .........
        ... 181 more
        .........
        .........
09:09:22,076 INFO  [org.dcm4chee.arc.delete.impl.DeletionServiceImpl] (default task-1) Successfully delete Study[pk=2611, uid=1.2.124.113532.80.22166.20879.20201207.211625.126275554, id=14572] from database

Note : Even after some time, if only a single request is triggered to permanently delete the study, it shows success in UI / server log, but the study remains in DB

10:06:46,273 INFO  [org.dcm4chee.arc.qido.QidoRS] (default task-1) Process GET /dcm4chee-arc/aets/DCM4CHEE/rs/studies?limit=21&includefield=all&offset=0&orderby=PatientName,-StudyDate,-StudyTime from [email protected]
10:06:46,405 INFO  [org.dcm4chee.arc.qido.QidoRS] (default task-1) SearchForStudies: 1 Matches
10:06:50,362 INFO  [org.dcm4chee.arc.conf.rs.ConfigurationRS] (default task-1) Process GET /dcm4chee-arc/devices/dcm4chee-arc from [email protected]
10:06:51,888 INFO  [org.dcm4chee.arc.iocm.rs.StudyMgtRS] (default task-1) Process DELETE /dcm4chee-arc/aets/DCM4CHEE/rs/studies/1.2.124.113532.80.22166.20879.20201207.211625.126275554 from [email protected]
10:06:52,000 INFO  [org.dcm4chee.arc.delete.impl.DeletionServiceImpl] (default task-1) Start deleting Study[pk=2611, uid=1.2.124.113532.80.22166.20879.20201207.211625.126275554, id=14572] from database
10:06:52,036 INFO  [org.dcm4chee.arc.delete.impl.DeletionServiceImpl] (default task-1) Successfully delete Study[pk=2611, uid=1.2.124.113532.80.22166.20879.20201207.211625.126275554, id=14572] from database
10:06:57,120 INFO  [org.dcm4chee.arc.qido.QidoRS] (default task-1) Process GET /dcm4chee-arc/aets/DCM4CHEE/rs/studies?limit=21&includefield=all&offset=0&orderby=PatientName,-StudyDate,-StudyTime from [email protected]
10:06:57,135 INFO  [org.dcm4chee.arc.qido.QidoRS] (default task-1) SearchForStudies: 1 Matches

[gunterze]

fixed by #4462