Bug 38646 - C4::Languages::getLanguages is very unreasonably slow (100+ ms)
Summary: C4::Languages::getLanguages is very unreasonably slow (100+ ms)
Status: Pushed to main
Alias: None
Product: Koha
Classification: Unclassified
Component: Searching (show other bugs)
Version: Main
Hardware: All All
: P5 - low normal
Assignee: Michał
QA Contact: Martin Renvoize (ashimema)
URL:
Keywords: additional_work_needed
Depends on:
Blocks:
 
Reported: 2024-12-06 14:58 UTC by Michał
Modified: 2025-01-31 14:21 UTC (History)
8 users (show)

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


Attachments
[PATCH] Bug 38646: rewrite C4::Languages::getLanguages to use a single cachable SQL query (7.43 KB, patch)
2024-12-06 15:06 UTC, Michał
Details | Diff | Splinter Review
Bug 38646: rewrite C4::Languages::getLanguages to use a single cachable SQL query (7.50 KB, patch)
2025-01-07 16:47 UTC, Martin Renvoize (ashimema)
Details | Diff | Splinter Review
Bug 38646: (QA folllow-up) Fix ONLY_FULL_GROUP_BY (1021 bytes, patch)
2025-01-07 16:47 UTC, Martin Renvoize (ashimema)
Details | Diff | Splinter Review
Bug 38646: Improve unit test coverage (5.12 KB, patch)
2025-01-08 11:34 UTC, Martin Renvoize (ashimema)
Details | Diff | Splinter Review
Bug 38646: rewrite C4::Languages::getLanguages to use a single cachable SQL query (7.50 KB, patch)
2025-01-08 11:34 UTC, Martin Renvoize (ashimema)
Details | Diff | Splinter Review
Bug 38646: (QA folllow-up) Fix ONLY_FULL_GROUP_BY (1021 bytes, patch)
2025-01-08 11:34 UTC, Martin Renvoize (ashimema)
Details | Diff | Splinter Review
Bug 38646: Improve unit test coverage (5.26 KB, patch)
2025-01-08 13:47 UTC, Martin Renvoize (ashimema)
Details | Diff | Splinter Review
Bug 38646: rewrite C4::Languages::getLanguages to use a single cachable SQL query (7.50 KB, patch)
2025-01-08 13:47 UTC, Martin Renvoize (ashimema)
Details | Diff | Splinter Review
Bug 38646: (QA follow-up) Fix ONLY_FULL_GROUP_BY (1020 bytes, patch)
2025-01-08 13:47 UTC, Martin Renvoize (ashimema)
Details | Diff | Splinter Review
Bug 38646: Update unit test for change (1.99 KB, patch)
2025-01-08 13:47 UTC, Martin Renvoize (ashimema)
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Michał 2024-12-06 14:58:31 UTC
My profiling with NYTProf has found that the call to C4::Languages::getLanguages is unreasonably slow, taking over 100 ms (and that's just on a single call of it apparently!!!). Indeed, the way it's coded, it'd run over 540 SQL queries for no good reason, slowing the already slow catalog search page loading further down.

This patch is gonna replace the inefficient and complicated function logic with proper SQL statement that joins the relevant functions. It also fixes the bug where user's native language would be displayed with native language in the parenthesis as well, such as "Polski (Polski)" instead of just "Polski".

The whole query is pretty fast and it gets cached by MySQL server, meaning it's runtime is measured in microseconds instead of hundreds of miliseconds, making it easily a 1000x+ improvement.

The nested CASE statements are a bit verbose, but not too bad, I figured it might be better to do that rather than select all the vars as temporary columns and later remove them or re-create the new object to return. Instead, no temporary variables that one has to remove will linger...

Please note that I didn't test the actual code since I don't have a working ktd installation by hand, but I did test the SQL statement thoroughly.
Comment 1 Michał 2024-12-06 15:06:13 UTC
Created attachment 175262 [details] [review]
[PATCH] Bug 38646: rewrite C4::Languages::getLanguages to use a single cachable SQL query
Comment 2 Michał 2024-12-06 15:07:46 UTC
Also I was thinking of alternative approach to handle AdvancedSearchLanguages, but it seemed more sketchy and with ~200 langs performance of FIND_IN_SET shouldn't be any problem whatsoever.

The alternative idea was:

    my @search_langs;
    my $language_list_cond = '';
    my $language_list = $isFiltered ? C4::Context->preference("AdvancedSearchLanguages") : undef;
    if ($language_list) {
        @search_langs = split(/,|\|/, $language_list);
        my $params = join ', ' => ('?') x @search_langs;
        $language_list_cond = 'AND language_rfc4646_to_iso639.iso639_2_code IN ($params)';
    }

#...

    -- Grab ISO code for language
    INNER JOIN language_rfc4646_to_iso639
    ON language_rfc4646_to_iso639.rfc4646_subtag = language_subtag_registry.subtag
    AND language_rfc4646_to_iso639.iso639_2_code IS NOT NULL
    ${language_list_cond}

#...

    if ($language_list) {
        $sth->execute(@search_langs, $current_language);
    } else {
        $sth->execute($current_language);
    }

^Unless someone believes the above is better?
Comment 3 David Nind 2024-12-06 22:36:53 UTC
Hi Michal,

Thanks for working on improving the performance, and submitting a patch!

I can't comment on the code and approach, but I'm sure others will!

I mainly help with testing bugs and signing them off before they go to QA.

If you could add a test plan, that would be great. This should ideally set out how to replicate the issue, apply the patch, and then show how it fixes or improves things.

See the commit message guidelines for what to include https://wiki.koha-community.org/wiki/Commit_messages

Feel free to ask on the bug if you need any help, or on the Koha Community's Development chat channel https://chat.koha-community.org/

Some other links: 
- Most Koha developers use koha-testing-docker (KTD) for their development environment - it gives you a complete Koha environment with all the required tools including a working instance and sample data, see https://gitlab.com/koha-community/koha-testing-docker
- This page about the development workflow may be useful if you are unfamiliar with how Koha does things https://wiki.koha-community.org/wiki/Development_workflow


David Nind
Comment 4 Fridolin Somers 2024-12-09 11:58:18 UTC
Whooo good catch, I will try
Comment 5 Martin Renvoize (ashimema) 2025-01-07 16:28:57 UTC
I'm afraid we have a test failure here:

C4::Languages::getLanguages(): DBI Exception: DBD::mysql::st execute failed: Non-grouping field 'iso639_2_code' is used in HAVING clause at t/db_dependent/Languages.t line 46

Remember we have ONLY_FULL_GROUP_BY enabled on SQL connections for the test suite.. hopefully it's a simple fix without degrading the performance gain to much.

I'd love to see a benchmark too.. failing QA for now for the failing test.
Comment 6 Martin Renvoize (ashimema) 2025-01-07 16:47:08 UTC
Created attachment 176207 [details] [review]
Bug 38646: rewrite C4::Languages::getLanguages to use a single cachable SQL query

My profiling with NYTProf has found that the call to C4::Languages::getLanguages is unreasonably slow, taking over 100 ms (and that's just on a single call of it apparently!!!). Indeed, the way it's coded, it'd run over 540 SQL queries for no good reason, slowing the already slow catalog search page loading further down.

This patch is gonna replace the inefficient and complicated function logic with proper SQL statement that joins the relevant functions. It also fixes the bug where user's native language would be displayed with native language in the parenthesis as well, such as "Polski (Polski)" instead of just "Polski".

The whole query is pretty fast and it gets cached by MySQL server, meaning its runtime is measured in microseconds instead of hundreds of miliseconds, making it easily a 1000x+ improvement.

Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 7 Martin Renvoize (ashimema) 2025-01-07 16:47:11 UTC
Created attachment 176208 [details] [review]
Bug 38646: (QA folllow-up) Fix ONLY_FULL_GROUP_BY

We can use a plain AND in the WHERE clause here rather than requireing a
HAVING.

Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 8 Martin Renvoize (ashimema) 2025-01-07 17:52:40 UTC
Working on a straight QA here whilst my head is in it... TDQA (Test Driven QA ;P - I.e I'm currently ensuring we have more comprehensive tests here.
Comment 9 Michał 2025-01-07 18:09:22 UTC
Awesome, thank you. I regret a bit not doing comparison benchmarks right away with the improved functions or not writing down how I got NYTProf working with Plack right away, while now I don't have access to the dev machine with the setup for some time.

As for the tests, since you mention you want to expand them, a bit of a joke but a bit of actually serious idea: there could be some test that'd measure how many SQL queries some given function resulted in being made, or how long in total they took. That could have the potential to catch some regressions. Of course a simple example is this very function where a test could say it expects no more than say 5 sql queries to be run under it, rather than few hundred. But it could expand to some other more advanced code paths and call chains, where a regression suddenly causing something to be way less efficient could otherwise be much harder to catch (if some unrelated function suddenly calls something that would do many more queries down the call chain after a change, where at the time of coding the other function things were okay there). Would that make any sense?
Comment 10 David Cook 2025-01-07 23:40:44 UTC
This looks good at a glance. I'm all for database call performance improvements :D
Comment 11 David Cook 2025-01-07 23:45:42 UTC
Another thing to note... getLanguages() is called both when loading the advanced search and when running a search and getting the results, but the output of this function is only ever used by the advanced search.

We should move this function / wrap it in a $template_type check like we do with other functions that are only used in 1 of the 2 modes.

It would actually be interesting to do a thoroughly analysis of the search.pl and opac-search.pl to see how much code could be moved into these types of conditions to further increase performance. 

I'll raise a separate ticket for that, since it's not intrinsically related to this one...
Comment 12 David Cook 2025-01-07 23:59:07 UTC
(In reply to David Cook from comment #11)
> Another thing to note... getLanguages() is called both when loading the
> advanced search and when running a search and getting the results, but the
> output of this function is only ever used by the advanced search.

(In reply to Martin Renvoize (ashimema) from comment #5)
> I'd love to see a benchmark too.. failing QA for now for the failing test.

So I just did a patch... and the performance difference when running catalogue/search.pl with getLanguages() and without getLanguages() is negligible in koha-testing-docker. 

I had runs where it was slower running without getLanguages(), so I can't attribute the presence/absence of getLanguages() to any speed differences.

That said... I think it's a good idea to reduce our volume of DB calls wherever possible, and maybe with a Koha DB under load you'd see a noticeable speed difference.
Comment 13 David Cook 2025-01-08 00:10:23 UTC
(In reply to David Cook from comment #12)
> (In reply to Martin Renvoize (ashimema) from comment #5)
> > I'd love to see a benchmark too.. failing QA for now for the failing test.
> 
> So I just did a patch... and the performance difference when running
> catalogue/search.pl with getLanguages() and without getLanguages() is
> negligible in koha-testing-docker. 
> 
> I had runs where it was slower running without getLanguages(), so I can't
> attribute the presence/absence of getLanguages() to any speed differences.
> 
> That said... I think it's a good idea to reduce our volume of DB calls
> wherever possible, and maybe with a Koha DB under load you'd see a
> noticeable speed difference.

See also bug 16734. (It looks like that patch was mistakenly never added to Koha despite being marked as pushed, but it's good to see another mention about the performance difference and utility of the change)
Comment 14 David Cook 2025-01-08 00:44:37 UTC
(In reply to Martin Renvoize (ashimema) from comment #8)
> Working on a straight QA here whilst my head is in it... TDQA (Test Driven
> QA ;P - I.e I'm currently ensuring we have more comprehensive tests here.

Good call. I took a look at t/db_dependent/Languages.t and felt like we weren't really testing getLanguages() in a thorough way
Comment 15 Martin Renvoize (ashimema) 2025-01-08 11:34:24 UTC
Created attachment 176227 [details] [review]
Bug 38646: Improve unit test coverage

This patch adds proper coverage of getLanguages() to the existing test
file.

It should pass prior to applying the rest of the patchset of this bug
Comment 16 Martin Renvoize (ashimema) 2025-01-08 11:34:27 UTC
Created attachment 176228 [details] [review]
Bug 38646: rewrite C4::Languages::getLanguages to use a single cachable SQL query

My profiling with NYTProf has found that the call to C4::Languages::getLanguages is unreasonably slow, taking over 100 ms (and that's just on a single call of it apparently!!!). Indeed, the way it's coded, it'd run over 540 SQL queries for no good reason, slowing the already slow catalog search page loading further down.

This patch is gonna replace the inefficient and complicated function logic with proper SQL statement that joins the relevant functions. It also fixes the bug where user's native language would be displayed with native language in the parenthesis as well, such as "Polski (Polski)" instead of just "Polski".

The whole query is pretty fast and it gets cached by MySQL server, meaning its runtime is measured in microseconds instead of hundreds of miliseconds, making it easily a 1000x+ improvement.

Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 17 Martin Renvoize (ashimema) 2025-01-08 11:34:30 UTC
Created attachment 176229 [details] [review]
Bug 38646: (QA folllow-up) Fix ONLY_FULL_GROUP_BY

We can use a plain AND in the WHERE clause here rather than requireing a
HAVING.

Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 18 Martin Renvoize (ashimema) 2025-01-08 11:36:07 UTC
Right.. we now have proper coverage or the expected return.

You mentioned you'd changed the return value so the test fails after applying your patches as expected.

I'm not working through whether I agree with the change as I have a nagging feeling there's a reason for including the additional information consistently.
Comment 19 Martin Renvoize (ashimema) 2025-01-08 13:47:18 UTC
Created attachment 176231 [details] [review]
Bug 38646: Improve unit test coverage

This patch adds proper coverage of getLanguages() to the existing test
file.

It should pass prior to applying the rest of the patchset of this bug
Comment 20 Martin Renvoize (ashimema) 2025-01-08 13:47:21 UTC
Created attachment 176232 [details] [review]
Bug 38646: rewrite C4::Languages::getLanguages to use a single cachable SQL query

My profiling with NYTProf has found that the call to C4::Languages::getLanguages is unreasonably slow, taking over 100 ms (and that's just on a single call of it apparently!!!). Indeed, the way it's coded, it'd run over 540 SQL queries for no good reason, slowing the already slow catalog search page loading further down.

This patch is gonna replace the inefficient and complicated function logic with proper SQL statement that joins the relevant functions. It also fixes the bug where user's native language would be displayed with native language in the parenthesis as well, such as "Polski (Polski)" instead of just "Polski".

The whole query is pretty fast and it gets cached by MySQL server, meaning its runtime is measured in microseconds instead of hundreds of miliseconds, making it easily a 1000x+ improvement.

Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 21 Martin Renvoize (ashimema) 2025-01-08 13:47:24 UTC
Created attachment 176233 [details] [review]
Bug 38646: (QA follow-up) Fix ONLY_FULL_GROUP_BY

We can use a plain AND in the WHERE clause here rather than requireing a
HAVING.

Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 22 Martin Renvoize (ashimema) 2025-01-08 13:47:27 UTC
Created attachment 176234 [details] [review]
Bug 38646: Update unit test for change

This drops the bracketed translation in the tests in
language_description where the bracketed language name matches the
preceeding one.

Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 23 Katrin Fischer 2025-01-10 18:21:13 UTC
Pushed for 25.05!

Well done everyone, thank you!
Comment 24 Jonathan Druart 2025-01-30 08:35:40 UTC
Koha_Main_MDB_Latest is failing since this is pushed

https://jenkins.koha-community.org/job/Koha_Main_MDB_Latest/1441/consoleFull

18:14:30 koha_1       |     #   Failed test 'getLanguages returned the expected results when no parameters are passed, description is "English (Native)"'
18:14:30 koha_1       |     #   at t/db_dependent/Languages.t line 185.
18:14:30 koha_1       |     # Compared $data->[1]{"description"}
18:14:30 koha_1       |     #    got : 'Spanish'
18:14:30 koha_1       |     # expect : 'French'
18:14:30 koha_1       | 
18:14:30 koha_1       |     #   Failed test 'getLanguages returned the expected results when "es" is requested, description is "Spanish falling back to English when missing (Native)"'
18:14:30 koha_1       |     #   at t/db_dependent/Languages.t line 193.
18:14:30 koha_1       |     # Compared $data->[1]{"description"}
18:14:30 koha_1       |     #    got : 'Spanish'
18:14:30 koha_1       |     # expect : 'French'
18:14:30 koha_1       | 
18:14:30 koha_1       |     #   Failed test 'getLanguages returned the expected results when "fr" is requested, description is "French (Native)"'
18:14:30 koha_1       |     #   at t/db_dependent/Languages.t line 203.
18:14:30 koha_1       |     # Compared $data->[1]{"description"}
18:14:30 koha_1       |     #    got : 'Spanish'
18:14:30 koha_1       |     # expect : 'French'
18:14:30 koha_1       |     # Looks like you failed 3 tests of 5.
18:14:30 koha_1       | 
18:14:30 koha_1       | #   Failed test 'getLanguages()'
18:14:30 koha_1       | #   at t/db_dependent/Languages.t line 224.
18:14:30 koha_1       | # Looks like you failed 1 test of 22.
18:14:30 koha_1       | [17:11:59] t/db_dependent/Languages.t
Comment 25 Michał 2025-01-30 09:06:36 UTC
That's really weird in principle since these tests were added by Martin together with the change in this exact bug, I assume he tested them to pass before attaching.
Comment 26 Jonathan Druart 2025-01-30 09:37:37 UTC
(In reply to Michał from comment #25)
> That's really weird in principle since these tests were added by Martin
> together with the change in this exact bug, I assume he tested them to pass
> before attaching.

They are only failing on "Koha_Main_MDB_Latest", which use the latest version of MariaDB, not the default we use in ktd.
Comment 27 Michał 2025-01-30 09:51:13 UTC
Okay then my guess right now for most likely cause is that `cmp_deeply` expects the array elements to be in the same order in $languages as $expected. And order of elements inside of actual objects doesn't matter, so it's possible `description` just happens to be first.

I don't see any other logical explanation. This is what I expected, but wasn't sure why, MariaDB version upgrade sounds like very plausible cause.

If you or someone would happen to have environment set up, they should either inspect the output of getLanguages with these sample data entered, or just actually view the tables and/or run the query from getLanguages. My hunch is that iirc especially since there's no numerical id in these columns, that the order of elements being returned is an explicit implementation detail of the DB server which shouldn't matter.

So a fix could be to find or create a test function that'd compare equality of arrays without regard to the order of elements. And I think neither the new or old getLanguages had anything that'd reorder languages from what the DB returned. Which suggests that it'd have regressed regardless of whether my patch was implemented, it's just that the new tests from Martin caught that.

So if that's the cause, then we could either:
- make tests not care about the order
- make getLanguages query explicitly sort by modifying the SQL query

And actually the latter might be more preferable now that I think about it, since the order could mess up how languages are shown in Koha interfaces on language lists!! (In one of the libraries I've heard some complaints about some language lists being out of order, on older Koha version, but I wasn't personally looking into the causes, interesting to note though)

And indeed I just checked on koha-staging and also on 24.11 (so before and after patch!), on /cgi-bin/koha/opac-search.pl, language list is definitely wrong and not ordered by anything logical!!! (and the order is different on different servers) So we should probably make a patch to sort it actually and keep the deep comparison func.

Now backporting a fix would be annoying, since this bug is classified as enhancement. So we either backport this + a fix, or we make two fixes targetting separately main and stable branches... (there's behavior change for displaying "English" instead of "English (English)", so it's not really a pure bug fix, if we consider bad performance a bug)
Comment 28 Katrin Fischer 2025-01-31 14:21:16 UTC
I am sorry, pretty busy so can't really dig in here. 

What are we missing for a patch? Could we patch the current failing test on main?