[Bug 22917] New: Circulation.t fails if tests are ran slowly
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Bug ID: 22917 Summary: Circulation.t fails if tests are ran slowly Change sponsored?: --- Product: Koha Version: unspecified Hardware: All OS: All Status: ASSIGNED Severity: normal Priority: P5 - low Component: Test Suite Assignee: jonathan.druart@bugs.koha-community.org Reporter: jonathan.druart@bugs.koha-community.org QA Contact: testopia@bugs.koha-community.org Target Milestone: --- After bug 21213 we wanted to know why Circulation.t was failing randomly on a given test. Since it is pushed, it failed (at least) twice, with the same error: # Failed test 'AddReturn must have debarred the patron' # at t/db_dependent/Circulation.t line 3112. # got: '' # expected: '1' # AddReturn returned message $VAR1 = { # 'WasReturned' => 1 # }; # Failed test 'Test at line 1918' # at t/db_dependent/Circulation.t line 3116. # got: '0' # expected: '1' # Failed test 'Test at line 1918' # at t/db_dependent/Circulation.t line 3119. # got: undef # expected: '2019-05-30' # Looks like you failed 3 tests of 21. The test at line 3113 expects the flags 'WasReturned' and 'Debarred' to be set, but only WasReturned is. Which means the patron has not been debarred. It is not because the checkout has not been detected as overdue. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Jonathan Druart <jonathan.druart@bugs.koha-community.org> changed: What |Removed |Added ---------------------------------------------------------------------------- Depends on| |21213 Referenced Bugs: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=21213 [Bug 21213] Circulation.t needs diagnostics -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Jonathan Druart <jonathan.druart@bugs.koha-community.org> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|ASSIGNED |Needs Signoff -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 --- Comment #1 from Jonathan Druart <jonathan.druart@bugs.koha-community.org> --- Created attachment 89797 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=89797&action=edit Bug 22917: Recreate the failure -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 --- Comment #2 from Jonathan Druart <jonathan.druart@bugs.koha-community.org> --- Created attachment 89798 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=89798&action=edit Bug 22917: Prevent Circulation.t if tests ran too slowly After bug 21213 we wanted to know why Circulation.t was failing randomly on a given test. Since it is pushed, it failed (at least) twice, with the same error: # Failed test 'AddReturn must have debarred the patron' # at t/db_dependent/Circulation.t line 3112. # got: '' # expected: '1' # AddReturn returned message $VAR1 = { # 'WasReturned' => 1 # }; # Failed test 'Test at line 1918' # at t/db_dependent/Circulation.t line 3116. # got: '0' # expected: '1' # Failed test 'Test at line 1918' # at t/db_dependent/Circulation.t line 3119. # got: undef # expected: '2019-05-30' # Looks like you failed 3 tests of 21. The test at line 3113 expects the flags 'WasReturned' and 'Debarred' to be set, but only WasReturned is. Which means the patron has not been debarred. It is not because the checkout has not been detected as overdue. If you apply only the first patch you will see that the tests are failing with the exact same failures. Indeed, if due_date is not passed to test_debarment_on_checkout, it is set to now (dt_from_string). However, if the call and the test of the parameters inside the subroutine takes more than 1 second, then due_date will be after what we really expect. To reproduce that, we add 1 minute to due_date and we observe the tests failing. The trick here (and we should have in all our tests) is to mock DateTime->now to make sure dt_from_string will always return the same value, it is what we expect from our tests (in 99.9% of the cases at least). -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 --- Comment #3 from Jonathan Druart <jonathan.druart@bugs.koha-community.org> --- Created attachment 89799 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=89799&action=edit Bug 22917: Fix more funky things And that's where a land. We are making another test failing much more often than before. The 'now' mocked will be far before the now() of mysql from the tests executed at the end of Circulation.t Without this patch I get the following error one out of the two runs: # Failed test 'renew log successfully added' # at t/db_dependent/Circulation.t line 3024. # got: '4' # expected: '5' # Looks like you failed 1 test of 13. Using the mocked value will solve this issue. I cannot find any side-effects this change could cause. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Jonathan Druart <jonathan.druart@bugs.koha-community.org> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |martin.renvoize@ptfs-europe | |.com, | |nick@bywatersolutions.com, | |tomascohen@gmail.com --- Comment #4 from Jonathan Druart <jonathan.druart@bugs.koha-community.org> --- Some fun for you guys :) -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 --- Comment #5 from Martin Renvoize <martin.renvoize@ptfs-europe.com> --- Created attachment 89853 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=89853&action=edit Bug 22917: Fix a typo in an output_pref call Due to a type in a call to output_pref (datenonly vs dateonly) we were comparing logactions within a minutes accuracy. Counting the logs for the day would be sufficient for the test ;) -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Martin Renvoize <martin.renvoize@ptfs-europe.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #89799|0 |1 is obsolete| | -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 --- Comment #6 from Martin Renvoize <martin.renvoize@ptfs-europe.com> --- I've replaced the final patch with an alternative that fixes the typo in the test rather than altering the behaviour of C4::Log::logaction. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Martin Renvoize <martin.renvoize@ptfs-europe.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #89797|0 |1 is obsolete| | --- Comment #7 from Martin Renvoize <martin.renvoize@ptfs-europe.com> --- Created attachment 89855 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=89855&action=edit Bug 22917: Recreate the failure Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Martin Renvoize <martin.renvoize@ptfs-europe.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #89798|0 |1 is obsolete| | --- Comment #8 from Martin Renvoize <martin.renvoize@ptfs-europe.com> --- Created attachment 89856 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=89856&action=edit Bug 22917: Prevent Circulation.t if tests ran too slowly After bug 21213 we wanted to know why Circulation.t was failing randomly on a given test. Since it is pushed, it failed (at least) twice, with the same error: # Failed test 'AddReturn must have debarred the patron' # at t/db_dependent/Circulation.t line 3112. # got: '' # expected: '1' # AddReturn returned message $VAR1 = { # 'WasReturned' => 1 # }; # Failed test 'Test at line 1918' # at t/db_dependent/Circulation.t line 3116. # got: '0' # expected: '1' # Failed test 'Test at line 1918' # at t/db_dependent/Circulation.t line 3119. # got: undef # expected: '2019-05-30' # Looks like you failed 3 tests of 21. The test at line 3113 expects the flags 'WasReturned' and 'Debarred' to be set, but only WasReturned is. Which means the patron has not been debarred. It is not because the checkout has not been detected as overdue. If you apply only the first patch you will see that the tests are failing with the exact same failures. Indeed, if due_date is not passed to test_debarment_on_checkout, it is set to now (dt_from_string). However, if the call and the test of the parameters inside the subroutine takes more than 1 second, then due_date will be after what we really expect. To reproduce that, we add 1 minute to due_date and we observe the tests failing. The trick here (and we should have in all our tests) is to mock DateTime->now to make sure dt_from_string will always return the same value, it is what we expect from our tests (in 99.9% of the cases at least). Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Martin Renvoize <martin.renvoize@ptfs-europe.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #89853|0 |1 is obsolete| | --- Comment #9 from Martin Renvoize <martin.renvoize@ptfs-europe.com> --- Created attachment 89857 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=89857&action=edit Bug 22917: Fix a typo in an output_pref call Due to a type in a call to output_pref (datenonly vs dateonly) we were comparing logactions within a minutes accuracy. Counting the logs for the day would be sufficient for the test ;) -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Martin Renvoize <martin.renvoize@ptfs-europe.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Needs Signoff |Signed Off --- Comment #10 from Martin Renvoize <martin.renvoize@ptfs-europe.com> --- Good fixes, added my own version of last patch.. Signing off -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Jonathan Druart <jonathan.druart@bugs.koha-community.org> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #89857|0 |1 is obsolete| | --- Comment #11 from Jonathan Druart <jonathan.druart@bugs.koha-community.org> --- Created attachment 89876 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=89876&action=edit Bug 22917: Fix a typo in an output_pref call Due to a type in a call to output_pref (datenonly vs dateonly) we were comparing logactions within a minutes accuracy. Counting the logs for the day would be sufficient for the test ;) Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 --- Comment #12 from Jonathan Druart <jonathan.druart@bugs.koha-community.org> --- Created attachment 89877 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=89877&action=edit Bug 22917: Fix typo in another test file It looks safe to do it here and now. Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Signed Off |Passed QA Patch complexity|--- |Small patch -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #89855|0 |1 is obsolete| | --- Comment #13 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- Created attachment 90018 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=90018&action=edit Bug 22917: Recreate the failure Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com> Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #89856|0 |1 is obsolete| | --- Comment #14 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- Created attachment 90019 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=90019&action=edit Bug 22917: Prevent Circulation.t if tests ran too slowly After bug 21213 we wanted to know why Circulation.t was failing randomly on a given test. Since it is pushed, it failed (at least) twice, with the same error: # Failed test 'AddReturn must have debarred the patron' # at t/db_dependent/Circulation.t line 3112. # got: '' # expected: '1' # AddReturn returned message $VAR1 = { # 'WasReturned' => 1 # }; # Failed test 'Test at line 1918' # at t/db_dependent/Circulation.t line 3116. # got: '0' # expected: '1' # Failed test 'Test at line 1918' # at t/db_dependent/Circulation.t line 3119. # got: undef # expected: '2019-05-30' # Looks like you failed 3 tests of 21. The test at line 3113 expects the flags 'WasReturned' and 'Debarred' to be set, but only WasReturned is. Which means the patron has not been debarred. It is not because the checkout has not been detected as overdue. If you apply only the first patch you will see that the tests are failing with the exact same failures. Indeed, if due_date is not passed to test_debarment_on_checkout, it is set to now (dt_from_string). However, if the call and the test of the parameters inside the subroutine takes more than 1 second, then due_date will be after what we really expect. To reproduce that, we add 1 minute to due_date and we observe the tests failing. The trick here (and we should have in all our tests) is to mock DateTime->now to make sure dt_from_string will always return the same value, it is what we expect from our tests (in 99.9% of the cases at least). Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com> Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #89876|0 |1 is obsolete| | --- Comment #15 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- Created attachment 90020 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=90020&action=edit Bug 22917: Fix a typo in an output_pref call Due to a type in a call to output_pref (datenonly vs dateonly) we were comparing logactions within a minutes accuracy. Counting the logs for the day would be sufficient for the test ;) Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org> Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #89877|0 |1 is obsolete| | --- Comment #16 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- Created attachment 90021 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=90021&action=edit Bug 22917: Fix typo in another test file It looks safe to do it here and now. Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org> Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |m.de.rooy@rijksmuseum.nl QA Contact|testopia@bugs.koha-communit |m.de.rooy@rijksmuseum.nl |y.org | -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Nick Clemens <nick@bywatersolutions.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Passed QA |Pushed to Master --- Comment #17 from Nick Clemens <nick@bywatersolutions.com> --- Awesome work all! Pushed to master for 19.05 -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Martin Renvoize <martin.renvoize@ptfs-europe.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Version(s)| |19.05.00, 18.11.06 released in| | Status|Pushed to Master |Pushed to Stable --- Comment #18 from Martin Renvoize <martin.renvoize@ptfs-europe.com> --- Pushed to 18.11.x for 18.11.06 -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Liz Rea <wizzyrea@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |wizzyrea@gmail.com Status|Pushed to Stable |RESOLVED Resolution|--- |FIXED --- Comment #19 from Liz Rea <wizzyrea@gmail.com> --- Declining these for 18.05 as some don't seem to apply. Please submit a new patchset if you feel it's necessary! Liz -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Jonathan Druart <jonathan.druart@bugs.koha-community.org> changed: What |Removed |Added ---------------------------------------------------------------------------- Blocks| |23234 Referenced Bugs: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=23234 [Bug 23234] Circulation.t failing when comparing dates that seem identicals -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Jonathan Druart <jonathan.druart@bugs.koha-community.org> changed: What |Removed |Added ---------------------------------------------------------------------------- Blocks| |24881 Referenced Bugs: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=24881 [Bug 24881] Circulation.t still fails if tests are ran slowly -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=22917 Jonathan Druart <jonathan.druart@bugs.koha-community.org> changed: What |Removed |Added ---------------------------------------------------------------------------- Blocks| |25551 Referenced Bugs: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=25551 [Bug 25551] [OMNIBUS] Some tests are failing randomly -- You are receiving this mail because: You are watching all bug changes.
participants (1)
-
bugzilla-daemon＠bugs.koha-community.org