Bug 14494

Summary: Terribly slow checkout caused by DateTime->new in far future
Product: Koha Reporter: Marcel de Rooy <m.de.rooy>
Component: Architecture, internals, and plumbingAssignee: Marcel de Rooy <m.de.rooy>
Status: CLOSED FIXED QA Contact: Testopia <testopia>
Severity: normal    
Priority: P5 - low CC: chris, jonathan.druart, kyle, liz, marjorie.barry-vila, mtj, tomascohen
Version: Main   
Hardware: All   
OS: All   
See Also: http://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=13242
http://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=14197
http://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=14522
Change sponsored?: --- Patch complexity: Small patch
Documentation contact: Documentation submission:
Text to go in the release notes:
Version(s) released in:
Circulation function:
Bug Depends on: 12669    
Bug Blocks:    
Attachments: Bug 14494: Prevent slow checkout if the patron does not have an expiry date
Bug 14494: Terribly slow checkout caused by DateTime->new in far future
Bug 14494: Terribly slow checkout caused by DateTime->new in far future
Bug 14494: Prevent slow checkout if the patron does not have an expiry date
Bug 14494: Terribly slow checkout caused by DateTime->new in far future
Bug 14494: Unit test
Bug 14494: Unit test
Bug 14494: Unit tests for CanBookBeIssued related to dateexpiry
Bug 14494: Add some unit tests too for CalcDateDue
Bug 14494: Prevent slow checkout if the patron does not have an expiry date
Bug 14494: Terribly slow checkout caused by DateTime->new in far future
Bug 14494: Unit tests for CanBookBeIssued related to dateexpiry
Bug 14494: Add some unit tests too for CalcDateDue
[PASSED QA] Bug 14494: Prevent slow checkout if the patron does not have an expiry date
[PASSED QA] Bug 14494: Terribly slow checkout caused by DateTime->new in far future
[PASSED QA] Bug 14494: Unit tests for CanBookBeIssued related to dateexpiry
[PASSED QA] Bug 14494: Add some unit tests too for CalcDateDue

Description Marcel de Rooy 2015-07-06 11:33:00 UTC
An expiry date of 9999-12-31 for organizations was a nice idea :)
But checking out an item to that patron takes 1 minute or longer !
The cause?
The following lines in CanBookBeIssued seem to be the main cause:
            my $expiry_dt = DateTime->new(
                year => $y,
                month => $m,
                day   => $d,
                time_zone => C4::Context->tz,
            );
This call takes forever with 9999-12-31 when the timezone is not 'floating' or 'UTC', but e.g. Europe/Amsterdam.
If the timezone is UTC, it takes 0.0002 seconds.

DateTime gives the following advices:
===
Do not try to use named time zones (like "America/Chicago") with dates very far in the future (thousands of years). The current implementation of DateTime::TimeZone will use a huge amount of memory calculating all the DST changes from now until the future date. Use UTC or the floating time zone and you will be safe.

•use UTC for all calculations 
If you do care about time zones (particularly DST) or leap seconds, try to use non-UTC time zones for presentation and user input only. Convert to UTC immediately and convert back to the local time zone for presentation

The results DateTime.pm produces are predictable and correct, and mostly intuitive, but datetime math gets very ugly when time zones are involved ...
===
We are not doing that currently. We use in C4::Context:
DateTime::TimeZone->new(name => 'local')

Could we implement the calculation/presentation advice of DateTime in Koha somehow?
Comment 1 Jonathan Druart 2015-07-09 09:00:58 UTC Comment hidden (obsolete)
Comment 2 Katrin Fischer 2015-07-09 09:05:32 UTC
Hm, I feel a bit like this builds in a secret feature - if I use 9998 it will be slow, but if I use 9999 it will be faster? 

