Bug 23571

Summary: Add measures to prevent concurrent execution of fines.pl
Product: Koha Reporter: Hugo Agud <hagud>
Component: Command-line UtilitiesAssignee: Tomás Cohen Arazi <tomascohen>
Status: CLOSED FIXED QA Contact: Jonathan Druart <jonathan.druart>
Severity: enhancement    
Priority: P5 - low CC: 1joynelson, amit.gupta, amitddng135, gmcharlt, jonathan.druart, katrin.fischer, kyle.m.hall, martin.renvoize, philippe.blouin, robin, tomascohen
Version: Main   
Hardware: All   
OS: All   
See Also: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=16528
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=24651
Change sponsored?: Sponsored Patch complexity: Trivial patch
Documentation contact: Documentation submission:
Text to go in the release notes:
Version(s) released in:
20.05.00
Bug Depends on: 25109    
Bug Blocks:    
Attachments: Bug 23571: [DO NOT PUSH] crash condition builder
Bug 23571: Add flock to fines.pl
Bug 23571: [DO NOT PUSH] crash condition builder
Bug 23571: Add flock to fines.pl
Bug 23571: Add flock to fines.pl
Bug 23571: Add flock to fines.pl
Bug 23571: (follow-up) Only look for overdues after obtaining the lock
[ALTERNATIVE] Bug 23571: Prevent concurrent execution of fines.pl
Bug 23571: Prevent concurrent execution of fines.pl
Bug 23571: Prevent concurrent execution of fines.pl
Bug 23571: Prevent concurrent execution of fines.pl
Bug 23571: (QA follow-up) Add missing newline in warning
Bug 23571: Prevent concurrent execution of fines.pl
Bug 23571: (QA follow-up) Add missing newline in warning
bug 23571: (QA follow-up) Remove perlcritic warning

Description Hugo Agud 2019-09-09 06:25:49 UTC
Under certain circunstances fines.pl may block a server.

1. if syspref calculate on return
2. If koha site has a big number of overdue items
3. there are puntual high number of checkin

under this circunstances koha launches several fines.pl,each for every koha checkin,  that overload cpu and make koha unresponsive

This actions should be desiderable

1. fines.pl on return just calculate the user account, not all users

Another option is possible, block fines.pl if there is another process running.. but perhaps option 1 is faster?
Comment 1 Agustín Moyano 2019-12-05 22:12:35 UTC
Created attachment 96055 [details] [review]
Bug 23571: [DO NOT PUSH] crash condition builder

This patch adds t/db_dependent/bug_23571_crash_condition_builder.t file
This file is not intended to be part of Koha, but it's used to emulate crash conditions.
It will create 5000 users, 5000 biblios with 2 items each, and each item issued to a user.
It really takes a lot of time, so please be zen about it ;)

To use it execute
prove t/db_dependent/bug_23571_crash_condition_builder.t

Sponsored-by: Orex Digital
Comment 2 Agustín Moyano 2019-12-05 22:12:38 UTC
Created attachment 96056 [details] [review]
Bug 23571: Add flock to fines.pl

This patch adds a lock file for fines.pl.

To test:
1. Apply this patch
2. In two separate consoles run misc/cronjobs/fines.pl
SUCCESS => The first one runs normally, but the second one fails with a message flock failed for the lock file.
3. Sign off.

Sponsored-by: Orex Digital
Comment 3 Hugo Agud 2020-01-07 08:28:22 UTC
I have installed the patch , and from sudo koha-shell kohadev I have launched two terminal session but there is no error message at second terminal, perhaps I have done something wrong

SESSION 1
kohadev-koha@kohadevbox:/tmp$ perl /home/vagrant/kohaclone/misc/cronjobs/fines.pl -v -l -o
Use of uninitialized value $lockfile in concatenation (.) or string at /home/vagrant/kohaclone/misc/cronjobs/fines.pl line 93.
WARNING: Could not create lock file : No such file or directory
Verify if directories /var/lock/koha/koha_kohadev, /var/lock/koha_fines_koha_kohadev or /tmp/koha_fines_koha_kohadev exist and check file permissions
writing to /var/lib/koha/kohadev/tmp/koha_kohadev_2020-01-07.log
Use of uninitialized value in subtraction (-) at /home/vagrant/kohaclone/C4/Overdues.pm line 250.
Use of uninitialized value in numeric eq (==) at /home/vagrant/kohaclone/C4/Overdues.pm line 266.
Use of uninitialized value in subtraction (-) at /home/vagrant/kohaclone/C4/Overdues.pm line 250.

