Bug 25292

Summary: L1 cache too long in Z3950 server (z3950-responder)
Product: Koha Reporter: Jonathan Druart <jonathan.druart>
Component: Architecture, internals, and plumbingAssignee: Jonathan Druart <jonathan.druart>
Status: CLOSED FIXED QA Contact: Testopia <testopia>
Severity: normal    
Priority: P5 - low CC: andrew, caroline.cyr-la-rose, f.demians, fridolin.somers, magnus, mtj, nick, victor
Version: unspecified   
Hardware: All   
OS: All   
Change sponsored?: --- Patch complexity: ---
Documentation contact: Documentation submission:
Text to go in the release notes:
Version(s) released in:
21.05.00,20.11.02,20.05.08
Circulation function:
Bug Depends on: 13937    
Bug Blocks: 24761    
Attachments: Bug 25292: Flushing L1 on every Z3950 server search
Bug 25292: Flushing L1 on every Z3950 server search
Bug 25292: Flushing L1 on every Z3950 server search
Bug 25292: Flushing L1 on every Z3950 server search

Description Jonathan Druart 2020-04-27 14:06:25 UTC

    
Comment 1 Jonathan Druart 2020-04-27 14:31:53 UTC
Created attachment 103795 [details] [review]
Bug 25292: Flushing L1 on every Z3950 server search

This patch flushes the L1 cache on each Z3950 server search.

There is no need to flush it in init_handler (when the connection is
made), the L1 cache is not accessed (this behaviour goes against what I
expected).

This means each search will fetch values from the
L2 cache (ie memcached) and persist the L1 cache (in Perl
memory cache) until the result are returned (or longer?).

Test plan:
% perl misc/z3950_responder.pl --config-dir=/kohadevbox/koha/etc/z3950
% zoomsh
ZOOM>connect localhost:2100
ZOOM>set databaseName biblios
ZOOM>search x
ZOOM>search x

Between the 2 searches you can modify the value of SearchEngine, you
will notice that the number of hits is different
Comment 2 Frédéric Demians 2020-04-28 06:03:18 UTC
I can reproduce the test plan on a dual installation (ES/Zebra), and see the result variation depending on selected search engine. So it works. But won't it impact performance?
Comment 3 Jonathan Druart 2020-04-28 08:31:00 UTC
Of course there will be a difference, but you will hit L2 (memcached) anyway. It won't be worst than other search (UI).

