Evergreen

Deleting patrons can exceed staff client timeouts

Bug #1758160 reported by Blake GH
18
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Evergreen
Fix Released
Undecided
Unassigned
Evergreen 3.1.3
3.0
Fix Released
Undecided
Unassigned
Evergreen 3.0.9

Bug Description

It's possible for patrons with a large number of circulations and other related things to cause postgres to take to long to get results back to the OpenSRF call.

The logs show this:
open-ils.cstore.json_query.atomic {"from":["actor.usr_delete",PATRONID,null]}

The subsequent query is:

select from actor.usr_delete(PATRONID,null)

That query will do many things. One of which is calling:
perform actor.usr_purge_data( src_usr, dest_usr );

which eventually calls
DELETE FROM action.circulation WHERE usr = src_usr;
followed by

  BEFORE DELETE
  ON action.circulation
  FOR EACH ROW
  EXECUTE PROCEDURE action.age_circ_on_delete();

There is a slowness here. I executed explain analyze DELETE FROM action.circulation WHERE usr = TESTUSERID;

and I found that
Trigger for constraint usr_circ_history_source_circ_fkey: time=116932.556 calls=978

Took the lions share of the time. This lead me to create and index

CREATE INDEX action_usr_circ_history_source_circ_idx
  ON action.usr_circ_history
  USING btree
  (source_circ);

And viola - the same explain analyze

Trigger for constraint usr_circ_history_source_circ_fkey: time=13.212 calls=978

Branch soon.

Revision history for this message
Blake GH (bmagic) wrote :

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

tags: added: pullrequest
Dan Wells (dbw2)
Changed in evergreen:
milestone: none → 3.1.1
status: New → Confirmed
Revision history for this message
Dan Wells (dbw2) wrote :

Blake, thanks for this fix! Just a note, the branch has the upgrade script, but it still needs to add the same thing to the main schema files somewhere.

Revision history for this message
Blake GH (bmagic) wrote :

Oops! I knew that. Push forced, same link.

Evergreen Bug Maintenance (bugmaster)
Changed in evergreen:
milestone: 3.1.1 → 3.1.2
Revision history for this message
Michele Morgan (mmorgan) wrote :

This patch did not do the trick in my testing. Attempts to delete *some* patrons still times out in the client.

Here's an EXPLAIN ANALYZE for one such patron subsequent to applying the patch :

EXPLAIN ANALYZE delete from action.circulation where usr = 2082592;

                                                QUERY PLAN
--------------------------------------------------------------------------------------------------------
 Delete on circulation (cost=0.44..951.43 rows=481 width=6) (actual time=532.420..532.420 rows=0 loops=1)
   -> Index Scan using circ_all_usr_idx on circulation (cost=0.44..951.43 rows=481 width=6) (actual time=0.234..19.172 rows=1313 loops=1)
         Index Cond: (usr = 2082592)
 Planning time: 1.751 ms
 Trigger for constraint circulation_limit_group_map_circ_fkey: time=59.308 calls=1261
 Trigger for constraint usr_circ_history_source_circ_fkey: time=156220.717 calls=1261
 Trigger action_circulation_aging_tgr: time=505.381 calls=1313
 Trigger age_parent_circ: time=6492.583 calls=1261
 Trigger mat_summary_remove_tgr: time=133.659 calls=1261
 Execution time: 163442.200 ms
(10 rows)

It is interesting to note that this patron has zero rows in action.usr_circ_history.

Leaving the pullrequest tag in place and would welcome other testers.

Evergreen Bug Maintenance (bugmaster)
Changed in evergreen:
milestone: 3.1.2 → 3.1.3
Revision history for this message
Jason Boyer (jboyer) wrote :

For me this issue addresses both user purging and circ aging. I've got a signoff branch with tweaked upgrade script here: http://git.evergreen-ils.org/?p=working/Evergreen.git;a=shortlog;h=refs/heads/user/jboyer/lp1758160_auch_index_signoff working/user/jboyer/lp1758160_auch_index_signoff

I'll also mark my bug about aging circs as a duplicate of this one.

tags: added: signedoff
Revision history for this message
Jason Stephenson (jstephenson) wrote :

I have also been testing this patch and it works for me, too. I have seen an 80% drop in the time to age circulations and a 75% drop in the time to purge users on my test database with this index added.

Michele's comment raises a valid concern, but I think adding the index is better than nothing at this point. We can always revisit the performance of this later if something else comes up.

I have signed off and pushed this to master, rel_3_1, and rel_3_0 for posterity.

Changed in evergreen:
status: Confirmed → Fix Committed
Evergreen Bug Maintenance (bugmaster)
Changed in evergreen:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.