DCM4CHEE-ARC-LIGHT v5.16.2 - Deletion of Rejected Instances not deleting

[Docjay]

DCM4CHEE v5.16.2

Wildfly v16

DB:  Mysql

  I've noticed this since upgrading to v5.16.2 (might have been in 5.16.0 as well) but all of the rules I had setup for deleting studies have failed to reject any since the update.

My studies are getting a 'Study Expiration Date', but many of them are past due.

I've been referring to this wiki entry but the settings it mentions were already configured.

Not sure if it has to do with the Rejection Note or not, but I already have one that was configured named 'Retention Expired'.

I also changed the 'Delete rejected polling interval' to PT5M from PT4H to see if it would make a difference or not, but it didn't help.

The last time this was broken was the query being sent to MYSQL without hyphens so the search came back empty - reference this post

I've attached several screenshots of my config

Any help will be very appreciated!

Thank you

[Docjay]

Can any of the devs help out with this new issue?

thank you

[vrinda...@j4care.com]

Please see attached configurations and server.log. It works.

[Docjay]

Vrinda,

 

    Thanks for your reply.  Just wanted to say that my settings hadn't change from when I updated from 5.15.x to 5.16.2.  I did notice that the 'Study Expiration State' on the exams that have a 'Study Expiration Date' past due is 'REJECTED'.

I've attached a screen shot.

