invalid date error - unable to retrieve hold

[Ben Shum]

Evergreen version: 2.0.10
OpenSRF version: 2.0.1
PostgreSQL version: 8.4
Linux distribution: Ubuntu Lucid 10.04

Every once in awhile, our libraries end up with holds that are not retrievable. They sit there stuck on retrieving until a network error occurs. What follows is an example failure message:

Wed Dec 14 2011 16:37:33 GMT-0500 (Eastern Standard Time)

Error retrieving details for hold #2140200

{
"payload":
[

]
,
"debug":"osrfMethodException : *** Call to
[
open-ils.circ.hold.details.retrieve.authoritative
]
failed for session
[
1323898643.581005.13238986437274
]
,
thread trace
[
1
]
:\nInvalid date format: at /usr/share/perl5/Error.pm line 416.\n\n",
"status":500
}

Presumably, when reading that we can assume that it's a hold with an ID of 2140200, but the error of "Invalid date format" is troublesome. Thus far, our only recourse has been to manually edit the hold in the database to cancel it and start over to view the given hold entry. Guessing that something in one of the fields must be corrupted.

Related timestamps:

From action.hold_request:

request_time: 2011-10-27 06:50:02-04
capture_time: 2011-11-16 09:23:34.424896-05
prev_check_time: 2011-11-16 01:05:14-05
shelf_time: NULL
shelf_expire_time: NULL

From action.hold_transit_copy:

source_send_time: 2011-11-16 09:23:34.424896-05
dest_recv_time: NULL

So it looks like the item is still in-transit to the pickup library, but the hold is still not viewable.

Thus far, the only way to get the hold viewable again has been to cancel the hold by inputting via the database a value for the "cancel_time" field, usually accompanied in our case with a cancel_cause and cancel_note for reference of the bug.

This kind of problem was reported in IRC previously as well: http://open-ils.org/irc_logs/evergreen/2011-09/%23evergreen.12-Mon-2011.log

[Steve Callender (stevecallender)]

I ran across this today as well.

From what I can determine, a hold was created. An item that went into transit to fulfill the hold. After the transit was started, and the transit entry was created, the hold was reset and a new item was used to fulfill the hold. The original hold transit was never aborted.

So in the holds screen, the new item was put on the holds shelf making the hold ready for pickup, but yet there was still the phantom transit out there from the original item coming over to fulfill the hold. This confused the system, as it knows there is an item on the holds shelf but it also sees an open transit for the hold at the same time and it gets the invalid date from the null received time on action.hold_transit_copy.

To fix the holds view, I just manually stamped the received time on the transit and changed the original items status back to 0 (available).

[Galen Charlton (gmc)]

In particular, this occurs only when the pickup OU has the circ.hold_shelf_status_delay org unit setting set to a value, as otherwise the code doesn't try to add that interval to the null transit receive time.

So, to sum up the criteria, the problem can occur if:

- a hold has a captured item...
- the captured item has status 8 (on hold shelf)
- there is another item that is currently in transit to fill the hold
- the pickup library (or one of its ancestors) has the circ.hold_shelf_status_delay library setting set.

[Galen Charlton (gmc)]

A patch to fix the exception is available at the tip of the user/gmcharlt/lp904581_comfort_confused_holds branch in the working/Evergreen repository:

http://git.evergreen-ils.org/?p=working/Evergreen.git;a=shortlog;h=refs/heads/user/gmcharlt/lp904581_comfort_confused_holds

Note that the patch doesn't do anything to address the causes of the phantom transits, it just avoids taking them into account when computing the hold status.

[Ben Shum (bshum)]

Assigning to be tested and pushed during the next 2.7 maintenance release.

[Ben Shum (bshum)]

Pushed to master, rel_2_7, and rel_2_6. Thanks Galen.