Bug 38181 - Extreme slow search results on OPAC (only) search when result records contain multiple items.
Summary: Extreme slow search results on OPAC (only) search when result records contain...
Status: CONFIRMED
Alias: None
Product: Koha
Classification: Unclassified
Component: Searching (show other bugs)
Version: 24.05
Hardware: All All
: P5 - low normal
Assignee: Bugs List
QA Contact: Testopia
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2024-10-15 21:42 UTC by Kdask
Modified: 2024-10-22 22:36 UTC (History)
2 users (show)

See Also:
Change sponsored?: ---
Patch complexity: ---
Documentation contact:
Documentation submission:
Text to go in the release notes:
Version(s) released in:
Circulation function:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Kdask 2024-10-15 21:42:41 UTC
When performing a search on the OPAC, if the results containing records that are having a large number of holdings (e.g serials with over 1000 issues/items or even less) there is a huge delay on showing the results (~x8 times slower for the same search if we remove the multiple items from the resulting records)

The odd is that the exact same search on the intranet interface works without these delays so I'm guessing that this is a problem on the OPAC search implementation?

The problem exists with zebra but also with the use of Elasticsearch engine.
Using elasticsearch tried also removing all the item related indexes - 952* subfields (and re-indexing) but the result is the same.

In the following google drive link you can find a demo bib record with 1809 items (MarcXML - Marc21) if it helps to reproduce it.https://drive.google.com/file/d/11SQmfdWal9tzcovS0mrgu6vIOPf1aCbc/view
You will have to import the record, and then try searching for the title on OPAC: The Journal of biological chemistry.

In my case with a decent server without load (Debian, 4cpu cores, 16gb RAM) with plack enabled takes about ~50sec to get the result.

Regards
Comment 1 David Cook 2024-10-15 23:17:30 UTC
Are you using the OpacHiddenItems system preference?

There are OPAC-only system preferences that implement post-processing to search results, which can have considerable negative effects.

This issue might be a duplicate of bug 36261
Comment 2 Kdask 2024-10-16 01:37:16 UTC
Interesting, i don't use the OpacHiddenItems preference (it's empty)
although the OpacHiddenItemsHidesRecord was on "hide".
I'm using OpacSuppression on bibliographic records on 942$n.

I tried setting OpacHiddenItemsHidesRecord (and OpacSuppression) to -> Don't hide, re-indexed, restarted but still the same, both zebra and elasticsearch.
Comment 3 David Cook 2024-10-16 01:48:58 UTC
(In reply to Kdask from comment #2)
> Interesting, i don't use the OpacHiddenItems preference (it's empty)
> although the OpacHiddenItemsHidesRecord was on "hide".
> I'm using OpacSuppression on bibliographic records on 942$n.

That's interesting for sure. OpacSuppression wouldn't cause a slowdown, and OpacHiddenItemsHidesRecord shouldn't matter if OpacHiddenItems isn't used.

--

The hidelostitems might be impacting you, as I think it scans through every lost item, although I could be wrong. 

--

I know I've had the same problem as you before... and I think those 2 were the causes, but it might've been something else. 