at midnight, it appears the 'RejectExpiredStudiesScheduler' runs (I can't find the old setting where we could give it a time to start in the config any longer) and I'm seeing this message throughout the log:

2019-05-02 00:03:29,132 WARN  [org.dcm4chee.arc.delete.impl.RejectExpiredStudiesScheduler] (EE-ManagedScheduledExecutorService-default-Thread-1) Failed to reject Expired Study[UID=1.2.4.0.13.1.4.2252867.10.196.122.108.918011220190422223633].
: org.dcm4che3.net.service.DicomServiceException: Retention Period of Study not yet expired.
    at org.dcm4chee.arc.store.impl.StoreServiceEJB.checkExpirationDate(StoreServiceEJB.java:413)
    at org.dcm4chee.arc.store.impl.StoreServiceEJB.rejectInstances(StoreServiceEJB.java:357)
    at org.dcm4chee.arc.store.impl.StoreServiceEJB.updateDB(StoreServiceEJB.java:215)
    at sun.reflect.GeneratedMethodAccessor110.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at

All of those entries like the one above in my log for today are checking SUIDs that are only 10 days old.  So its as if its only looking back 10 days?

I have the study retention policy set for 10 days 'P10D', and it appears that the 'RejectExpiredStudiesScheduler' is only looking backwards 10 days, so nothing would qualify yet.  I'll try to gather some MySQL logs to clarify that assumption.

EDIT:  I just saw this note on the wiki

Note :

• Upto version 5.16.0 Reject Expired Studies Polling Start Time shall be configured.
• Version 5.16.0 onwards the use of Reject Expired Studies Polling Start Time is discontinued and instead one or more Reject Expired Studies Schedule shall be configured

I have configured 'Reject Expired Studies Schedule' for 'hour=0-23 dayOfWeek=0-6' and will test

[vrinda...@j4care.com]

The only explanation I see to the error log that you showed above, is that there is probably one (or more) series of this study which is not yet expired and scheduler is trying to reject the expired study.

If this is indeed the case, then it brings up another issue, that series expiration date somehow was set to be greater than study expiration date, which ideally should not be the case.

We have handled in code (in Store Service, HL7 Service & RESTful services) that study expiration date shall never be lesser than series expiration date.

[Docjay]

Vrinda,

    I've found the query from MYSQL that the service ran last night at close to midnight..  If your testing in  postgresql, this might not be the same query

SELECT
    study0_.pk AS pk1_28_,
    study0_.access_control_id AS access_c2_28_,
    study0_.access_time AS access_t3_28_,
    study0_.accession_no AS accessio4_28_,
    study0_.dicomattrs_fk AS dicomat26_28_,
    study0_.completeness AS complete5_28_,
    study0_.created_time AS created_6_28_,
    study0_.expiration_date AS expirati7_28_,
    study0_.expiration_exporter_id AS expirati8_28_,
    study0_.expiration_state AS expirati9_28_,
    study0_.ext_retrieve_aet AS ext_ret10_28_,
    study0_.failed_retrieves AS failed_11_28_,
    study0_.accno_issuer_fk AS accno_i27_28_,
    study0_.modified_time AS modifie12_28_,
    study0_.patient_fk AS patient28_28_,
    study0_.ref_phys_name_fk AS ref_phy29_28_,
    study0_.rejection_state AS rejecti13_28_,
    study0_.study_size AS study_s14_28_,
    study0_.storage_ids AS storage15_28_,
    study0_.study_custom1 AS study_c16_28_,
    study0_.study_custom2 AS study_c17_28_,
    study0_.study_custom3 AS study_c18_28_,
    study0_.study_date AS study_d19_28_,
    study0_.study_desc AS study_d20_28_,
    study0_.study_id AS study_i21_28_,
    study0_.study_iuid AS study_i22_28_,
    study0_.study_time AS study_t23_28_,
    study0_.updated_time AS updated24_28_,
    study0_.version AS version25_28_
FROM
    study study0_
WHERE
    study0_.expiration_date <= '20190502'
        AND (study0_.expiration_state IN (0 , 1))
LIMIT 2000

The above query comes back with '0' results.

If I remove the line 'AND (study0.expiration_state IN (0, 1))', then the query comes back with results. 

I then looked at the study table in MySQL and all of the studies have an 'expiration_state' of '2'.

Expanding the properties in the GUI for a few studies that 'should' have been deleted by now, the 'Study Expiration State' has a property of 'REJECTED'.

I have attached a screen shot of the GUI.

Can you please explain what states '0' and '1' are in the query?  This would explain why my expired studies are NOT being deleted from the database and from disk.

Thank you

[vrinda...@j4care.com]

For the following which you posted earlier,

2019-05-02 00:03:29,132 WARN  [org.dcm4chee.arc.delete.impl.RejectExpiredStudiesScheduler] (EE-ManagedScheduledExecutorService-default-Thread-1) Failed to reject Expired Study[UID=1.2.4.0.13.1.4.2252867.10.196.122.108.918011220190422223633].
: org.dcm4che3.net.service.DicomServiceException: Retention Period of Study not yet expired.
    at org.dcm4chee.arc.store.impl.StoreServiceEJB.checkExpirationDate(StoreServiceEJB.java:413)
    at org.dcm4chee.arc.store.impl.StoreServiceEJB.rejectInstances(StoreServiceEJB.java:357)
    at org.dcm4chee.arc.store.impl.StoreServiceEJB.updateDB(StoreServiceEJB.java:215)
    at sun.reflect.GeneratedMethodAccessor110.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at

I've now added a fix to correctly reflect the ExpirationState as FAILED_TO_REJECT, if rejection of expired study/series failed for any reason, so that it shall not be misleading.

You may check values of expiration_date column in your series table in the database for the corresponding study (study_fk). Also check the expiration_date column in your study table for the same study.

As I already mentioned earlier the series.expiration_date shall always be lesser than or equal to study.expiration_date. If your results are otherwise, then it is a different issue altogether which needs to be debugged.

[Docjay]

I've checked my series table against one study in my study table.  The 'expiration_date' for all of the series is 'null'.

Is there a way to update all of these old series to reflect the same expiration_date for its parent study?

The study I checked was a study that was on the system prior to 5.16.0, and then after to 5.16.2

[vrinda...@j4care.com]

- I've checked my series table against one study in my study table.  The 'expiration_date' for all of the series is 'null'.

Ok, this clarifies and confirms that series.expiration_date is not greater than study.expiration_date i.e the expiration is set only on study level. But this fails to explain why Rejection Service threw the following error

2019-05-02 00:03:29,132 WARN  [org.dcm4chee.arc.delete.impl.RejectExpiredStudiesScheduler] (EE-ManagedScheduledExecutorService-default-Thread-1) Failed to reject Expired Study[UID=1.2.4.0.13.1.4.2252867.10.196.122.108.918011220190422223633].
: org.dcm4che3.net.service.DicomServiceException: Retention Period of Study not yet expired.
    at org.dcm4chee.arc.store.impl.StoreServiceEJB.checkExpirationDate(StoreServiceEJB.java:413)
    at org.dcm4chee.arc.store.impl.StoreServiceEJB.rejectInstances(StoreServiceEJB.java:357)
    at org.dcm4chee.arc.store.impl.StoreServiceEJB.updateDB(StoreServiceEJB.java:215)

- Is there a way to update all of these old series to reflect the same expiration_date for its parent study?

Not needed, since this indicates that the application of expiration_date was done only on Study level. There was probably no requirement in your application to expire one (or more) series earlier than the study.

What is the value of expiration_date for this study (whose series.expiration_date is null) in your database? Does the provided screenshot correspond to StudyInstanceUID=1.2.4.0.13.1.4.2252867.10.196.122.108.918011220190422223633 ?

[Docjay]

The error above from the server log failed I believe because the expiration date did not meet the 10 day requirement of my retention rule.  It was on the 10th day, yes, but that day wasn't completely over with yet.

the SUID that is mentioned in the server log that you referenced, has a 'expiration_date' of '20190502'.

Earlier, I just randomly checked one study in my database with the study date of '20190410'.  Its SUID = '1.2.4.0.13.1.4.2252867.10.196.122.108.916321020190410003301' and its 'expiration_date' = '20190420', which corresponds to my 10 day retention policy.

I did a count of all studies with a expiration date of 'null' and it came back with '0'

I did a count of all series with an expiration date of 'null' and it came back with '7431'.  Also, the total count of series in the database is '7431'.

Hope this helps

[vrinda...@j4care.com]

- The error above from the server log failed I believe because the expiration date did not meet the 10 day requirement of my retention rule.  It was on the 10th day, yes, but that day wasn't completely over with yet.

That's correct.

As mentioned earlier, the issue should fix the expiration state to be changed from 2 (= REJECTED) to 5 (= FAILED_TO_REJECT) if an issue occurred on failure to reject expired study/series, so it is clearer.

Scheduler picks up only those studies which are expired and whose state is 0 (= UPDATEABLE) or 1 (= FROZEN)

[Docjay]

Vrinda,

   Thanks for the explanation.  After the state changes to '5', how can I get them to change to a '0' so that they can be picked up and deleted?

[vrinda...@j4care.com]

Currently we don't have any requirement that scheduler shall pick FAILED_TO_REJECT (= 5) expired study/series again and retry.

The only workaround available for now is to use RESTful Service to update Expiration Date (you can set past date same as currently displayed for your expired study). The Expiration State will be set to UPDATEABLE (= 0), which will be then picked by RejectExpiredStudiesScheduler. 

This workaround (for your affected studies) you can do even now, without waiting for the issue fix, which shall change the state from REJECTED (= 2) to UPDATEABLE (= 0).

[Docjay]

Virinda,

    Perfect - thank you!

I went ahead an ran this update statement in MySQL

update d4c5.study
set expiration_state = 0
where expiration_state = 2;