[OPEN-ILS-DEV] Circ History Sorting

[Josh Stompro]

Hello, I'm having trouble with sorting the columns in the my opac, circ history screen.  I've have a 2.10.5 test system setup with all our production data on a single VM.  Maybe the VM just doesn't have enough resources.

I have 226 items in my history when I look at action.usr_circ_history.

Viewing and paging through the history works fine.  It looks like when doing normal viewing and paging the  cstore query is used directly, and it is limited to 15 items per page.

When I click the title column to sort I see the following.  The web page takes about 30 seconds to re-load and says that I have no data in my history.  When looking at atop I see beam.smp go to 100% CPU for 60 seconds, and then and apache process at 100% CPU for 45 seconds.

When I look at the logs I see the following.  It looks like cstore waits 6 seconds for a response and then gives up... but the system must still be pulling in the data and then processing it, even though cstore gave up.
[2016-08-17 15:52:25] /usr/sbin/apache2 [INFO:8529:CStoreEditor.pm:139:1471433103852926] editor[1|127625] request en-US open-ils.cstore.direct.action.user_circ_history.search.atomic [{"usr":127625},{"flesh_fields":{"auch":["target_copy"],"acp":["call_number"],"acn":["record"]},"order_by":{"auch":"xact_start DESC"},"flesh":3},{"substream":1}]
open-ils.cstore 2016-08-17 15:52:25 [INFO:23530:osrf_application.c:1059:1471433103852927] CALL: open-ils.cstore open-ils.cstore.direct.action.user_circ_history.search.atomic {"usr":127625},{"order_by":{"auch":"xact_start DESC"},"flesh":3,"flesh_fields":{"auch":["target_copy"],"acp":["call_number"],"acn":["record"]}},{"substream":1}
open-ils.cstore 2016-08-17 15:52:26 [INFO:23530:osrf_app_session.c:1017:1471433103852927] [open-ils.cstore] sent 1582282 bytes of data to opensrf at private.localhost/client_at_virt-egdev1.larl.org_8529
open-ils.cstore 2016-08-17 15:52:26 [INFO:23530:osrf_stack.c:163:1471433103852927] Message processing duration 0.761759
open-ils.cstore 2016-08-17 15:52:32 [INFO:23530:osrf_prefork.c:496:1471433103852927] No request was received in 6 seconds, exiting stateful session
open-ils.cstore 2016-08-17 15:52:32 [INFO:23530:osrf_app_session.c:1017:1471433103852927] [open-ils.cstore] sent 196 bytes of data to opensrf at private.localhost/client_at_virt-egdev1.larl.org_8529
[2016-08-17 15:53:25] /usr/sbin/apache2 [INFO:8529:CStoreEditor.pm:139:1471433103852927] editor[1|127625] request returned no data : open-ils.cstore.direct.action.user_circ_history.search.atomic
[2016-08-17 15:53:25] /usr/sbin/apache2 [INFO:8529:CStoreEditor.pm:139:1471433103852927] editor[1|127625] rolling back db session
[2016-08-17 15:53:25] /usr/sbin/apache2 [INFO:8529:CStoreEditor.pm:139:1471433103852927] editor[1|127625] request en-US open-ils.cstore.transaction.rollback []

I was looking where the 6 second cstore timeout was set, and all I see in opensrf.xml is the <keepalive> set to 6, is that the timeout?

>From looking at the code for this feature,
http://git.evergreen-ils.org/?p=Evergreen.git;a=commitdiff;h=c8493cabf211ebfd14bfd179923f8bc6622334d9;hp=f1e09f95eb069494e93da74111c91a5788ee369d

It looks like when sorting is enabled, the full list of history items is pulled and the TT code in circ_history.tt2 does the sorting and paging.  So on each page load the entire list of history items needs to be pulled and processed.  So it goes from having to deal with 15 items max, to 250-5000 items.  I just checked our history table and see that the most history someone has is 5000 items.  Is there any chance that this code can deal with 5000 items in a reasonable time period?  It looks like it is fleshing the record, so including the full marcxml data for each of those 5000 items, mainly to pull out the title non filing info, that gets to be a big chunk of data to move around for each page load.

As it is, If I go through and click on each of the sort options while I'm waiting for the page to load, which I can see an impatient patron doing to try to elicit a response from the page, I start a new request for each click.  This causes my test vm to become unresponsive to all other catalog requests, with beam.smp sitting at 300% Cpu usage, so an easy way for a user to DOS the system intentionally or unintentionally.

What would be a good strategy for handling this more efficiently?  Push everything to the database with a custom query that generates the title sort field and negates the need to do processing in circ_history.tt2?  Are there any materialized views that generate a title_sort field already?  Could this data be cached in memcached?

I can see that if I'm really trying to look at my history, I might make a bunch of requests in a short time period, various sorts, and paging through the results, so making this more efficient would help.

Josh


Lake Agassiz Regional Library - Moorhead MN larl.org
Josh Stompro     | Office 218.233.3757 EXT-139
LARL IT Director | Cell 218.790.2110

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://libmail.georgialibraries.org/pipermail/open-ils-dev/attachments/20160818/65c153e5/attachment.html>