Bug 19176 - Dates comparison fails on slow server
Summary: Dates comparison fails on slow server
Status: Pushed to Master
Alias: None
Product: Koha
Classification: Unclassified
Component: Test Suite (show other bugs)
Version: master
Hardware: All All
: P5 - low normal (vote)
Assignee: Jonathan Druart
QA Contact: Julian Maurice
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-08-25 20:57 UTC by Jonathan Druart
Modified: 2017-11-03 16:53 UTC (History)
6 users (show)

See Also:
Change sponsored?: ---
Patch complexity: ---
Bot Control: ---
When did the bot last check this:
Who signed the patch off:
Text to go in the release notes:


Attachments
Bug 19176: Truncate to minutes when comparing dates in tests (6.04 KB, patch)
2017-08-25 20:59 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 19176: Compare the number of seconds when comparing dates in tests (6.14 KB, patch)
2017-08-28 19:23 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 19176: Compare the number of seconds when comparing dates in tests (6.18 KB, patch)
2017-09-22 18:08 UTC, David Bourgault
Details | Diff | Splinter Review
Bug 19176: Compare the number of seconds when comparing dates in tests (7.52 KB, patch)
2017-10-13 15:36 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 19176: Reduce the number of seconds to 5 (1.42 KB, patch)
2017-10-23 14:40 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 19176: Compare the number of seconds when comparing dates in tests (7.51 KB, patch)
2017-10-23 14:44 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 19176: Reduce the number of seconds to 5 (1.41 KB, patch)
2017-10-23 14:44 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 19176: Compare the number of seconds when comparing dates in tests (7.54 KB, patch)
2017-10-23 22:35 UTC, Josef Moravec
Details | Diff | Splinter Review
Bug 19176: Reduce the number of seconds to 5 (1.45 KB, patch)
2017-10-23 22:35 UTC, Josef Moravec
Details | Diff | Splinter Review
Bug 19176: followup - fix POD in t/lib/Dates.pm (730 bytes, patch)
2017-10-23 22:36 UTC, Josef Moravec
Details | Diff | Splinter Review
Bug 19176: Fix how t::lib::Dates::compare handle timezone (2.11 KB, patch)
2017-10-30 14:42 UTC, Julian Maurice
Details | Diff | Splinter Review
Bug 19176: (QA follow-up) few cosmetic changes (1.31 KB, patch)
2017-11-03 16:52 UTC, Jonathan Druart
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Jonathan Druart 2017-08-25 20:57:47 UTC
#   Failed test 'borrowers.updated_on should have been set to now on creating'
#   at t/db_dependent/Patrons.t line 74.
#          got: '2017-08-10T20:53:03'
#     expected: '2017-08-10T20:53:04'
# Looks like you failed 1 test of 17.
[20:53:15] t/db_dependent/Patrons.t .....................................
Comment 1 Jonathan Druart 2017-08-25 20:59:59 UTC
Created attachment 66493 [details] [review]
Bug 19176: Truncate to minutes when comparing dates in tests

#   Failed test 'borrowers.updated_on should have been set to now on creating'
  #   at t/db_dependent/Patrons.t line 74.
  #          got: '2017-08-10T20:53:03'
  #     expected: '2017-08-10T20:53:04'
  # Looks like you failed 1 test of 17.
  [20:53:15] t/db_dependent/Patrons.t .....................................

The plan here is to compare string and/or DateTime objects and truncate the DateTime to minute
That way tests will no longer fail when the seconds differ
Comment 2 Marc Véron 2017-08-26 11:45:50 UTC
Hi Jonathan

The patch minifies that false positives happen, but IMO the test will still arbitrarely fail with e.g. following dates:

got: '2017-08-10T20:53:59'
expected: '2017-08-10T20:54:00'

Wouldn't it be safer to calculate the delta and pass the test OK if delta <60 sec?
(Or even introduce a param for the precision that defaults to 60.)

Marc
Comment 3 Jonathan Druart 2017-08-28 19:23:01 UTC
Created attachment 66563 [details] [review]
Bug 19176: Compare the number of seconds when comparing dates in tests