Ah... yes... it might have to do with reserves. I don't know if there's an open bug or not about that (I can't find one on a quick search in my bug lists), but on the OPAC only there is very inefficient code which checks the reservability of every item. 

Locally, we removed a bit of the item processing in the OPAC for reserves specifically and had enormous performance improvements.
Comment 4 David Cook 2024-10-16 02:01:57 UTC
I don't have time at the moment, but let me see if I can find any obvious details...

I think it was in C4/XSLT.pm:

    # grab the XML, run it through our stylesheet, push it out to the browser
    my $itemsxml;
    if ( $xslsyspref eq "OPACXSLTDetailsDisplay" || $xslsyspref eq "XSLTDetailsDisplay" || $xslsyspref eq "XSLTResultsDisplay" ) {
        $itemsxml = ""; #We don't use XSLT for items display on these pages
    } else {
        $itemsxml = buildKohaItemsNamespace($biblionumber, $hidden_items, $items_rs);
    }

That buildKohaItemsNamespace has some really bad code. 

That said... I think if you have the syspref PassItemMarcToXSLT turned off then you should be fine.
Comment 5 David Cook 2024-10-16 02:04:22 UTC
(In reply to David Cook from comment #3)
> The hidelostitems might be impacting you, as I think it scans through every
> lost item, although I could be wrong. 

Maybe not. At a glance, it looks like that's been switched to just be 1 database query.
Comment 6 David Cook 2024-10-16 02:11:48 UTC
Those were the ideas I had off the top of my head. 

You might have better luck searching for help using the "Koha Chat" or using a "Koha Support Company" (via https://koha-community.org/support/)

In your case, you might need someone to look at your particular system. 

That said, I haven't tried reproducing yet with that demo bib record, but I am curious, since I've tackled this same problem for my own customers (a while ago) using a modified version of Koha.

I'll keep this on my radar in any case...
Comment 7 Katrin Fischer 2024-10-16 07:17:55 UTC
My guess is that your search is fast enough, that's why changing the indexing didn't work. It's the time it takes to process the items for display that is hurting you. PassItemMarcToXSLT and other system preferences related to item display in the result list (not sure if the first does impact results or only detail) might be a good guess.
Comment 8 Kdask 2024-10-17 20:12:55 UTC
Thanks for all the responses.
For the record, PassItemMarcToXSLT is turned off from the beginning.

I'll keep digging, i guess somewhere on the results page the iterating of the items takes too long. Something probably with the item availability/visibility since in intranet is fine.
I have the same behavior in 2 other installations but because there were only 1 or 2 records with lot of items it's quite hard to notice. On this installation there are more than 1000 records with more than ~200 items.
Comment 9 David Cook 2024-10-17 23:08:47 UTC
(In reply to Kdask from comment #8)
> I'll keep digging, i guess somewhere on the results page the iterating of
> the items takes too long. 

I would say so. Unfortunately, it's going to take more digging as you say.

Are you a coder yourself?

--

You know... I just remembered another troubleshooting step that you can take! 

I had the same problem where my staff interface was fast and my OPAC was slow, and even after coding optimizations I couldn't explain it. In fact, even when I tracked the indexing engine (e.g. Zebra), I noticed that the search was slower for the OPAC!

And the problem was that the "defaultSortField" and "defaultSortOrder" and "OPACdefaultSortField" and "OPACdefaultSortOrder" values were different, so I was actually getting different sorting for what was otherwise the same search query.

When I made those match, my search was equally slow on both the staff interface and the OPAC. And that's because my search results were now including the same bib records with large item holdings.

I know that doesn't help you make the search faster, but it helped me a lot in terms of troubleshooting.

Just another idea.
Comment 10 David Cook 2024-10-17 23:10:43 UTC
(On a side note, with Elasticsearch, if your bib record has a large number of items, and you're using the syspref ElasticsearchMARCFormat set to ISO2709, you'll have problems retrieving your bibs. See bug 27365. I'm hoping in the next few months to create a fix/workaround for that...)
Comment 11 David Cook 2024-10-17 23:13:59 UTC
To help with your troubleshooting, take a look at your koha-conf.xml and look for "zebra_loglevels". You'll want to (temporarily) include "request" in the log levels.

It can be helpful to analyze what exact query is being sent to Zebra for the OPAC and the staff interface. That can help you to ensure both interfaces are getting the same records.

If they are getting the exact same records back from the search engine... then it'll have to be a Koha coding issue.
Comment 12 David Cook 2024-10-17 23:22:06 UTC
You know looking again at C4/XSLT.pm....

I think C4::XSLT::buildKohaItemsNamespace() might actually still cause a problem regardless of PassItemMarcToXSLT...

C4::Search uses PassItemMarcToXSLT to delete all the items from a MARC record retrieved from the search engine before C4::XSLT::XSLTParse4Display runs. 

C4::Search doesn't pass any items_rs to XSLTParse4Display, which means it then does its own DB lookups after all, which includes pre-fetching all reserves.

In my experience, the particularly problematic functions in buildKohaItemsNamespace are "$item->has_pending_hold", "$item->holds->waiting->count", and "$item->get_transfer".
Comment 13 David Cook 2024-10-17 23:37:12 UTC
Yep... I totally forgot that PassItemMarcToXSLT has nothing to do with buildKohaItemsNamespace.

The goal of PassItemMarcToXSLT is to remove the 952 fields to so that what has become the "ExpandCodedFields" processor doesn't do unnecessary work, since the item XML is done using the DB and not the MARCXML anyway.

Which... is actually super significant for future indexing reasons... but I won't get into those...
Comment 14 David Cook 2024-10-17 23:47:25 UTC
The good news is that I am quite confident that I know what the issue is. The OPAC is super slow, because it iterates through every single item in order to determine item status to show in the search results.

The bad news is that I don't currently have a good solution for this problem.

--

For one of my libraries, I've created a customization that skips those 3 problem ORM method calls I mentioned above, and that has saved a lot of time. But that was a hack I did to get better performance quickly for that 1 library...

At a glance, the solution is probably to do 3 database calls per 1 bib which create hashmaps keyed off itemnumber using raw SQL queries, rather than 3 ORM-based database calls per 1 item.

That's probably the solution. 

(If we really wanted to optimize, we could prepare the SQL statements ahead of time, and then just hand the statement handle to XSLTParse4Display, but one things at a time...)
Comment 15 David Cook 2024-10-17 23:48:29 UTC
Since this performance problem is at the Koha end, it's worth noting (for other people reading this report) that it affects both Zebra and Elasticsearch results.
Comment 16 David Cook 2024-10-18 00:00:48 UTC
I have been meaning to address search result slowness for a while... but I've got quite a few things on my plate at the moment.

I'm going to keep this one on my TODO list, and I hope to come back to it soon.

If you are a coder, go to C4/XSLT.pm sub buildKohaItemsNamespace, and look at those 3 method calls:

311         elsif ( $item->has_pending_hold ) {
312             $status = 'other';
313             $substatus = 'Pending hold';
314         }
315         elsif ( $item->holds->waiting->count ) {
316             $status = 'other';
317             $substatus = 'Hold waiting';
318         }
319         elsif ($item->get_transfer) {
320             $status = 'other';
321             $substatus = 'In transit';
322         }

If you can optimize those, that should help a lot. 

If someone else than me can do this work, that would be awesome.

If not, I do plan to come back to it when I can...
Comment 17 Jonathan Druart 2024-10-21 07:41:07 UTC
(In reply to David Cook from comment #16)
> If you can optimize those, that should help a lot. 

See also bug 7012.

We should also store the status of the different items in ES's index.
Comment 18 David Cook 2024-10-21 23:02:23 UTC
(In reply to Jonathan Druart from comment #17)
> (In reply to David Cook from comment #16)
> > If you can optimize those, that should help a lot. 
> 
> See also bug 7012.
> 
> We should also store the status of the different items in ES's index.

Mmm that's interesting.

That said, even if we stored status in the database, it would still be more efficient to run 1 query to get all item statuses rather than running X queries foreach Y items to get their item status.

Thanks for bringing that one to my attention though.
Comment 19 Jonathan Druart 2024-10-22 07:41:26 UTC
(In reply to David Cook from comment #18)
> (In reply to Jonathan Druart from comment #17)
> > (In reply to David Cook from comment #16)
> > > If you can optimize those, that should help a lot. 
> > 
> > See also bug 7012.
> > 
> > We should also store the status of the different items in ES's index.
> 
> Mmm that's interesting.
> 
> That said, even if we stored status in the database, it would still be more
> efficient to run 1 query to get all item statuses rather than running X
> queries foreach Y items to get their item status.

I was suggesting to store them in ES's index.
Comment 20 David Cook 2024-10-22 22:36:04 UTC
(In reply to Jonathan Druart from comment #19)
> I was suggesting to store them in ES's index.

I've got quite a few questions/concerns about that, but I'm not going to get into that right now.