SESSION 2
kohadev-koha@kohadevbox:/home/vagrant$ perl /home/vagrant/kohaclone/misc/cronjobs/fines.pl -v -l -o
Use of uninitialized value $lockfile in concatenation (.) or string at /home/vagrant/kohaclone/misc/cronjobs/fines.pl line 93.
WARNING: Could not create lock file : No such file or directory
Verify if directories /var/lock/koha/koha_kohadev, /var/lock/koha_fines_koha_kohadev or /tmp/koha_fines_koha_kohadev exist and check file permissions
writing to /var/lib/koha/kohadev/tmp/koha_kohadev_2020-01-07.log
Use of uninitialized value in subtraction (-) at /home/vagrant/kohaclone/C4/Overdues.pm line 250.
Use of uninitialized value in numeric eq (==) at /home/vagrant/kohaclone/C4/Overdues.pm line 266
Comment 4 Hugo Agud 2020-02-14 07:53:59 UTC
Created attachment 98898 [details] [review]
Bug 23571: [DO NOT PUSH] crash condition builder

This patch adds t/db_dependent/bug_23571_crash_condition_builder.t file
This file is not intended to be part of Koha, but it's used to emulate crash conditions.
It will create 5000 users, 5000 biblios with 2 items each, and each item issued to a user.
It really takes a lot of time, so please be zen about it ;)

To use it execute
prove t/db_dependent/bug_23571_crash_condition_builder.t

Sponsored-by: Orex Digital

Signed-off-by: Hugo Agud <hagud@orex.es>
Comment 5 Hugo Agud 2020-02-14 07:54:03 UTC
Created attachment 98899 [details] [review]
Bug 23571: Add flock to fines.pl

This patch adds a lock file for fines.pl.

To test:
1. Apply this patch
2. In two separate consoles run misc/cronjobs/fines.pl
SUCCESS => The first one runs normally, but the second one fails with a message flock failed for the lock file.
3. Sign off.

Sponsored-by: Orex Digital

Signed-off-by: Hugo Agud <hagud@orex.es>
Comment 6 Martin Renvoize 2020-02-19 16:41:27 UTC
Created attachment 99263 [details] [review]
Bug 23571: Add flock to fines.pl

This patch adds a lock file for fines.pl.

To test:
1. Apply this patch
2. In two separate consoles run misc/cronjobs/fines.pl
SUCCESS => The first one runs normally, but the second one fails with a message flock failed for the lock file.
3. Sign off.

Sponsored-by: Orex Digital
Signed-off-by: Hugo Agud <hagud@orex.es>
Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 7 Martin Renvoize 2020-02-19 16:57:45 UTC
Created attachment 99264 [details] [review]
Bug 23571: Add flock to fines.pl

This patch adds a lock file for fines.pl.

To test:
1. Apply this patch
2. In two separate consoles run misc/cronjobs/fines.pl
SUCCESS => The first one runs normally, but the second one fails with a message flock failed for the lock file.
3. Sign off.

Sponsored-by: Orex Digital
Signed-off-by: Hugo Agud <hagud@orex.es>
Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 8 Martin Renvoize 2020-02-19 16:57:48 UTC
Created attachment 99265 [details] [review]
Bug 23571: (follow-up) Only look for overdues after obtaining the lock

No point in performing the overdues fetch before obtaining the lock and
knowing we can do something with them.

Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 9 Martin Renvoize 2020-02-19 17:03:27 UTC
Comment on attachment 99264 [details] [review]
Bug 23571: Add flock to fines.pl

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

So, this generally looks pretty good to me.. However... I'd love to see the locking mechanisms factored out into the Koha::Script base class so we could share the common code between command-line scripts and make adding flocking elsewhere a simple pattern to follow.

Would you be willing to have a go at that Agustin?