#   Failed test 'borrowers.updated_on should have been set to now on creating'
  #   at t/db_dependent/Patrons.t line 74.
  #          got: '2017-08-10T20:53:03'
  #     expected: '2017-08-10T20:53:04'
  # Looks like you failed 1 test of 17.
  [20:53:15] t/db_dependent/Patrons.t .....................................

The plan here is to compare the number of seconds between two dates.
If < 60 the dates are consired as identicals.
Comment 4 Jonathan Druart 2017-08-28 19:24:32 UTC
(In reply to Marc Véron from comment #2)
> Wouldn't it be safer to calculate the delta and pass the test OK if delta
> <60 sec?
> (Or even introduce a param for the precision that defaults to 60.)

Yes, I though about that but considered as negligible/can be ignored.
But you are right, let's fix it correctly :)
Comment 5 Tomás Cohen Arazi 2017-08-30 21:48:47 UTC
(In reply to Marc Véron from comment #2)
> Hi Jonathan
> 
> The patch minifies that false positives happen, but IMO the test will still
> arbitrarely fail with e.g. following dates:
> 
> got: '2017-08-10T20:53:59'
> expected: '2017-08-10T20:54:00'
> 
> Wouldn't it be safer to calculate the delta and pass the test OK if delta
> <60 sec?
> (Or even introduce a param for the precision that defaults to 60.)
> 
> Marc

The datetime should be mocked IMO.
Comment 6 David Bourgault 2017-09-22 18:08:40 UTC
Created attachment 67322 [details] [review]
Bug 19176: Compare the number of seconds when comparing dates in tests

  #   Failed test 'borrowers.updated_on should have been set to now on creating'
  #   at t/db_dependent/Patrons.t line 74.
  #          got: '2017-08-10T20:53:03'
  #     expected: '2017-08-10T20:53:04'
  # Looks like you failed 1 test of 17.
  [20:53:15] t/db_dependent/Patrons.t .....................................

The plan here is to compare the number of seconds between two dates.
If < 60 the dates are consired as identicals.

Signed-off-by: David Bourgault <david.bourgault@inlibro.com>
Comment 7 Julian Maurice 2017-10-13 12:10:52 UTC
t::lib::Dates::compare doesn't trigger a fail if dates differ only in hours, days, months or years. For instance,

t::lib::Dates::compare('2017-01-01 01:00:00', '2018-02-02 02:00:00') says
ok 1 - (in 0 seconds)

Also, I think t::lib::Dates::compare shouldn't call ok(), because when a test fails it reports the filename and line where the test failed, and it will always be t/lib/Dates.pm, line 22, which is not very useful.

IMO it should return -1, 0 or 1 (like DateTime::compare) and should be called like that:
ok(0 == t::lib::Dates::compare($got, $expected), $description)
Comment 8 Julian Maurice 2017-10-13 12:28:21 UTC
... and it doesn't consider timezone.

my $dt = DateTime->new(
    year => 2017,
    month => 1,
    day => 1,
    hour => 1,
    minute => 1,
    second => 0,
    time_zone => '+0000',
);
my $dt2 = DateTime->new(
    year => 2017,
    month => 1,
    day => 1,
    hour => 1,
    minute => 1,
    second => 0,
    time_zone => '+0400',
);
t::lib::Dates::compare($dt, $dt2, 'different timezones');

says 'ok'.

Maybe you should compare "epoch values" (DateTime::epoch) instead.
Comment 9 Jonathan Druart 2017-10-13 15:36:37 UTC
Created attachment 68082 [details] [review]
Bug 19176: Compare the number of seconds when comparing dates in tests

#   Failed test 'borrowers.updated_on should have been set to now on creating'
  #   at t/db_dependent/Patrons.t line 74.
  #          got: '2017-08-10T20:53:03'
  #     expected: '2017-08-10T20:53:04'
  # Looks like you failed 1 test of 17.
  [20:53:15] t/db_dependent/Patrons.t .....................................

The plan here is to compare the number of seconds between two dates.
If < 60 the dates are consired as identicals.
Comment 10 Jonathan Druart 2017-10-13 15:37:27 UTC
Thanks Julian, excellent remarks. I rewrote the patch and add tests for the new module. Switch back to Needs Signoff.
Comment 11 M. Tompsett 2017-10-16 13:24:31 UTC
Comment on attachment 68082 [details] [review]
Bug 19176: Compare the number of seconds when comparing dates in tests

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

::: t/Test/Dates.pm
@@ +10,5 @@
> +
> +is( t::lib::Dates::compare( $dt_1, $dt_2 ), -1, '2017 is before 2018' );
> +is( t::lib::Dates::compare( $dt_2, $dt_1 ), 1,  '2018 is after 2017' );
> +
> +is( t::lib::Dates::compare( $date_1, $date_2 ), -1, '2017 is before 2018 (strings comparaison)' );

Typo: comparison.

::: t/lib/Dates.pm
@@ +19,5 @@
> +    my $dt_expected = dt_from_string($expected);
> +    $dt_got->set_time_zone('floating');
> +    $dt_expected->set_time_zone('floating');
> +    my $diff = $dt_got->epoch - $dt_expected->epoch;
> +    if ( abs($diff) < 60 ) { return 0 }

A slow server isn't going to have a 15+ second gap, I believe this 60 could be smaller.
Comment 12 Magnus Enger 2017-10-23 09:31:56 UTC
How can this be tested? Just run the tests in t/db_dependent/Patrons.t and t/db_dependent/Virtualshelves.t?
Comment 13 Jonathan Druart 2017-10-23 14:40:06 UTC
Created attachment 68412 [details] [review]
Bug 19176: Reduce the number of seconds to 5
Comment 14 Jonathan Druart 2017-10-23 14:44:10 UTC
Created attachment 68413 [details] [review]
Bug 19176: Compare the number of seconds when comparing dates in tests

#   Failed test 'borrowers.updated_on should have been set to now on creating'
  #   at t/db_dependent/Patrons.t line 74.
  #          got: '2017-08-10T20:53:03'
  #     expected: '2017-08-10T20:53:04'
  # Looks like you failed 1 test of 17.
  [20:53:15] t/db_dependent/Patrons.t .....................................

The plan here is to compare the number of seconds between two dates.
If < 60 the dates are consired as identicals.
Comment 15 Jonathan Druart 2017-10-23 14:44:29 UTC
Created attachment 68414 [details] [review]
Bug 19176: Reduce the number of seconds to 5
Comment 16 Jonathan Druart 2017-10-23 14:46:31 UTC
(In reply to M. Tompsett from comment #11)
> Typo: comparison.

Fixed.

> ::: t/lib/Dates.pm
> @@ +19,5 @@
> > +    my $dt_expected = dt_from_string($expected);
> > +    $dt_got->set_time_zone('floating');
> > +    $dt_expected->set_time_zone('floating');
> > +    my $diff = $dt_got->epoch - $dt_expected->epoch;
> > +    if ( abs($diff) < 60 ) { return 0 }
> 
> A slow server isn't going to have a 15+ second gap, I believe this 60 could
> be smaller.

Reduced to 5.

(In reply to Magnus Enger from comment #12)
> How can this be tested? Just run the tests in t/db_dependent/Patrons.t and
> t/db_dependent/Virtualshelves.t?

yes, and t/Test/Dates.t
Comment 17 Josef Moravec 2017-10-23 22:35:48 UTC
Created attachment 68448 [details] [review]
Bug 19176: Compare the number of seconds when comparing dates in tests

#   Failed test 'borrowers.updated_on should have been set to now on creating'
  #   at t/db_dependent/Patrons.t line 74.
  #          got: '2017-08-10T20:53:03'
  #     expected: '2017-08-10T20:53:04'
  # Looks like you failed 1 test of 17.
  [20:53:15] t/db_dependent/Patrons.t .....................................

The plan here is to compare the number of seconds between two dates.
If < 60 the dates are consired as identicals.

Signed-off-by: Josef Moravec <josef.moravec@gmail.com>
Comment 18 Josef Moravec 2017-10-23 22:35:55 UTC
Created attachment 68449 [details] [review]
Bug 19176: Reduce the number of seconds to 5

Signed-off-by: Josef Moravec <josef.moravec@gmail.com>
Comment 19 Josef Moravec 2017-10-23 22:36:01 UTC
Created attachment 68450 [details] [review]
Bug 19176: followup - fix POD in t/lib/Dates.pm

Signed-off-by: Josef Moravec <josef.moravec@gmail.com>
Comment 20 Julian Maurice 2017-10-27 13:24:03 UTC
There's still something wrong with timezones.

Try this:

$dt_1 = DateTime->new(year => 2001, month => 1, day => 1, hour => 0, minute => 0, second => 0, time_zone => '+0100');
$dt_3 = DateTime->new(year => 2001, month => 1, day => 1, hour => 1, minute => 0, second => 0, time_zone => '+0200');
is( DateTime->compare($dt_1, $dt_3), 0 );
is( t::lib::Dates::compare( $dt_1, $dt_3 ), 0 );

$dt_1 and $dt_3 are the exact same time, but with a different timezone.
DateTime->compare returns 0, but t::lib::Dates::Compare returns -1, because it sets timezone of both date to 'floating' before comparing them, which is wrong not only because it produces a false result, but also because comparing DateTime objects shouldn't modify them.

Also a note on this line:

$dt_3 = $dt_1->clone->set_time_zone('+0400');

It doesn't do what you think. After that line, $dt_3 is still equal to $dt_1 (with a different timezone) because set_time_zone also adjusts the local time (see http://search.cpan.org/~drolsky/DateTime-1.44/lib/DateTime.pm#$dt-%3Eset_time_zone%28_$tz_%29)
Comment 21 Jonathan Druart 2017-10-30 14:32:29 UTC
Hi Julian,
Thanks for taking care of this.
I am stuck and I do not have more time to spend on this. Do you have something to suggest?
If we do not find a way to handle tz easily, we can provide a way to compare dates without handling them.
Moreover I am not sure we need it in existing tests.
Comment 22 Julian Maurice 2017-10-30 14:42:09 UTC
Created attachment 68848 [details] [review]
Bug 19176: Fix how t::lib::Dates::compare handle timezone
Comment 23 Julian Maurice 2017-10-30 14:45:23 UTC
(In reply to Jonathan Druart from comment #21)
> Hi Julian,
> Thanks for taking care of this.
> I am stuck and I do not have more time to spend on this. Do you have
> something to suggest?
> If we do not find a way to handle tz easily, we can provide a way to compare
> dates without handling them.
> Moreover I am not sure we need it in existing tests.

I'm not sure if we need it, but I think it's better to behave like DateTime::compare.
The last patch should fix the timezone problem.
Comment 24 Jonathan Druart 2017-11-01 15:59:23 UTC
Thanks Julian!
Comment 25 Jonathan Druart 2017-11-01 16:15:16 UTC
Pushed to master for 17.11, thanks to everybody involved!
Comment 26 Marcel de Rooy 2017-11-02 08:23:17 UTC
Just a few (minor) comments from looking at t::lib::Dates

Test::More seems not to be used.
$description is not used either, and if I am not mistaken is never passed too.
POD says that date is truncated to minutes, but the code compares epoch times (which are seconds) and than rather out of the blue ignores a difference of less than 6 seconds (why 6) ? A comment in the code would be helpful too. The POD is no longer true.

If I understood well, Julian asked to remove the floating timezones. It seems to me that you'd better compare dates in floating however. (See similar problem with DST boundaries on earlier pushed report.) And yes, you should clone the dates when changing timezone and comparing.
Comment 27 Jonathan Druart 2017-11-03 16:52:22 UTC
Created attachment 68923 [details] [review]
Bug 19176: (QA follow-up) few cosmetic changes
Comment 28 Jonathan Druart 2017-11-03 16:53:18 UTC
Last patch pushed to master