I am not expecting a huge difference here but I have not compared.
Comment 4 Victor Grousset/tuxayo 2020-05-31 19:35:30 UTC
(In reply to Jonathan Druart from comment #1)
> ZOOM>search x
> ZOOM>search x
> 
> Between the 2 searches you can modify the value of SearchEngine, you
> will notice that the number of hits is different

I don't get what should I do to see a difference in the number of hits.

I've searched for few things before the patch.
And after the patch (after restarting the responder). Same number of hits.
Then I did restart_all.

In this session, I switched at some points from ES to Zebra.
I'm confused and can't invent a list of steps that leads to something consistently good (after the patch) or bad (before the patch).


kohadev-koha@6c8a568fb951:/kohadevbox/koha$ zoomsh
ZOOM>connect localhost:2100
ZOOM>set databaseName biblios
ZOOM>search shock
localhost:2100: 2 hits
ZOOM>search the
localhost:2100: 192 hits
ZOOM>search the
localhost:2100: 192 hits
ZOOM>search the
localhost:2100: 192 hits
# I think I switched from 
ZOOM>search the
localhost:2100: 0 hits
ZOOM>search the
localhost:2100: 0 hits
ZOOM>search the
localhost:2100: 0 hits
ZOOM>search les
localhost:2100: 0 hits
ZOOM>search yes
localhost:2100: 0 hits
ZOOM>search shoch
localhost:2100: 0 hits
ZOOM>search shodck
localhost:2100: 0 hits
ZOOM>search shock
localhost:2100: 0 hits
ZOOM>search the
localhost:2100: 0 hits


second try with more details.

kohadev-koha@6c8a568fb951:/kohadevbox/koha$ zoomsh
ZOOM>connect localhost:2100
ZOOM>set databaseName biblios
ZOOM>search shock
localhost:2100: 2 hits
ZOOM>search the
localhost:2100: 192 hits
ZOOM>
kohadev-koha@6c8a568fb951:/kohadevbox/koha$ # switch toZebra
kohadev-koha@6c8a568fb951:/kohadevbox/koha$ zoomsh                                                                                             
ZOOM>connect localhost:2100
ZOOM>set databaseName biblios
ZOOM>search shock
localhost:2100 error: Temporary system error (Bib-1:2) Cannot connect to upstream server                                                       
ZOOM>search the
localhost:2100 error: Temporary system error (Bib-1:2) Cannot connect to upstream server                                                       
ZOOM>
kohadev-koha@6c8a568fb951:/kohadevbox/koha$ zoomsh
ZOOM>
kohadev-koha@6c8a568fb951:/kohadevbox/koha$ #restart responder
kohadev-koha@6c8a568fb951:/kohadevbox/koha$ zoomsh
ZOOM>connect localhost:2100
ZOOM>set databaseName biblios
ZOOM>search shock
localhost:2100 error: Temporary system error (Bib-1:2) Cannot connect to upstream server
ZOOM>search the
localhost:2100 error: Temporary system error (Bib-1:2) Cannot connect to upstream server
ZOOM>
Comment 5 Victor Grousset/tuxayo 2020-05-31 19:36:02 UTC
The last two logs are with the patch applied.
Comment 6 Jonathan Druart 2020-06-01 07:51:36 UTC
This is all what I do:

ZOOM>connect localhost:2100
ZOOM>set databaseName biblios
ZOOM>search x
localhost:2100: 18 hits

# Change the syspref SearchEngine

ZOOM>search x
localhost:2100: 230 hits

This is a ugly way of confirming that the correct value has been retrieve, but you could add a warn statement in the code, in search_handler, to check which value from cache (so easy to test is a syspref) is retrieved.
Comment 7 Victor Grousset/tuxayo 2020-06-29 22:10:02 UTC
After changing the syspref, I must restart ZOOM to have a different number of hits.

Is that expected?
Comment 8 Jonathan Druart 2020-07-31 08:28:39 UTC
(In reply to Victor Grousset/tuxayo from comment #7)
> After changing the syspref, I must restart ZOOM to have a different number
> of hits.
> 
> Is that expected?

No, please detail what you tried and the result.
Comment 9 Jonathan Druart 2020-07-31 08:31:34 UTC
(In reply to Jonathan Druart from comment #8)
> (In reply to Victor Grousset/tuxayo from comment #7)
> > After changing the syspref, I must restart ZOOM to have a different number
> > of hits.
> > 
> > Is that expected?
> 
> No, please detail what you tried and the result.

Hum forget that, you detailed above.
Comment 10 Jonathan Druart 2020-07-31 08:52:15 UTC
Created attachment 107621 [details] [review]
Bug 25292: Flushing L1 on every Z3950 server search

This patch flushes the L1 cache on each Z3950 server search.

There is no need to flush it in init_handler (when the connection is
made), the L1 cache is not accessed (this behaviour goes against what I
expected).

This means each search will fetch values from the
L2 cache (ie memcached) and persist the L1 cache (in Perl
memory cache) until the result are returned (or longer?).

Test plan:
% perl misc/z3950_responder.pl --config-dir=/kohadevbox/koha/etc/z3950
% zoomsh
ZOOM>connect localhost:2100
ZOOM>set databaseName biblios
ZOOM>search x
ZOOM>search x

Between the 2 searches you can modify the value of SearchEngine, you
will notice that the number of hits is different
Comment 11 Jonathan Druart 2020-07-31 08:54:10 UTC
I am really confused, I am pretty sure the original patch was working when I wrote it but... reading the code it couldn't have worked.

This new patch should work accordingly to what is advertised in the commit message.
Comment 12 Magnus Enger 2020-10-10 18:46:16 UTC
Tried to test this on Debian 9.13, but when I try to install Net::Z3950::SimpleServer it says "You have YAZ version 4.2.30; you need 4.2.51 or better. at Makefile.PL line 23", so I'm guessing I would need to have Debian 10.
Comment 13 Mason James 2020-10-11 03:03:43 UTC
(In reply to Magnus Enger from comment #12)
> Tried to test this on Debian 9.13, but when I try to install
> Net::Z3950::SimpleServer it says "You have YAZ version 4.2.30; you need
> 4.2.51 or better. at Makefile.PL line 23", so I'm guessing I would need to
> have Debian 10.

hi Magnus, have you tried using the version in the debian.org repo?

https://packages.debian.org/stretch/libnet-z3950-simpleserver-perl
Comment 14 Fridolin Somers 2020-12-16 13:37:52 UTC
Created attachment 114436 [details] [review]
Bug 25292: Flushing L1 on every Z3950 server search

This patch flushes the L1 cache on each Z3950 server search.

There is no need to flush it in init_handler (when the connection is
made), the L1 cache is not accessed (this behaviour goes against what I
expected).

This means each search will fetch values from the
L2 cache (ie memcached) and persist the L1 cache (in Perl
memory cache) until the result are returned (or longer?).

Test plan:
% perl misc/z3950_responder.pl --config-dir=/kohadevbox/koha/etc/z3950
% zoomsh
ZOOM>connect localhost:2100
ZOOM>set databaseName biblios
ZOOM>search x
ZOOM>search x

Between the 2 searches you can modify the value of SearchEngine, you
will notice that the number of hits is different

Signed-off-by: Fridolin Somers <fridolin.somers@biblibre.com>
Comment 15 Fridolin Somers 2020-12-16 13:39:42 UTC
Works well when you have both searchengine running.

Noticed that daemon fails when you switch to Elasticsearch without having it installed.
But that is for another bug.

Best regards ;)
Comment 16 Nick Clemens (kidclamp) 2021-01-08 19:01:16 UTC
Created attachment 114976 [details] [review]
Bug 25292: Flushing L1 on every Z3950 server search

This patch flushes the L1 cache on each Z3950 server search.

There is no need to flush it in init_handler (when the connection is
made), the L1 cache is not accessed (this behaviour goes against what I
expected).

This means each search will fetch values from the
L2 cache (ie memcached) and persist the L1 cache (in Perl
memory cache) until the result are returned (or longer?).

Test plan:
% perl misc/z3950_responder.pl --config-dir=/kohadevbox/koha/etc/z3950
% zoomsh
ZOOM>connect localhost:2100
ZOOM>set databaseName biblios
ZOOM>search x
ZOOM>search x

Between the 2 searches you can modify the value of SearchEngine, you
will notice that the number of hits is different

Signed-off-by: Fridolin Somers <fridolin.somers@biblibre.com>

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>
Comment 17 Jonathan Druart 2021-01-11 09:30:02 UTC
Pushed to master for 21.05, thanks to everybody involved!
Comment 18 Fridolin Somers 2021-01-11 12:59:52 UTC
Pushed to 20.11.x for 20.11.02
Comment 19 Andrew Fuerste-Henry 2021-01-20 00:55:05 UTC
Pushed to 20.05.x for 20.05.08
Comment 20 Victor Grousset/tuxayo 2021-01-22 01:47:53 UTC
Not backported to oldoldstable (19.11.x). Feel free to ask if it's needed.