I did a profile of opac-search and am going to make a few improvements to it. You can see the results here: http://debian.koha-community.org/~robin/opac-search/ This was run on a production 3.12.2 system, with 10 branches, with a database server on a different machine. This means that database latency is more visible.
Created attachment 21988 [details] [review] Bug 11051 - remove unneccessary SQL queries in GetBranches The way GetBranches was written, it will issue one query to get all branches, and then one query per branch for the branch relations. This patch pre-fetches the relations table (as we need it all anyway) and so makes the whole process happen in two queries, rather than take 1+N, where N is the number of branches. This might not seem like much, but when you do a search, GetBranches is called once for each result, so 25. And you might have 10 branches. This causes 275 database requests when you could get away with 50. From profiling, when you run a search, this is the thing that calls DBI::st::execute the most. Refer: http://debian.koha-community.org/~robin/opac-search/usr-share-koha-lib-C4-Branch-pm-146-line.html#125 Test Plan: * Have a database with branches and relationships between the branches. (these are 'Lubrary groups' in the UI. * Make sure the relationships show up correctly after applying the patch.
Created attachment 21989 [details] [review] Bug 11051 - remove unneccessary SQL queries in GetBranches The way GetBranches was written, it will issue one query to get all branches, and then one query per branch for the branch relations. This patch pre-fetches the relations table (as we need it all anyway) and so makes the whole process happen in two queries, rather than take 1+N, where N is the number of branches. This might not seem like much, but when you do a search, GetBranches is called once for each result, so 25. And you might have 10 branches. This causes 275 database requests when you could get away with 50. From profiling, when you run a search, this is the thing that calls DBI::st::execute the most. Refer: http://debian.koha-community.org/~robin/opac-search/usr-share-koha-lib-C4-Branch-pm-146-line.html#125 Test Plan: * Have a database with branches and relationships between the branches. (these are 'Lubrary groups' in the UI. * Make sure the relationships show up correctly after applying the patch.
Caching on GetMarcStructure seems to actually be slower than running it. Compare: http://debian.koha-community.org/~robin/opac-search/usr-share-koha-lib-C4-XSLT-pm-1282-line.html#78 (uncached) to: http://debian.koha-community.org/~robin/opac-search-cached/nytprof/usr-share-koha-lib-C4-XSLT-pm-1320-line.html#78 (cached) That function has ~1 second difference across all its calls. Removing the memoization of GetMarcStructure should fix this.
Created attachment 21990 [details] [review] Bug 11051 - remove caching of GetMarcStructure Profiling suggests that this is actually ~1s slower with caching enabled, probably due to serialisation overheads. Compare uncached: http://debian.koha-community.org/~robin/opac-search/usr-share-koha-lib-C4-XSLT-pm-1282-line.html#78 to cached: http://debian.koha-community.org/~robin/opac-search-cached/nytprof/usr-share-koha-lib-C4-XSLT-pm-1320-line.html#78 Test plan (please do this, more data points are good): * set up an instance with memcache available but not used * run the profiler on it * enable the use of memcache * run the profiler on it, note that the caching is being used and the code runs slower. * apply the patch * run the profiler again with memcache, note that the caching is not being used and things are back to being speedy. A quick primer to using the profiler: * apt-get install libdevel-nytprof-perl * sudo -u library-koha env MEMCACHED_SERVERS=localhost:11211 MEMCACHED_NAMESPACE=library-koha-opac KOHA_CONF=/etc/koha/sites/library/koha-conf.xml PERL5LIB=/usr/share/koha/lib SERVER_PORT=80 perl -d:NYTProf /usr/share/koha/opac/cgi-bin/opac/opac-search.pl 'q=a' * this will create nytprof.out in the current dir (use /tmp) * run nytprofhtml to produce HTML output. * remove/include the MEMCACHED variables to turn caching on/off globally.
Profiling shows a lot of time being spend doing DBI::ping. Bug 10611 has a solution to this that ought to be under this umbrella too.
Created attachment 22404 [details] [review] Bug 11051 - remove caching of GetMarcStructure Profiling suggests that this is actually ~1s slower with caching enabled, probably due to serialisation overheads. Compare uncached: http://debian.koha-community.org/~robin/opac-search/usr-share-koha-lib-C4-XSLT-pm-1282-line.html#78 to cached: http://debian.koha-community.org/~robin/opac-search-cached/nytprof/usr-share-koha-lib-C4-XSLT-pm-1320-line.html#78 Test plan (please do this, more data points are good): * set up an instance with memcache available but not used * run the profiler on it * enable the use of memcache * run the profiler on it, note that the caching is being used and the code runs slower. * apply the patch * run the profiler again with memcache, note that the caching is not being used and things are back to being speedy. A quick primer to using the profiler: * apt-get install libdevel-nytprof-perl * sudo -u library-koha env MEMCACHED_SERVERS=localhost:11211 MEMCACHED_NAMESPACE=library-koha-opac KOHA_CONF=/etc/koha/sites/library/koha-conf.xml PERL5LIB=/usr/share/koha/lib SERVER_PORT=80 perl -d:NYTProf /usr/share/koha/opac/cgi-bin/opac/opac-search.pl 'q=a' * this will create nytprof.out in the current dir (use /tmp) * run nytprofhtml to produce HTML output. * remove/include the MEMCACHED variables to turn caching on/off globally. Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com> Passes koha-qa.pl and all unit tests. No errors detected.
Created attachment 22405 [details] [review] Bug 11051 - remove unneccessary SQL queries in GetBranches The way GetBranches was written, it will issue one query to get all branches, and then one query per branch for the branch relations. This patch pre-fetches the relations table (as we need it all anyway) and so makes the whole process happen in two queries, rather than take 1+N, where N is the number of branches. This might not seem like much, but when you do a search, GetBranches is called once for each result, so 25. And you might have 10 branches. This causes 275 database requests when you could get away with 50. From profiling, when you run a search, this is the thing that calls DBI::st::execute the most. Refer: http://debian.koha-community.org/~robin/opac-search/usr-share-koha-lib-C4-Branch-pm-146-line.html#125 Test Plan: * Have a database with branches and relationships between the branches. (these are 'Lubrary groups' in the UI. * Make sure the relationships show up correctly after applying the patch. Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Created attachment 22406 [details] [review] Bug 11051 - remove caching of GetMarcStructure Profiling suggests that this is actually ~1s slower with caching enabled, probably due to serialisation overheads. Compare uncached: http://debian.koha-community.org/~robin/opac-search/usr-share-koha-lib-C4-XSLT-pm-1282-line.html#78 to cached: http://debian.koha-community.org/~robin/opac-search-cached/nytprof/usr-share-koha-lib-C4-XSLT-pm-1320-line.html#78 Test plan (please do this, more data points are good): * set up an instance with memcache available but not used * run the profiler on it * enable the use of memcache * run the profiler on it, note that the caching is being used and the code runs slower. * apply the patch * run the profiler again with memcache, note that the caching is not being used and things are back to being speedy. A quick primer to using the profiler: * apt-get install libdevel-nytprof-perl * sudo -u library-koha env MEMCACHED_SERVERS=localhost:11211 MEMCACHED_NAMESPACE=library-koha-opac KOHA_CONF=/etc/koha/sites/library/koha-conf.xml PERL5LIB=/usr/share/koha/lib SERVER_PORT=80 perl -d:NYTProf /usr/share/koha/opac/cgi-bin/opac/opac-search.pl 'q=a' * this will create nytprof.out in the current dir (use /tmp) * run nytprofhtml to produce HTML output. * remove/include the MEMCACHED variables to turn caching on/off globally. Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com> Passes koha-qa.pl and all unit tests. No errors detected.
I completely agree with the first patch. The second one looks good too but I cannot reproduce the load difference. In fact, in C4::Biblio, the memoize_memcached routine die with "Invalid memcached argument" (though C4::Context::memcached returns a Cache::Memcached object). Anyway, I hope another QAer will reproduce and pass QA on these 2 patches.
Hi Robin, I am a bit worried about the dependency on bug 10611 as we were planning on adding some kind of Postgres support to 3.16.
(In reply to Katrin Fischer from comment #10) > Hi Robin, I am a bit worried about the dependency on bug 10611 as we were > planning on adding some kind of Postgres support to 3.16. It's not a hard depends, it's just that bug 10611 solves a problem that I identified that (significantly) improves performance. I think that we should apply that, and then work out how to make it work with pgsql, but that's a discussion for that bug.
So these patches can be tested without 10611 as well?
(In reply to Katrin Fischer from comment #12) > So these patches can be tested without 10611 as well? Yep.
Created attachment 24117 [details] [review] [PASSED QA]Bug 11051 - remove unneccessary SQL queries in GetBranches The way GetBranches was written, it will issue one query to get all branches, and then one query per branch for the branch relations. This patch pre-fetches the relations table (as we need it all anyway) and so makes the whole process happen in two queries, rather than take 1+N, where N is the number of branches. This might not seem like much, but when you do a search, GetBranches is called once for each result, so 25. And you might have 10 branches. This causes 275 database requests when you could get away with 50. From profiling, when you run a search, this is the thing that calls DBI::st::execute the most. Refer: http://debian.koha-community.org/~robin/opac-search/usr-share-koha-lib-C4-Branch-pm-146-line.html#125 Test Plan: * Have a database with branches and relationships between the branches. (these are 'Lubrary groups' in the UI. * Make sure the relationships show up correctly after applying the patch. Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com> Signed-off-by: Jonathan Druart <jonathan.druart@biblibre.com>
I marked the patch I tested as passed qa.
I have pushed the GetBranches() patch to master. Thanks, Robin! I'll reset the bug to signed off for the other patch.
I noticed that GetMarcStructure does its own caching (which is likely to be problematic with plack) and this will be why it's substantially slower with memcache.
Hi Robin, I tried ... and failed. Could you adapt your hints a bit for testing with a dev installation?
(In reply to Katrin Fischer from comment #18) > Hi Robin, I tried ... and failed. Could you adapt your hints a bit for > testing with a dev installation? Really all you'll need to do is a) make sure you have memcached installed and running, and b) change the paths to point to wherever they happen to be on your dev install. You probably don't need to run with the sudo either in that case, so you could drop the "sudo -u library-koha env" part.
Robin, could you take a look at comment 9 from Jonathan?
(In reply to Katrin Fischer from comment #20) > Robin, could you take a look at comment 9 from Jonathan? I can, but I don't know why it'd be doing that. Maybe memcached wasn't running or something?
(In reply to Robin Sheat from comment #21) > (In reply to Katrin Fischer from comment #20) > > Robin, could you take a look at comment 9 from Jonathan? > > I can, but I don't know why it'd be doing that. Maybe memcached wasn't > running or something? To me it is not working on master. After some debug: C4::Context->memcached returns a Cache::Memcached object (created in the BEGIN block of C4::Context l.86). The call to memoize_memcached (BEGIN block in C4::Biblio) is done with memoize_memcached( 'GetMarcStructure', memcached => C4::Context->memcached); My error (which I got when I remove the eval) is "Invalid memcached argument (expected a hash)" It is raised because memoize_memcached expects a hashref for the memcached value, not a Cache::Memcached instance. From Memoize::Memcached (v.0.03): my $memcached_args = delete $args{memcached} || {}; croak "Invalid memcached argument (expected a hash)" unless ref $memcached_args eq 'HASH'; Tell me if I am not clear or if I forgot something.
Robin, did you see my last comment?
(In reply to Jonathan Druart from comment #22) > (In reply to Robin Sheat from comment #21) > > (In reply to Katrin Fischer from comment #20) > > > Robin, could you take a look at comment 9 from Jonathan? > > > > I can, but I don't know why it'd be doing that. Maybe memcached wasn't > > running or something? > > To me it is not working on master. > > After some debug: > C4::Context->memcached returns a Cache::Memcached object (created in the > BEGIN block of C4::Context l.86). > > The call to memoize_memcached (BEGIN block in C4::Biblio) is done with > memoize_memcached( 'GetMarcStructure', > memcached => C4::Context->memcached); > > My error (which I got when I remove the eval) is > "Invalid memcached argument (expected a hash)" > It is raised because memoize_memcached expects a hashref for the memcached > value, not a Cache::Memcached instance. Just curious: The above call seems to be incorrect and is removed. But after removal you got the same error? Where is it raised in that situation?
(In reply to M. de Rooy from comment #24) > Just curious: The above call seems to be incorrect and is removed. But after > removal you got the same error? Where is it raised in that situation? I get the error without the patch.
(In reply to Jonathan Druart from comment #25) > (In reply to M. de Rooy from comment #24) > > Just curious: The above call seems to be incorrect and is removed. But after > > removal you got the same error? Where is it raised in that situation? > > I get the error without the patch. OK. In that case I do not exactly understand what keeps you from passing QA on this patch? I saw that Kyle signed off on it.
(In reply to M. de Rooy from comment #26) > OK. In that case I do not exactly understand what keeps you from passing QA > on this patch? I saw that Kyle signed off on it. There are 2 reasons. 1/ I don't see the load difference following the test plan. 2/ There are some calls to memoize_memcached('subroutine_name', memcached => C4::Context->memcached); in the code. If the call is wrong, we should fix it everywhere. If I am wrong, I am not able to pass qa on it :)
(In reply to Jonathan Druart from comment #27) > There are 2 reasons. > 1/ I don't see the load difference following the test plan. > 2/ There are some calls to > memoize_memcached('subroutine_name', memcached => C4::Context->memcached); > in the code. > If the call is wrong, we should fix it everywhere. If I am wrong, I am not > able to pass qa on it :) I installed memcached (and ..) and ran the memoize_memcached call for GetMarcStructure and called it in a for loop so many times. My findings are: 1) As Jonathan pointed out, the call seems to be wrong. If I pass memcached =>1 as parameter, I also have: Invalid memcached argument (expected a hash). If I pass memcached => {}, it seems to be okay. I do not understand why we still find this error. Are other people using another version for memcached, Cache::Memcached or Memoize::Memcached? 2) When I increase the number of loops (calls to GetMarcStructure), I also see that the memcache variant is much slower. Since I am not yet that familiar with memcached, I am not sure if this is just a matter of configuration. I would appreciate some more feedback from the author or other users of memcached. I will send a mail to the dev list. Changing status to reflect the need for clarification.
(In reply to M. de Rooy from comment #28) > (In reply to Jonathan Druart from comment #27) > > There are 2 reasons. > > 1/ I don't see the load difference following the test plan. > > 2/ There are some calls to > > memoize_memcached('subroutine_name', memcached => C4::Context->memcached); > > in the code. > > If the call is wrong, we should fix it everywhere. If I am wrong, I am not > > able to pass qa on it :) > > I installed memcached (and ..) and ran the memoize_memcached call for > GetMarcStructure and called it in a for loop so many times. > My findings are: > > 1) As Jonathan pointed out, the call seems to be wrong. If I pass memcached > =>1 as parameter, I also have: Invalid memcached argument (expected a hash). > If I pass memcached => {}, it seems to be okay. > I do not understand why we still find this error. Are other people using > another version for memcached, Cache::Memcached or Memoize::Memcached? Memoize::Memcached v0.04 changed the use of isa() in favour of ref() to prevent deprecation messages in Perl 5.12+. I think Debian's 0.03 package at some point introduced a similar patch (the package was abandoned, I own it now because of that). The problem is (i think, have just arrived from a month without any Perl) that isa('HASH') was true because it would match all inherited classes (not only the latest blessed one). I'll try to fix it (help is welcome), but I don't think i will be available in Debian soon.
Could you guys please test with the latest Memoize/Memcache.pm from my repo: https://gitorious.org/memoize-memcached/memoize-memcached/source/master: Thanks!
Robin, which version of Memcached did you use?
(In reply to Jonathan Druart from comment #31) > Robin, which version of Memcached did you use? In early February last year? I have no idea. Whatever was in whatever my dev VM was running then, most likely. Probably Wheezy.
These lines have been removed by commit 71ba269136c61e57e8388f91f2562d062004d7fd Bug 11842 - fix framework caching with memcache/plack Memoize::Memcached has been removed by bug 16770. And GetMarcStructure is not correctly cached using Koha::Cache (see 16365).
(In reply to Jonathan Druart from comment #33) > And GetMarcStructure is not correctly cached using Koha::Cache (see 16365). /not/now !