Deleting queues containing many records is slow, can time out

[Jeff Davis]

Evergreen 2.8.1

Deleting an import queue can be very slow if the queue contains many records. On our system, deleting a queue containing 136 bib records (via MARC Batch Import/Export > Inspect Queues) timed out. Here's Postgres EXPLAIN output for the underlying DELETE query:

EXPLAIN ANALYZE DELETE FROM vandelay.bib_queue WHERE id = 3529;
                                                           QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------
 Delete on bib_queue (cost=0.28..6.30 rows=1 width=6) (actual time=0.143..0.143 rows=0 loops=1)
   -> Index Scan using bib_queue_pkey on bib_queue (cost=0.28..6.30 rows=1 width=6) (actual time=0.076..0.077 rows=1 loops=1)
         Index Cond: (id = 3529)
 Planning time: 0.714 ms
 Trigger for constraint queued_bib_record_queue_fkey on bib_queue: time=958.881 calls=1
 Trigger for constraint acq_lineitem_history_queued_record_fkey on queued_bib_record: time=63388.685 calls=136
 Trigger for constraint lineitem_queued_record_fkey on queued_bib_record: time=10015.377 calls=136
 Trigger for constraint bib_match_queued_record_fkey on queued_bib_record: time=3616.050 calls=136
 Trigger for constraint import_item_record_fkey on queued_bib_record: time=1477.384 calls=136
 Execution time: 79458.309 ms
(10 rows)

As you can see, the DELETE took almost 80 seconds, mainly because the queued bib records are deleted via cascade and there are a lot of unindexed foreign key references to vandelay.queued_bib_record in other tables.

After adding indexes to those foreign key references, the main DELETE query sped up substantially:

EXPLAIN ANALYZE DELETE FROM vandelay.bib_queue WHERE id = 3529;
                                                           QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------
 Delete on bib_queue (cost=0.28..6.30 rows=1 width=6) (actual time=0.137..0.137 rows=0 loops=1)
   -> Index Scan using bib_queue_pkey on bib_queue (cost=0.28..6.30 rows=1 width=6) (actual time=0.071..0.072 rows=1 loops=1)
         Index Cond: (id = 3529)
 Planning time: 0.606 ms
 Trigger for constraint queued_bib_record_queue_fkey on bib_queue: time=14.217 calls=1
 Trigger for constraint acq_lineitem_history_queued_record_fkey on queued_bib_record: time=4.922 calls=136
 Trigger for constraint lineitem_queued_record_fkey on queued_bib_record: time=6.291 calls=136
 Trigger for constraint bib_match_queued_record_fkey on queued_bib_record: time=3.237 calls=136
 Trigger for constraint import_item_record_fkey on queued_bib_record: time=2.235 calls=136
 Execution time: 31.199 ms
(10 rows)

I'll push a commit momentarily that adds those indexes.

[Jeff Davis (jdavis-sitka)]

See the top commit in this branch:

http://git.evergreen-ils.org/?p=working/Evergreen.git;a=shortlog;h=refs/heads/user/jeffdavis/lp1479953-delete-bib-queue-speedup

[Martha Crawley (mcrawley)]

Would also like to be able to delete acquisitions queues.

[Kathy Lussier (klussier)]

Hi Martha,

The problem with deleting acquisitions queues was fixed in https://bugs.launchpad.net/evergreen/+bug/1289486.

If you continue to have the problem on a release that has the above fix, then I recommend filing a new bug since it is a separate problem than the one identified in this bug report.

Cheers!
Kathy

[Kathy Lussier (klussier)]

These timeouts have also been a problem at a couple of our sites.

I just tested Jeff's patch with a queue containing 1000 records. Pre-patch, it took more than 18 seconds to delete the queue. Post-patch, it tooks a little more than three seconds to delete it.

Signoff branch is available at

http://git.evergreen-ils.org/?p=working/Evergreen.git;a=shortlog;h=refs/heads/user/kmlussier/lp1479953-delete-bib-queue-speedup

Is this code considered to be a new feature? If so, we'll need a release notes entry.

[Jason Stephenson (jstephenson)]

Works for me! We got a roughly 5x speedup in queue deletion after adding the indexes.

Signed off and pushed to master for 2.9.