double-scan during check-in still troublesome

[Jason Etheridge]

This is similar to https://bugs.launchpad.net/evergreen/+bug/902255

In this scenario, on EG 2.7.2, the first scan created a hold transit, and the second scan may have created a second transit to the home library. I say "may have", because the UI indicated that a second transit was created and the logs also show this, but there is no corresponding entry in the action.transit_copy table (and no error in the logs), but there is a gap in the sequence matching the logged Identity value for the transit.

Still problematic one way or the other.

[Meg Stroup (mstroup)]

We're seeing this behavior in SCLENDS, 3.1.6.

A book from library X arrives at Y. Y checks the book out to their patron, and the patron returns it. Library Y is unable to check the book in.

[Lugene Shelly (lugene)]

I handle support for PaILS, and we recently had two SPARK libraries report the issue within days of each other. We're on 3.1.6.

Dale at Equinox checked our logs and found double checkin scans on the items in question. When the items were checked in, Evergreen only closed one of the transit records and tried to place the items into transit to send them home. Since an open transit record was already present, Evergreen could not create another transit record and the error message caused it to bail out of the entire checkin. Here is one of the error messages:

[INFO:6560:Circulate.pm:587:1541261361169722946] circulator: pushing event DATABASE_UPDATE_FAILED
osrf_sys.09.log.gz:2018-11-05 09:31:16 node3.grp10.v31 open-ils.circ [INFO:6560:Circulate.pm:573:1541261361169722946] circulator: BAILING OUT
osrf_sys.09.log.gz:2018-11-05 09:31:16 node3.grp10.v31 open-ils.circ [INFO:6560:Circulate.pm:293:1541261361169722946] circulator: bailing out with events: DATABASE_UPDATE_FAILED

[Robert J Jackson (rjackson-deactivatedaccount)]

Here at Evergreen Indiana we have just upgraded to the most recent web client as of 11/18/2018. So far there have been 3 reports of items not checking in. The staff do not receive any indication of a problem. Log checking indicates an error with the action.transit_copy table. Review of the table shows an open transit for a checked out item. Further review shows there are duplicate rows for the actual transit involved. Deletion or closing of the transit by setting a dest_recv_time resolves the issue for the particular check in.

It looks like we have 48 potential issues outstanding at this time:

evergreen=# select count(a.id) from asset.copy a, action.transit_copy b where a.status = 1 and a.deleted = 'f' and a.id = b.target_copy and b.dest_recv_time is null and b.cancel_time is null;
-[ RECORD 1 ]
count | 48

[Robert J Jackson (rjackson-deactivatedaccount)]

Here is the corresponding log entry indicating error attempting to create a transit (so this appears to come into play on items checking in, having an open transit entry and trying to fill an existing hold):

2018-11-20 16:38:29 app12-prod open-ils.cstore: [ERR :30099:oils_sql.c:2522:zzz] open-ils.cstore ERROR inserting action::transit_copy object using query [INSERT INTO action.transit_copy (copy_status,dest,dest_recv_time,id,persistant_transfer,prev_hop,source,prev_dest,source_send_time,target_copy,cancel_time) VALUES (7,353,DEFAULT,DEFAULT,DEFAULT,DEFAULT,337,DEFAULT,'now',34206506,DEFAULT);]: 41990401 41990401: ERROR: Copy id=34206506 is already in transitCONTEXT: PL/pgSQL function action.copy_transit_is_unique() line 8 at RAISE

[Michele Morgan (mmorgan)]

Marking this as a duplicate of lp 1819542.

The original report goes back to the xul client, but all the comments relate to release 3.1.6, where a uniqueness constraint on action.transit_copy was introduced by the fix for lp 1787274. Lp 1819542 more concisely describes the problem related to the comments on this bug.