Bug 28276

Summary: Do not fetch config ($KOHA_CONF) from memcached
Product: Koha Reporter: Julian Maurice <julian.maurice>
Component: Architecture, internals, and plumbingAssignee: Julian Maurice <julian.maurice>
Status: CLOSED FIXED QA Contact: Testopia <testopia>
Severity: normal    
Priority: P5 - low CC: andrewfh, dcook, fridolin.somers, martin.renvoize, victor
Version: Main   
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.06
Bug Depends on:    
Bug Blocks: 28306    
Attachments: Bug 28276: Do not fetch config ($KOHA_CONF) from memcached
Bug 28276: Do not fetch config ($KOHA_CONF) from memcached
Bug 28276: Do not fetch config ($KOHA_CONF) from memcached

Description Julian Maurice 2021-05-02 12:47:05 UTC
memcached address and namespace are in $KOHA_CONF, so it is required to read it before being able to access the cache. And after that, configuration is kept in memory forever. Storing this in memcached is useless and even counter-productive, since Koha reads both the file and the cache.
Comment 1 Julian Maurice 2021-05-02 12:47:40 UTC
Created attachment 120352 [details] [review]
Bug 28276: Do not fetch config ($KOHA_CONF) from memcached

memcached address and namespace are in $KOHA_CONF, so it is required to
read it before being able to access the cache. And after that,
configuration is kept in memory forever. Storing this in memcached is
useless and even counter-productive, since Koha reads both the file and
the cache

This patch addresses this issue by removing the cache-related code from
C4::Context->new.
It means that C4::Context->new will always read the configuration file,
so this patch also replaces inappropriate calls to
C4::Context->new->config by appropriate calls to C4::Context->config

It also fixes a bug where C4::Context->new would ignore the filepath
given in parameters if there was something in cache.

It also removes a problematic call to Koha::Caches->get_instance.
Because this call was outside of any subroutine, it would have happened
before the initialization of $C4::Context::context (which happen in
C4::Context::import)

Test plan:
1. Do not apply the patch yet
2. Add the following line at the beginning of Koha::Config::read_from_file
    warn "read_from_file($file)";
   This will allow you to check how many times the file is read.
3. Flush memcached and restart starman
4. Check the logs, you should see "read_from_file" a bunch of times
5. Apply the patch
6. Re-add the line from step 2
7. Flush memcached and restart starman
8. Check the logs, you should see "read_from_file" only once
9. Make sure the memcached config from $KOHA_CONF (memcached_servers,
   memcached_namespace) is taken into account by checking the About page
Comment 2 Victor Grousset/tuxayo 2021-05-03 19:43:06 UTC
Error:
«Starting Z39.50/SRU daemon for kohadev:Global symbol "$file" requires explicit package name (did you forget to declare "my $file"?) at /kohadevbox/koha/Koha/Config.pm line 36.»

I guess there should be simple quotes right?

Test results: Is that what should be expected? (less reads but still multiple)
==================== Before patch ========================
==================== restart =============================
root@kohadevbox:kohadevbox$ restart_all 
Restarting Apache httpd web server: apache2.
Restarting Koha ILS: koha-commonStopping Plack daemon for kohadev:.
Error: Z39.50/SRU not running for kohadev: failed!
Stopping Koha worker daemon for kohadev:.
Stopping Koha indexing daemon for kohadev:.
Starting Plack daemon for kohadev:.
Starting Z39.50/SRU daemon for kohadev:read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.
.
Starting Koha worker daemon for kohadev:.
Starting Koha indexing daemon for kohadev:.

==================== logs ========================
==> /var/log/koha/kohadev/plack-error.log <==
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.

==> /var/log/koha/kohadev/sip-output.log <==
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.

==> /var/log/koha/kohadev/indexer-output.log <==
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.

==> /var/log/koha/kohadev/worker-output.log <==
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.

==> /var/log/koha/kohadev/indexer-output.log <==
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.


==================== After patch ========================
==================== restart =============================
root@kohadevbox:kohadevbox$ restart_all 
Restarting Apache httpd web server: apache2.
Restarting Koha ILS: koha-commonStopping Plack daemon for kohadev:.
Stopping Z39.50/SRU daemon for kohadev:.
Stopping Koha worker daemon for kohadev:.
Stopping Koha indexing daemon for kohadev:.
Starting Plack daemon for kohadev:.
Starting Z39.50/SRU daemon for kohadev:read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.
.
Starting Koha worker daemon for kohadev:.
Starting Koha indexing daemon for kohadev:.

==================== logs ========================
==> /var/log/koha/kohadev/plack-error.log <==
Process Backgrounded
2021/05/03-19:36:13 Starman::Server (type Net::Server::PreFork) starting! pid(3537)
Binding to UNIX socket file "/var/run/koha/kohadev/plack.sock"
Setting gid to "1000 1000"
Setting uid to "1000"
Starman: Accepting connections at unix://localhost:/var/run/koha/kohadev/plack.sock/
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.