::: misc/cronjobs/fines.pl
@@ +82,5 @@
>  cronlogaction();
>  
> +my ($lockfile, $LockFH);
> +foreach (
> +    '/var/lock/koha',

How did you come up with these locations?

I note in the equivalent in rebuild_zebra.pl we use a config variable, followed by a fallback order...  I actually like the idea of using /var/lock/koha but I'm not sure I understand where if came from?
Comment 10 Jonathan Druart 2020-02-21 10:22:18 UTC
A couple of things:
1. test plan says "the second one fails", but it actually prints. I would die instead.
2. That will make you avoid the indentation level you add with this patch.
The algo would be:
- try to get a lock
- if lock already exists then exit/die with "cannot get lock" (or something more meaningful: "previous run is still alive, cannot start")
- continue the normal process of the script
Comment 11 Jonathan Druart 2020-02-21 10:22:37 UTC
(In reply to Jonathan Druart from comment #10)
> A couple of things:
> 1. test plan says "the second one fails", but it actually prints. I would
> die instead.

s/would/should!
Comment 12 Jonathan Druart 2020-02-21 10:32:36 UTC
Also, do you know that you can lock a portion of the file?

I have no idea why your code is that complicated, I think you should investigate this code:

use Modern::Perl;
use Fcntl qw(:flock);
sub is_locked {
    unless ( flock(DATA, LOCK_EX|LOCK_NB) ) {
        return 1;
    }    
    return 0;
}

die "is locked" if is_locked();

say "is not locked! sleeping 5 sec";
sleep(5);

__DATA__
USED BY LOCK - DO NOT REMOVE
Comment 13 Jonathan Druart 2020-02-24 09:07:33 UTC
Failing QA. Agustin please investigate comment 12 and tell us if there is a possibility to simplify your code.
Comment 14 Tomás Cohen Arazi 2020-04-12 13:35:17 UTC
Created attachment 102772 [details] [review]
[ALTERNATIVE] Bug 23571: Prevent concurrent execution of fines.pl

This patch introduces locking in fines.pl. It does so by leveraging on
bug 25109, which introduces a generic locking implementation on
Koha::Script.

The introduced changes:
1. Try to get the lock
2.a. If success, normal execution happens
2.b. If rejected, cronlogaction is called with a meaningful message and
  a normal exit happens, so we don't flood the logs in vain. --verbose
  will make the script print the same message on STDERR, as already is
  the case with this script

To test:
1. Apply this patch
2. In two separate consoles run:
   $ kshell
  k$ perl misc/cronjobs/fines.pl --verbose
SUCCESS => The first one runs normally, the second one exists really fast
  and prints a message about the lock.
3. Sign off :-D

Sponsored-by: Orex Digital

Signed-off-by: Tomas Cohen Arazi <tomascohen@theke.io>
Comment 15 Tomás Cohen Arazi 2020-04-12 13:42:49 UTC
(In reply to Martin Renvoize from comment #9)
> Comment on attachment 99264 [details] [review] [review]
> Bug 23571: Add flock to fines.pl
> 
> Review of attachment 99264 [details] [review] [review]:
> -----------------------------------------------------------------
> 
> So, this generally looks pretty good to me.. However... I'd love to see the
> locking mechanisms factored out into the Koha::Script base class so we could
> share the common code between command-line scripts and make adding flocking
> elsewhere a simple pattern to follow.
> 
> Would you be willing to have a go at that Agustin?
> 
> ::: misc/cronjobs/fines.pl
> @@ +82,5 @@
> >  cronlogaction();
> >  
> > +my ($lockfile, $LockFH);
> > +foreach (
> > +    '/var/lock/koha',
> 
> How did you come up with these locations?
> 
> I note in the equivalent in rebuild_zebra.pl we use a config variable,
> followed by a fallback order...  I actually like the idea of using
> /var/lock/koha but I'm not sure I understand where if came from?

Take a look at 25109, in which I introduce a centralized place to calculate this path.
Comment 16 Tomás Cohen Arazi 2020-04-12 13:44:17 UTC
(In reply to Jonathan Druart from comment #10)
> A couple of things:
> 1. test plan says "the second one fails", but it actually prints. I would
> die instead.
> 2. That will make you avoid the indentation level you add with this patch.
> The algo would be:
> - try to get a lock
> - if lock already exists then exit/die with "cannot get lock" (or something
> more meaningful: "previous run is still alive, cannot start")
> - continue the normal process of the script

Solved in my alternative patch. I chose to keep the output silent, unless --verbose is passed. This is the right behaviour for cronjobs, specially if we have the execution logged in the action_logs.
Comment 17 Tomás Cohen Arazi 2020-04-12 13:45:49 UTC
(In reply to Jonathan Druart from comment #12)
> Also, do you know that you can lock a portion of the file?

I loved the trick when I read about it while implementing 25109. But as we support multiple instances running the same codebase, this won't work. We need a 'namespace' (per instance) and the only way I found to do it was in a lock file.
Comment 18 Tomás Cohen Arazi 2020-04-12 13:46:05 UTC
(In reply to Jonathan Druart from comment #13)
> Failing QA. Agustin please investigate comment 12 and tell us if there is a
> possibility to simplify your code.

Done :-D
Comment 19 Martin Renvoize 2020-04-12 15:05:01 UTC
Awesome guys, this is really great to see. 😀. I'll put it high up my list to start playing with these bugs with a view to SO/QA after the Easter break.
Comment 20 Jonathan Druart 2020-04-13 09:49:54 UTC
Can't locate object method "new" via package "Koha::Scrip" (perhaps you forgot to load "Koha::Scrip"?) at misc/cronjobs/fines.pl line 80.

typo.
Comment 21 Jonathan Druart 2020-04-13 10:10:17 UTC
Created attachment 102804 [details] [review]
Bug 23571: Prevent concurrent execution of fines.pl

This patch introduces locking in fines.pl. It does so by leveraging on
bug 25109, which introduces a generic locking implementation on
Koha::Script.

The introduced changes:
1. Try to get the lock
2.a. If success, normal execution happens
2.b. If rejected, cronlogaction is called with a meaningful message and
  a normal exit happens, so we don't flood the logs in vain. --verbose
  will make the script print the same message on STDERR, as already is
  the case with this script

To test:
1. Apply this patch
2. In two separate consoles run:
   $ kshell
  k$ perl misc/cronjobs/fines.pl --verbose
SUCCESS => The first one runs normally, the second one exists really fast
  and prints a message about the lock.
3. Sign off :-D

Sponsored-by: Orex Digital

Signed-off-by: Tomas Cohen Arazi <tomascohen@theke.io>

Amended-pach JD: Fix syntax issue (typo Koha::Scrip and ';' after the
catch block)
Comment 22 Jonathan Druart 2020-04-13 10:11:10 UTC
(In reply to Jonathan Druart from comment #21)
> Amended-pach JD: Fix syntax issue (typo Koha::Scrip and ';' after the
> catch block)

"pach", that's quite ironical :)
Comment 23 Tomás Cohen Arazi 2020-04-13 11:56:04 UTC
Created attachment 102821 [details] [review]
Bug 23571: Prevent concurrent execution of fines.pl

This patch introduces locking in fines.pl. It does so by leveraging on
bug 25109, which introduces a generic locking implementation on
Koha::Script.

The introduced changes:
1. Try to get the lock
2.a. If success, normal execution happens
2.b. If rejected, cronlogaction is called with a meaningful message and
  a normal exit happens, so we don't flood the logs in vain. --verbose
  will make the script print the same message on STDERR, as already is
  the case with this script

To test:
1. Apply this patch
2. In two separate consoles run:
   $ kshell
  k$ perl misc/cronjobs/fines.pl --verbose
SUCCESS => The first one runs normally, the second one exists really fast
  and prints a message about the lock.
3. Sign off :-D

Sponsored-by: Orex Digital

Signed-off-by: Tomas Cohen Arazi <tomascohen@theke.io>

Amended-pach JD: Fix syntax issue (typo Koha::Scrip and ';' after the
catch block)
Comment 24 Kyle M Hall 2020-04-13 13:52:18 UTC
Created attachment 102844 [details] [review]
Bug 23571: Prevent concurrent execution of fines.pl

This patch introduces locking in fines.pl. It does so by leveraging on
bug 25109, which introduces a generic locking implementation on
Koha::Script.

The introduced changes:
1. Try to get the lock
2.a. If success, normal execution happens
2.b. If rejected, cronlogaction is called with a meaningful message and
  a normal exit happens, so we don't flood the logs in vain. --verbose
  will make the script print the same message on STDERR, as already is
  the case with this script

To test:
1. Apply this patch
2. In two separate consoles run:
   $ kshell
  k$ perl misc/cronjobs/fines.pl --verbose
SUCCESS => The first one runs normally, the second one exists really fast
  and prints a message about the lock.
3. Sign off :-D

Sponsored-by: Orex Digital

Signed-off-by: Tomas Cohen Arazi <tomascohen@theke.io>

Amended-pach JD: Fix syntax issue (typo Koha::Scrip and ';' after the
catch block)

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Comment 25 Jonathan Druart 2020-04-13 14:19:52 UTC
Why no "\n" in the print statement, is that expected?
Comment 26 Tomás Cohen Arazi 2020-04-13 14:57:31 UTC
(In reply to Jonathan Druart from comment #25)
> Why no "\n" in the print statement, is that expected?

I think I only missed it.
Comment 27 Tomás Cohen Arazi 2020-04-13 18:51:25 UTC
Created attachment 102888 [details] [review]
Bug 23571: (QA follow-up) Add missing newline in warning

Signed-off-by: Tomas Cohen Arazi <tomascohen@theke.io>
Comment 28 Jonathan Druart 2020-04-14 08:36:59 UTC
Created attachment 102910 [details] [review]
Bug 23571: Prevent concurrent execution of fines.pl

This patch introduces locking in fines.pl. It does so by leveraging on
bug 25109, which introduces a generic locking implementation on
Koha::Script.

The introduced changes:
1. Try to get the lock
2.a. If success, normal execution happens
2.b. If rejected, cronlogaction is called with a meaningful message and
  a normal exit happens, so we don't flood the logs in vain. --verbose
  will make the script print the same message on STDERR, as already is
  the case with this script

To test:
1. Apply this patch
2. In two separate consoles run:
   $ kshell
  k$ perl misc/cronjobs/fines.pl --verbose
SUCCESS => The first one runs normally, the second one exists really fast
  and prints a message about the lock.
3. Sign off :-D

Sponsored-by: Orex Digital

Signed-off-by: Tomas Cohen Arazi <tomascohen@theke.io>

Amended-pach JD: Fix syntax issue (typo Koha::Scrip and ';' after the
catch block)

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>

Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org>
Comment 29 Jonathan Druart 2020-04-14 08:37:02 UTC
Created attachment 102911 [details] [review]
Bug 23571: (QA follow-up) Add missing newline in warning

Signed-off-by: Tomas Cohen Arazi <tomascohen@theke.io>

Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org>
Comment 30 Jonathan Druart 2020-04-14 08:37:06 UTC
Created attachment 102912 [details] [review]
bug 23571: (QA follow-up) Remove perlcritic warning

Bareword file handle opened at line 138, column 5.  See pages 202,204 of PBP.  (Severity: 5)

Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org>
Comment 31 Martin Renvoize 2020-04-14 16:23:26 UTC
Nice work everyone!

Pushed to master for 20.05
Comment 32 Joy Nelson 2020-05-05 22:02:41 UTC
does not apply cleanly (Koha/Script.pm) to 19.11.x branch.  please rebase if needed.
Comment 33 Blou 2021-03-23 18:40:13 UTC
> Solved in my alternative patch. I chose to keep the output silent, unless
> --verbose is passed. This is the right behaviour for cronjobs, specially if
> we have the execution logged in the action_logs.

I'd like to understand how it is "the right behavior" for a process to not output a message when a fatal error occurs ?  I've seen the option -q added for quietness, but never to require -v to print fatal errors.

We ran the script manually and got nothing telling us it failed.  The action logs is NOT a valid alternative for meaningful (and efficient) error messages.
Comment 34 Jonathan Druart 2021-07-16 10:14:37 UTC
(In reply to Blou from comment #33)
> > Solved in my alternative patch. I chose to keep the output silent, unless
> > --verbose is passed. This is the right behaviour for cronjobs, specially if
> > we have the execution logged in the action_logs.
> 
> I'd like to understand how it is "the right behavior" for a process to not
> output a message when a fatal error occurs ?  I've seen the option -q added
> for quietness, but never to require -v to print fatal errors.
> 
> We ran the script manually and got nothing telling us it failed.  The action
> logs is NOT a valid alternative for meaningful (and efficient) error
> messages.

As the script is (by default) only called on a daily basis, it may be relevant to send to STDERR the lock error (even without --verbose).

Tomas, what do you think?