When we fixed the same thing for debarments it made more sense, as the 'ulimited' debarment uses 9999 automatically, without the user entering a date. For the patron expiry the date is defined by the library and could be anything.
Comment 3 Jonathan Druart 2015-07-09 09:18:18 UTC
(In reply to Katrin Fischer from comment #2)
> Hm, I feel a bit like this builds in a secret feature - if I use 9998 it
> will be slow, but if I use 9999 it will be faster? 
> 
> When we fixed the same thing for debarments it made more sense, as the
> 'ulimited' debarment uses 9999 automatically, without the user entering a
> date. For the patron expiry the date is defined by the library and could be
> anything.

As I understood the description, the feature has existed.
Anyway we should call Koha::DateUtils here and not directly DateTime.
Comment 4 Katrin Fischer 2015-07-09 09:30:03 UTC
I don't think it's a feature - it has to be typed in manually in the configuration. I think it would make sense to me if we introduced an option to have an 'unlimited' expiry date in the GUI - then the check on 9999 would make more sense to me.
Comment 5 Marcel de Rooy 2015-07-09 10:00:20 UTC Comment hidden (obsolete)
Comment 6 Marcel de Rooy 2015-07-09 10:01:17 UTC
Typical example of patch collision.
Can we get the best of both?
Comment 7 Marcel de Rooy 2015-07-09 10:01:51 UTC
(In reply to Katrin Fischer from comment #2)
> Hm, I feel a bit like this builds in a secret feature - if I use 9998 it
> will be slow, but if I use 9999 it will be faster? 
> 
> When we fixed the same thing for debarments it made more sense, as the
> 'ulimited' debarment uses 9999 automatically, without the user entering a
> date. For the patron expiry the date is defined by the library and could be
> anything.

We should not do hardcoded tests on 9999.
Comment 8 Jonathan Druart 2015-07-09 10:08:28 UTC
(In reply to Marcel de Rooy from comment #6)
> Typical example of patch collision.
> Can we get the best of both?

As I already said, IMO we should not use DateTime outside of Koha::DateUtils.
Comment 9 Marcel de Rooy 2015-07-09 10:14:35 UTC
(In reply to Jonathan Druart from comment #8)
> (In reply to Marcel de Rooy from comment #6)
> > Typical example of patch collision.
> > Can we get the best of both?
> 
> As I already said, IMO we should not use DateTime outside of Koha::DateUtils.

That is fine. My patch also touches CalcDateDue. I will rework it now. Can we prevent another duplication of effort?
Comment 10 Marcel de Rooy 2015-07-09 10:16:02 UTC
btw I will also remove the 9999
Note that I am having trouble now with the Circulation test. It fails with me on test 49 already.
not ok 49 - No items due in less than one day (0 days in advance)
#   Failed test 'No items due in less than one day (0 days in advance)'
#   at t/db_dependent/Circulation.t line 527.
#          got: '2'
#     expected: '0'
Comment 11 Marcel de Rooy 2015-07-09 10:37:04 UTC Comment hidden (obsolete)
Comment 12 Marcel de Rooy 2015-07-09 10:58:38 UTC
not ok 49 - No items due in less than one day (0 days in advance)
#   Failed test 'No items due in less than one day (0 days in advance)'
#   at t/db_dependent/Circulation.t line 527.
#          got: '2'
#     expected: '0'

Resolved this one now. The staff expiry was too quick :)
Still looking now at:

ok 61 - Calling UpdateFine on non-existant fine with an amount of 0 does not result in an empty fine
DBD::mysql::db begin_work failed: Already in a transaction at /usr/share/perl5/DBIx/Class/Storage/DBI.pm line 1339.
DBIx::Class::Schema::txn_begin(): DBD::mysql::db begin_work failed: Already in a transaction at /usr/share/perl5/DBIx/Class/Storage/DBI.pm line 1339. at /home/koha/testclone/t/lib/TestBuilder.pm line 75
DBIx::Class::Schema::txn_rollback(): Storage transaction_depth 0 does not match false AutoCommit of DBI::db=HASH(0xb24823c), attempting ROLLBACK anyway at /home/koha/testclone/t/lib/TestBuilder.pm line 360
Comment 13 Marcel de Rooy 2015-07-09 11:58:21 UTC Comment hidden (obsolete)
Comment 14 Marcel de Rooy 2015-07-09 11:58:24 UTC Comment hidden (obsolete)
Comment 15 Marcel de Rooy 2015-07-09 11:58:28 UTC Comment hidden (obsolete)
Comment 16 Marcel de Rooy 2015-07-09 12:02:02 UTC
Needs a signoff on the second path to get this into SO queue.
Comment 17 Marcel de Rooy 2015-07-09 12:09:58 UTC Comment hidden (obsolete)
Comment 18 Marcel de Rooy 2015-07-09 12:23:30 UTC Comment hidden (obsolete)
Comment 19 Marcel de Rooy 2015-07-10 07:48:04 UTC Comment hidden (obsolete)
Comment 20 Jonathan Druart 2015-07-10 08:22:09 UTC Comment hidden (obsolete)
Comment 21 Jonathan Druart 2015-07-10 08:22:13 UTC Comment hidden (obsolete)
Comment 22 Jonathan Druart 2015-07-10 08:22:16 UTC Comment hidden (obsolete)
Comment 23 Jonathan Druart 2015-07-10 08:22:20 UTC Comment hidden (obsolete)
Comment 24 Kyle M Hall (khall) 2015-07-10 15:33:11 UTC
Created attachment 40932 [details] [review]
[PASSED QA] Bug 14494: Prevent slow checkout if the patron does not have an expiry date

If a patron has a expiry date set to 9999-12-31 (for organizations for
instance), the checkouts are very slow.

It's caused by 2 different calls to DateTime in CanBookBeIssued:
1/
  DateTime->new( year => 9999, month => 12, day => 31, time_zone => C4::Context->tz );
The time_zone should not be set (as it's done in Koha::DateUtils), set to UTC or floating tz.

2/
  DateTime->compare($today, $expiry_dt)
The comparaison of 2 DT with 1 related to 9999 is very slow, as you can
imagine.

For 1/ we need to call Koha::DateUtils::dt_from_string (actually, we
should never call DateTime directly).
For 2/ we just need to test if the date is != 9999, no need to compare
it in this case.

Test plan:
Before this patch, confirm that the checkouts are slow if the patron has a
dateexpiry set to 9999-12-31.
update borrowers set dateexpiry="9999-12-31" where borrowernumber=42;

After this patch, you should not see any regression when checking out
items to an expired patron and to a valid patron.

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>

Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org>

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Comment 25 Kyle M Hall (khall) 2015-07-10 15:33:15 UTC
Created attachment 40933 [details] [review]
[PASSED QA] Bug 14494: Terribly slow checkout caused by DateTime->new in far future

An expiry date like 9999-12-31 in the local timezone will make DateTime
spend a lot of time (maybe 60 seconds) on date calculation. See the
DateTime documention on CPAN.
A calculation in floating (or alternatively in UTC) would only take
a few milliseconds.

This patch makes two changes in this regard:

[1] The compare between expiry date and today in CanBookBeIssued has been
    adjusted in Jonathan's patch. I am moving the compare to the floating
    timezone (as was done in my original patch). This removes a hardcoded
    9999.
[2] If ReturnBeforeExpiry is enabled, CalcDateDue compares the normal due
    date with the expiry date. The comparison is now done in the floating
    timezone. If the expiry date is before the due date, it is
    returned in the user context's timezone.

NOTE: The calls to set_time_zone moving to or from floating do not adjust
the local time.

TEST PLAN:
First without this patch (and the one from Jonathan):
[1] Set expiry date to 9999-12-31 for a patron.
[2] Enable ReturnBeforeExpiry.
[3] Checkout a book to this patron. This will be (very) slow.

Continue now with this patch applied:
[4] Check in the same book.
[5] Check it out again. Should be much faster.

Bonus test:
[6] Set borrower expiry date to today. Change relevant circulation rule
    to loan period of 21 hours. Test checking out with a manual due date
    /time just before today 23:59 and after that. In the second case the
    due date/time should become today 23:59 (note that 23:59 is not
    shown on the checkout form).

Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org>

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Comment 26 Kyle M Hall (khall) 2015-07-10 15:33:19 UTC
Created attachment 40934 [details] [review]
[PASSED QA] Bug 14494: Unit tests for CanBookBeIssued related to dateexpiry

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Moved the test on its own. Nicer than adding TestBuilder in the final part
of the test. No warnings/errors from TestBuilder, no dependency..

Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org>

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Comment 27 Kyle M Hall (khall) 2015-07-10 15:33:22 UTC
Created attachment 40935 [details] [review]
[PASSED QA] Bug 14494: Add some unit tests too for CalcDateDue

The second patch of this report made some changes to CalcDateDue.
We are adding some unit tests here.
See the commments on the third patch too.

Test plan:
Run t/db_dependent/Circulation_dateexpiry.t

Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org>
Amended patch: Set the number of tests for the second subtest (was
commented) and perltidy the second block.

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Comment 28 Jonathan Druart 2015-07-16 08:17:22 UTC
We should have a look later at DateTime::Infinite
http://search.cpan.org/~drolsky/DateTime-1.20/lib/DateTime/Infinite.pm
Comment 29 Tomás Cohen Arazi (tcohen) 2015-07-20 13:27:50 UTC
Patches pushed to master.

Thanks Marcel and Jonathan!
Comment 30 Chris Cormack 2015-07-29 20:33:59 UTC
Pushed to 3.20.x will be in 3.20.3
Comment 31 Liz Rea 2015-08-04 01:40:39 UTC
Pushed to 3.18.x, will be in 3.18.10.
Comment 32 Mason James 2015-08-28 02:47:39 UTC
(In reply to Liz Rea from comment #31)
> Pushed to 3.18.x, will be in 3.18.10.

Pushed to 3.16.x, will be in 3.16.14