==> /var/log/koha/kohadev/sip-output.log <==
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.

==> /var/log/koha/kohadev/indexer-output.log <==
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.

==> /var/log/koha/kohadev/worker-output.log <==
read_from_file($file)####################### at /kohadevbox/koha/Koha/Config.pm line 36.
Comment 3 Julian Maurice 2021-05-04 06:51:13 UTC
(In reply to Victor Grousset/tuxayo from comment #2)
> Error:
> «Starting Z39.50/SRU daemon for kohadev:Global symbol "$file" requires
> explicit package name (did you forget to declare "my $file"?) at
> /kohadevbox/koha/Koha/Config.pm line 36.»
> 
> I guess there should be simple quotes right?

You probably added the warn too early. It should be just after getting the parameters:
my ($class, $file) = @_;
warn "read_from_file($file)";

> Test results: Is that what should be expected? (less reads but still
> multiple)

You should see it once per worker. I see that there are two "read_from_file" in plack-error.log (after the patch). So if you have two workers that's normal.
Please make sure there are no "read_from_file" after startup, when you use koha web interface.
Comment 4 Martin Renvoize 2021-05-04 09:12:16 UTC
Comment on attachment 120352 [details] [review]
Bug 28276: Do not fetch config ($KOHA_CONF) from memcached

Review of attachment 120352 [details] [review]:
-----------------------------------------------------------------

::: Koha/Database.pm
@@ +49,4 @@
>  
>      require Koha::Schema;
>  
> +    my $db_driver = C4::Context::db_scheme2dbi(C4::Context->config('db_scheme'));;

This change looks reasonable to me, but is worth highlighting to whoever does QA as worth digging into.. I'm not 100% sure if there's some background reason this used to call $context->{db_driver} instead of passing db_scheme into db_scheme2dbi.
Comment 5 Martin Renvoize 2021-05-04 09:13:50 UTC
Created attachment 120428 [details] [review]
Bug 28276: Do not fetch config ($KOHA_CONF) from memcached

memcached address and namespace are in $KOHA_CONF, so it is required to
read it before being able to access the cache. And after that,
configuration is kept in memory forever. Storing this in memcached is
useless and even counter-productive, since Koha reads both the file and
the cache

This patch addresses this issue by removing the cache-related code from
C4::Context->new.
It means that C4::Context->new will always read the configuration file,
so this patch also replaces inappropriate calls to
C4::Context->new->config by appropriate calls to C4::Context->config

It also fixes a bug where C4::Context->new would ignore the filepath
given in parameters if there was something in cache.

It also removes a problematic call to Koha::Caches->get_instance.
Because this call was outside of any subroutine, it would have happened
before the initialization of $C4::Context::context (which happen in
C4::Context::import)

Test plan:
1. Do not apply the patch yet
2. Add the following line at the beginning of Koha::Config::read_from_file
    warn "read_from_file($file)";
   This will allow you to check how many times the file is read.
3. Flush memcached and restart starman
4. Check the logs, you should see "read_from_file" a bunch of times
5. Apply the patch
6. Re-add the line from step 2
7. Flush memcached and restart starman
8. Check the logs, you should see "read_from_file" only once
9. Make sure the memcached config from $KOHA_CONF (memcached_servers,
   memcached_namespace) is taken into account by checking the About page

Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 6 Martin Renvoize 2021-05-04 09:14:27 UTC
This achieves the desired effect for me.. works well and is a nice bit of cleanup.

Signing off
Comment 7 Victor Grousset/tuxayo 2021-05-04 21:52:39 UTC
(In reply to Julian Maurice from comment #3)
> You probably added the warn too early. It should be just after getting the
> parameters:
> my ($class, $file) = @_;
> warn "read_from_file($file)";

oops, how careless, now it's obvious ^^"
thanks :)

> You should see it once per worker. I see that there are two "read_from_file"
> in plack-error.log (after the patch). So if you have two workers that's
> normal.

Potential issue found, I added the following:
warn "######## read_from_file($file)" . "###" . int(rand(10000000)) . "######";
The rand to identify each unique call of the function.
Output with the patch:
============================== restart command ======================
Starting Z39.50/SRU daemon for kohadev:################# read_from_file(/etc/koha/sites/kohadev/koha-conf.xml)###9584085###### at /kohadevbox/koha/Koha/Config.pm line 37.
=============================== all logs =============================
==> /var/log/koha/kohadev/plack-error.log <==
Starman: Accepting connections at unix://localhost:/var/run/koha/kohadev/plack.sock/
################# read_from_file(/etc/koha/sites/kohadev/koha-conf.xml)###6082019###### at /kohadevbox/koha/Koha/Config.pm line 37.
################# read_from_file(/etc/koha/sites/kohadev/koha-conf.xml)###9302336###### at /kohadevbox/koha/Koha/Config.pm line 37.

==> /var/log/koha/kohadev/sip-output.log <==
################# read_from_file(/etc/koha/sites/kohadev/koha-conf.xml)###3475587###### at /kohadevbox/koha/Koha/Config.pm line 37.

==> /var/log/koha/kohadev/indexer-output.log <==
################# read_from_file(/etc/koha/sites/kohadev/koha-conf.xml)###5666078###### at /kohadevbox/koha/Koha/Config.pm line 37.

==> /var/log/koha/kohadev/worker-output.log <==
################# read_from_file(/etc/koha/sites/kohadev/koha-conf.xml)###488901###### at /kohadevbox/koha/Koha/Config.pm line 37.

There are two for plack, one per worker. But are the other calls expected?
And the one in the restart_all output?


> Please make sure there are no "read_from_file" after startup, when you use
> koha web interface.

Selenium tests didn't show calls to read_from_file in the logs.
Though the call to prove did but I guess it's because the test code load Koha stuff right?
https://paste.chapril.org/?39fdfda86050ed4c#8zBSp79ACPT6PRs29DKGzR4QbB3HWH9ycqxs2b9BXGiv

Then I messed a bit with the OPAC, I can't reproduce how that happended but I ended up doing this query:
http://localhost:8080/opac-search.pl?idx=&q=test&weight_search=1
Which calls read_from_file.
I guess it's not an issue since not having cgi-bin/koha is expected to change stuff.
The real issue would how did I end up with such an URL, which I didn't find.
Comment 8 Julian Maurice 2021-05-07 07:59:56 UTC
(In reply to Victor Grousset/tuxayo from comment #7)
> There are two for plack, one per worker. But are the other calls expected?
> And the one in the restart_all output?
Yes. Each service is started in a different process and they need to read $KOHA_CONF too.

> Selenium tests didn't show calls to read_from_file in the logs.
> Though the call to prove did but I guess it's because the test code load
> Koha stuff right?
I don't know how Selenium works, but I'm not too worried about those calls. Did you test this on master ?
Comment 9 Kyle M Hall 2021-05-07 13:53:00 UTC
Created attachment 120693 [details] [review]
Bug 28276: Do not fetch config ($KOHA_CONF) from memcached

memcached address and namespace are in $KOHA_CONF, so it is required to
read it before being able to access the cache. And after that,
configuration is kept in memory forever. Storing this in memcached is
useless and even counter-productive, since Koha reads both the file and
the cache

This patch addresses this issue by removing the cache-related code from
C4::Context->new.
It means that C4::Context->new will always read the configuration file,
so this patch also replaces inappropriate calls to
C4::Context->new->config by appropriate calls to C4::Context->config

It also fixes a bug where C4::Context->new would ignore the filepath
given in parameters if there was something in cache.

It also removes a problematic call to Koha::Caches->get_instance.
Because this call was outside of any subroutine, it would have happened
before the initialization of $C4::Context::context (which happen in
C4::Context::import)

Test plan:
1. Do not apply the patch yet
2. Add the following line at the beginning of Koha::Config::read_from_file
    warn "read_from_file($file)";
   This will allow you to check how many times the file is read.
3. Flush memcached and restart starman
4. Check the logs, you should see "read_from_file" a bunch of times
5. Apply the patch
6. Re-add the line from step 2
7. Flush memcached and restart starman
8. Check the logs, you should see "read_from_file" only once
9. Make sure the memcached config from $KOHA_CONF (memcached_servers,
   memcached_namespace) is taken into account by checking the About page

Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Comment 10 Victor Grousset/tuxayo 2021-05-07 15:03:44 UTC
(In reply to Julian Maurice from comment #8)
> Yes. Each service is started in a different process and they need to read
> $KOHA_CONF too.

Good :)

> I don't know how Selenium works, but I'm not too worried about those calls.

Sorry for the confusion, during the Selenium tests, the logs of Koha didn't show a call to the function. It was just a lazy way to do things in the UI ^^
The terminal where prove -r t/db_dependent/selenium was run did. But I'm not worried about that either.

> Did you test this on master ?

Yes
Comment 11 Jonathan Druart 2021-05-10 14:19:26 UTC
Pushed to master for 21.05, thanks to everybody involved!
Comment 12 David Cook 2021-05-10 23:23:40 UTC
Yay! This should prevent many a headache...
Comment 13 Fridolin Somers 2021-05-12 14:33:27 UTC
Pushed to 20.11.x for 20.11.06
Comment 14 Fridolin Somers 2021-05-12 14:35:46 UTC
(In reply to David Cook from comment #12)
> Yay! This should prevent many a headache...

Indeed.
Any configuration change whent with "Oh, I forgot to flush memcached, again".
Comment 15 David Cook 2021-05-13 01:51:41 UTC
(In reply to Fridolin Somers from comment #14)
> (In reply to David Cook from comment #12)
> > Yay! This should prevent many a headache...
> 
> Indeed.
> Any configuration change whent with "Oh, I forgot to flush memcached, again".

I'm sorry/glad that I'm not the only one who suffered this.
Comment 16 Andrew Fuerste-Henry 2021-05-25 12:27:12 UTC
Doesn't apply cleanly to 20.05, please rebase if needed