Bug 15240

Summary: Performance issue running overdue_notices.pl
Product: Koha Reporter: Sophie MEYNIEUX <sophie.meynieux>
Component: ToolsAssignee: Jonathan Druart <jonathan.druart>
Status: CLOSED FIXED QA Contact: Marcel de Rooy <m.de.rooy>
Severity: critical    
Priority: P5 - low CC: brendan, f.demians, gwilliams, janet.mcgowan, jonathan.druart, julian.maurice, jweaver, katrin.fischer, kyle, m.de.rooy, martin.renvoize, mtompset
Version: master   
Hardware: All   
OS: All   
See Also: http://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=12529
Change sponsored?: --- Patch complexity: Small patch
Documentation contact: Documentation submission:
Text to go in the release notes:
Version(s) released in:
Bug Depends on: 12529    
Bug Blocks: 15342    
Attachments: Bug 15240: Do not process issues with a date due later than today
Bug 15344: Remove some other calls of GetMemberDetails from pl scripts
Bug 15240: Do not process issues with a date due later than today
Bug 15240: Do not process issues with a date due later than today
Bug 15240: Do not process issues with a date due later than today
Bug 15240: [QA Follow-up] Minor adjustments

Description Sophie MEYNIEUX 2015-11-23 13:22:53 UTC
Since introduction of http://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=12529#add_comment "Overdue notices respect holidays" feature, there is a big problem of performance running overdue_notices.pl

For one of our client, where it used to take less than one hour, it now takes more than 7 hours. And this should be rune every day...

This is due to date criteria that were removed from SQL queries, so all current issues are parsed 3 times (once for each level of overdue) rather than just overdue issues concerning one given level.

Dealing with holidays should be done before quering issues, so that date criteria could be used.
Comment 1 Jonathan Druart 2015-12-08 13:17:44 UTC
Could you give information about the holidays? How many entries do you have in the special_holidays and repeatable_holidays tables?
Comment 2 Martin Renvoize 2015-12-08 19:18:11 UTC
We have a system that's really struggling with the same issue.

262 rows in special_holidays
9 rows in repeatable_holidays

We also have a system where the preferences are set to ignore the holidays and this runs much more quickly (though still isn't super quick). It has 921 special_holidays and 307 repeatable_holidays.

Hope that helps a little.

I'm happy to run a profile at the next run of the scripts unless someone else beats me to it.
Comment 3 Jonathan Druart 2015-12-09 11:47:30 UTC Comment hidden (obsolete)
Comment 4 Jonathan Druart 2015-12-09 11:49:45 UTC
Sophie, Martin,
If you are not using OverdueNoticeCalendar, the number of holidays should not change anything for you actually.
It would be great if you could have a look at this patch and compare the execution time, with and without.
Do not do it in production, I have not tested this patch enough to be 100% confident :)
Comment 5 Martin Renvoize 2015-12-09 13:08:20 UTC
That's what I meant by 'system where the preferences are set to ignore the holidays' in comment 2, I just couldn't remember what the pref was called ;)
Comment 6 Jonathan Druart 2015-12-09 15:47:26 UTC
So it could be related to the number of issues in the DB and this patch could do the job :)
Comment 7 Jonathan Druart 2015-12-09 17:52:08 UTC Comment hidden (obsolete)
Comment 8 Mark Tompsett 2016-01-06 04:17:16 UTC
Comment on attachment 45524 [details] [review]
Bug 15240: Do not process issues with a date due later than today

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

This eyeballs well.

::: misc/cronjobs/overdue_notices.pl
@@ +454,4 @@
>      AND b.branchcode = items.homebranch
>      AND biblio.biblionumber   = biblioitems.biblionumber
>      AND issues.borrowernumber = ?
> +    AND TO_DAYS($date)-TO_DAYS(issues.date_due) >= 0

This makes sure all the filtering based on date is done by MySQL.

@@ -500,5 @@
>              # <date> <itemcount> <firstname> <lastname> <address1> <address2> <address3> <city> <postcode> <country>
>  
> -            my $borrower_sql = <<'END_SQL';
> -SELECT issues.borrowernumber, firstname, surname, address, address2, city, zipcode, country, email, emailpro, B_email, smsalertnumber, phone, cardnumber,
> -TO_DAYS(?)-TO_DAYS(date_due) as difference, date_due

'difference' field removed because it is moved to part of the WHERE condition.

@@ +505,4 @@
>  FROM   issues,borrowers,categories
>  WHERE  issues.borrowernumber=borrowers.borrowernumber
>  AND    borrowers.categorycode=categories.categorycode
> +AND    TO_DAYS($date)-TO_DAYS(issues.date_due) >= 0

This was the difference field, which strangely was never really used, and by limiting the SQL query here (make SQL do the work), this speeds the script up.

Also, the ? in the TO_DAYS was changed to a hard coded $date. Gut feeling: meh, not a big deal.

@@ -508,3 @@
>  END_SQL
>              my @borrower_parameters;
> -            push @borrower_parameters, $date_to_run->datetime();

Removed, because the ? was changed to a hard coded $date.

@@ -526,5 @@
>              my $borrowernumber;
>              while ( my $data = $sth->fetchrow_hashref ) {
>  
> -                next unless ( DateTime->compare( $date_to_run, dt_from_string($data->{date_due})) ) == 1;
> -

Perl filtering on a larger data set is slower. Hence the removal of this, when replaced by the SQL grunt work.

@@ -616,5 @@
>                  my $j = 0;
>                  my $exceededPrintNoticesMaxLines = 0;
>                  while ( my $item_info = $sth2->fetchrow_hashref() ) {
> -                    next unless ( DateTime->compare( $date_to_run,  dt_from_string($item_info->{date_due})) ) == 1;
> -

Perl filtering on a larger data set is slower. Hence the removal of this, when replaced by the SQL grunt work.
Comment 9 Mark Tompsett 2016-01-06 04:48:18 UTC
It's nearing midnight, and there is no express test plan to follow or steps to take to generate the data necessary to sign off. :(
Comment 10 Jonathan Druart 2016-01-06 08:29:41 UTC
Test plan:
Launch the overdue_notices.pl on a large DB and compare the execution times with and without patch applied.
No behavior difference should be noticed.
Comment 11 HB-NEKLS 2016-01-07 19:54:33 UTC
Jonathan, I'm checking with ByWater to see if our rather large test system (running 3.22.1) database could somehow be used to help test the patch as you suggested you needed a large db to do it. I'll let you know what I find out.
Comment 12 Chris Cormack 2016-01-07 20:04:19 UTC Comment hidden (obsolete)
Comment 13 Jonathan Druart 2016-01-08 08:46:59 UTC
Hi Chris,
Thanks for testing!
Did you compare the execution times before and after the patches?
Comment 14 Kyle M Hall 2016-01-08 12:28:33 UTC
Pre patch:

time misc/cronjobs/overdue_notices.pl -t -itemscontent title,author,itemcallnumber,barcode,replacementprice

real	2m9.252s
user	2m5.492s
sys	0m0.108s

Post Patch:

time misc/cronjobs/overdue_notices.pl -t -itemscontent title,author,itemcallnumber,barcode,replacementprice

real	1m19.965s
user	1m12.437s
sys	0m0.192s

mysql> select COUNT(*) from issues where date_due > now();
+----------+
| COUNT(*) |
+----------+
|      480 |
+----------+
1 row in set (0.01 sec)

mysql> select COUNT(*) from issues where date_due <= now();
+----------+
| COUNT(*) |
+----------+
|    65218 |
+----------+
1 row in set (0.01 sec)

I found it quite striking how much of a time difference there was even though the number of checkouts not due yet is quite low so I ran the tests again with very similar results!
Comment 15 Jesse Weaver 2016-01-12 00:26:11 UTC
Kyle, Heather, does this changed script yield the same results? It passes my QA, as it just moves the date comparison into MySQL and preserves the --date functionality.
Comment 16 Kyle M Hall 2016-01-12 14:52:34 UTC
(In reply to Jesse Weaver from comment #15)
> Kyle, Heather, does this changed script yield the same results? It passes my
> QA, as it just moves the date comparison into MySQL and preserves the --date
> functionality.

I did not think to check that, I was focused on performance testing.
Comment 17 Katrin Fischer 2016-01-12 15:01:07 UTC
For us it's terribly important that the functionality remains unchanged and it's not quickly testable in Koha. Please don't rush this.
Comment 18 Kyle M Hall 2016-01-12 15:16:03 UTC
(In reply to Katrin Fischer from comment #17)
> For us it's terribly important that the functionality remains unchanged and
> it's not quickly testable in Koha. Please don't rush this.

Katrin, you are more than welcome to take point on QA for this bug. I wasn't QA'ing it, I was only doing performance testing.
Comment 19 Katrin Fischer 2016-01-12 15:29:09 UTC
I hope to get around to it soon - but the more testing the better. Overdues are a bit of a complicated matter. We only actively use it with the overdue and notice triggers - if someone else could verify it works the same as before without -t that would be helpful.
Comment 20 Marcel de Rooy 2016-01-22 10:16:22 UTC
QA: Looking at this one..
Comment 21 Marcel de Rooy 2016-01-22 10:58:54 UTC
(In reply to Marcel de Rooy from comment #20)
> QA: Looking at this one..

Will continue later (if no one else does).
Comment 22 Marcel de Rooy 2016-01-27 12:40:31 UTC Comment hidden (obsolete)
Comment 23 Marcel de Rooy 2016-01-27 12:42:22 UTC
Only tested git-bz; please wait..
Comment 24 Marcel de Rooy 2016-01-27 15:03:50 UTC
(In reply to Katrin Fischer from comment #19)
> I hope to get around to it soon - but the more testing the better. Overdues
> are a bit of a complicated matter. We only actively use it with the overdue
> and notice triggers - if someone else could verify it works the same as
> before without -t that would be helpful.

No reasons to worry. Actually, the code part where the triggered condition is executed (if passed), was not touched.
Comment 25 Marcel de Rooy 2016-01-27 15:14:27 UTC
Created attachment 47353 [details] [review]
Bug 15240: Do not process issues with a date due later than today

There is no need to do this job in Perl, MySQL could do it instead.
The idea is to only retrieve the issues info which could be overdued.

To test:
1/ Run the script
2/ Apply the patch
3/ Run the script again, notice the exact same results but execution time is faster

Signed-off-by: Chris Cormack <chrisc@catalyst.net.nz>
Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 26 Marcel de Rooy 2016-01-27 15:14:34 UTC
Created attachment 47354 [details] [review]
Bug 15240: [QA Follow-up] Minor adjustments

This patch does:
[1] It removes some unused modules.
[2] It adds some options not listed in the synopsis.
[3] It removes an unused sql expression from one query.
    Note: In fines related code the third parameter of CalcFine sometimes
    is named as days_overdue too.
[4] Corrects a few typos in comments or pod.

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 27 Marcel de Rooy 2016-01-27 15:15:36 UTC
QA Comment:
Your change generally looks good to me. But I will be very precise here :)

Note that you use TO_DAYS in the query. So you select the current date with all hours too. Formerly, records of today were compared with date_to_run (including time) eliminating the records in hours still to come. As long as $mindays is not zero (from overduerules), these records will be discarded later on (L 544-555) since mindays may not be zero in the code of this script (line 490).

Another point is the -date parameter. I am not sure what it actually should do btw, since it is documented rather poorly. Looking through code, it seems to mimic running on a different date (e.g. say -date <yesterday> or -date <tomorrow> e.g.). The same argument as above could be repeated for the records of the specific date given via this parameter.
This actually brings me to the conclusion that you made a large first step, but the second step would be moving the checks for mindays and maxdays into the SQL statement too. Note that it may run three times with different values for the three triggers. Another report? 

Related: While testing PREDUE and ODUE, I found that using -n on the command line will generate the error that the print notice for PREDUE and ODUE are not found. Copying them from email, revealed that PREDUE should use a block <item>...</item> in order to have the title displayed, or should use <items.content>. In a new installation this should be corrected. If you confirm that, we could address it on a new report too?

I used the opportunity to add a few minor adjustments in a follow-up.

Passed QA
Comment 28 Jonathan Druart 2016-01-27 16:12:03 UTC
(In reply to Marcel de Rooy from comment #27)
> Another point is the -date parameter. I am not sure what it actually should
> do btw, since it is documented rather poorly. Looking through code, it seems
> to mimic running on a different date (e.g. say -date <yesterday> or -date
> <tomorrow> e.g.). The same argument as above could be repeated for the
> records of the specific date given via this parameter.

That's exactly what it does.

> This actually brings me to the conclusion that you made a large first step,
> but the second step would be moving the checks for mindays and maxdays into
> the SQL statement too. Note that it may run three times with different
> values for the three triggers. Another report? 

I had in mind it was not possible, because of the calendar checks.
But looking at the code again, it seems possible.

> Related: While testing PREDUE and ODUE, I found that using -n on the command
> line will generate the error that the print notice for PREDUE and ODUE are
> not found. Copying them from email, revealed that PREDUE should use a block
> <item>...</item> in order to have the title displayed, or should use
> <items.content>. In a new installation this should be corrected. If you
> confirm that, we could address it on a new report too?

Indeed, ODUE.print should exist, we could add the print template if it does not exist.
PREDUE is used by advance_notices.pl

> I used the opportunity to add a few minor adjustments in a follow-up.

They looks good to me.

> Passed QA

Thanks!
Comment 29 Brendan Gallagher 2016-01-28 19:17:15 UTC
Pushed to Master - Should be in the May 2016 release.  Thanks!
Comment 30 Julian Maurice 2016-01-29 10:06:28 UTC
Patch pushed to 3.22.x, will be in 3.22.3
Comment 31 Frédéric Demians 2016-02-12 06:36:31 UTC
This patch has been pushed to 3.20.x, will be in 3.20.9.
Comment 32 Katrin Fischer 2016-02-28 22:03:41 UTC
I have tested these patches in 3.22.3 now and all works well!