Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Rejection of large number of instances fails by Transaction Timeout #3955

Closed
gunterze opened this issue Feb 13, 2023 · 0 comments
Closed

Rejection of large number of instances fails by Transaction Timeout #3955

gunterze opened this issue Feb 13, 2023 · 0 comments
Assignees
Labels
bug Something isn't working
Milestone

Comments

@gunterze
Copy link
Member

Rejection of large number of instances fails by Transaction Timeout (default 5 mins):

2023-02-10 15:02:39,284 INFO  [org.dcm4chee.arc.store.impl.StoreServiceEJB] (default task-4) 127.0.0.1@127.0.0.1->WORKLIST: RejectedInstance[pk=1, time=Fri Feb 10 15:02:39 CET 2023, code=(113038, DCM, "Incorrect Modality Worklist Entry")] of Instance[uid=1.2.840.113619.2.131.4444.1148402725.925052, class=1.2.840.10008.5.1.4.1.1.128] of Series[uid=1.2.840.113619.2.131.4444.1148402074.78228] of Study[uid=1.2.840.113619.2.55.1.1762927524.2188.1148396481.727]
...
2023-02-10 15:07:39,269 INFO  [org.dcm4chee.arc.store.impl.StoreServiceEJB] (default task-4) 127.0.0.1@127.0.0.1->WORKLIST: RejectedInstance[pk=16824, time=Fri Feb 10 15:07:39 CET 2023, code
=(113038, DCM, "Incorrect Modality Worklist Entry")] of Instance[uid=1.2.840.113619.2.131.4444.1148403332.766282.21, class=1.2.840.10008.5.1.4.1.1.128] of Series[uid=1.2.840.113619.2.131.444
4.1148402074.78228.21] of Study[uid=1.2.840.113619.2.55.1.1762927524.2188.1148396481.727]
2023-02-10 15:07:39,274 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check processing TX 0:ffffc0a802a9:-2e7f2683:63e649eb:49d5a in state  RUN
2023-02-10 15:07:39,274 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffffc0a802a9:-2e7f2683:63e649eb:49d5a invoked while multiple threads ac
tive within it.
2023-02-10 15:07:39,275 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012381: Action id 0:ffffc0a802a9:-2e7f2683:63e649eb:49d5a completed with multiple threads - thread d
efault task-4 was in progress with java.base@11.0.17/java.lang.reflect.Field.get(Field.java:418)
org.hibernate@5.3.28.Final//org.hibernate.property.access.spi.GetterFieldImpl.get(GetterFieldImpl.java:71)
org.hibernate@5.3.28.Final//org.hibernate.tuple.entity.AbstractEntityTuplizer.getPropertyValue(AbstractEntityTuplizer.java:577)
org.hibernate@5.3.28.Final//org.hibernate.persister.entity.AbstractEntityPersister.getPropertyValue(AbstractEntityPersister.java:4998)
org.hibernate@5.3.28.Final//org.hibernate.engine.spi.CascadingActions$8.noCascade(CascadingActions.java:371)
org.hibernate@5.3.28.Final//org.hibernate.engine.internal.Cascade.cascade(Cascade.java:165)
org.hibernate@5.3.28.Final//org.hibernate.event.internal.AbstractFlushingEventListener.cascadeOnFlush(AbstractFlushingEventListener.java:159)
org.hibernate@5.3.28.Final//org.hibernate.event.internal.AbstractFlushingEventListener.prepareEntityFlushes(AbstractFlushingEventListener.java:150)
org.hibernate@5.3.28.Final//org.hibernate.event.internal.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:83)
org.hibernate@5.3.28.Final//org.hibernate.event.internal.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:46)
org.hibernate@5.3.28.Final//org.hibernate.internal.SessionImpl.autoFlushIfRequired(SessionImpl.java:1433)
org.hibernate@5.3.28.Final//org.hibernate.internal.SessionImpl.list(SessionImpl.java:1519)
org.hibernate@5.3.28.Final//org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1598)
org.hibernate@5.3.28.Final//org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1566)
org.hibernate@5.3.28.Final//org.hibernate.query.internal.AbstractProducedQuery.getSingleResult(AbstractProducedQuery.java:1614)
deployment.dcm4chee-arc-ear-5.29.2-psql.ear.dcm4chee-arc-store-5.29.2.jar//org.dcm4chee.arc.store.impl.StoreServiceEJB.findRejectedInstance(StoreServiceEJB.java:580)
deployment.dcm4chee-arc-ear-5.29.2-psql.ear.dcm4chee-arc-store-5.29.2.jar//org.dcm4chee.arc.store.impl.StoreServiceEJB.rejectInstances(StoreServiceEJB.java:485)
deployment.dcm4chee-arc-ear-5.29.2-psql.ear.dcm4chee-arc-store-5.29.2.jar//org.dcm4chee.arc.store.impl.StoreServiceEJB.updateDB(StoreServiceEJB.java:276)
jdk.internal.reflect.GeneratedMethodAccessor81.invoke(Unknown Source)

Solved by inserting each RejectedInstance record in a new transaction, pausing overall transaction of updateDB.
Tested rejection of 20000 instances in 328s successfully

@vrindanayak vrindanayak added this to the 5.29.2 milestone Feb 14, 2023
@gunterze gunterze added the bug Something isn't working label Feb 14, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants