Bug 20191

Summary: OAI/Server.t still fails on slow servers
Product: Koha Reporter: Jonathan Druart <jonathan.druart>
Component: Test SuiteAssignee: Mark Tompsett <mtompset>
Status: CLOSED FIXED QA Contact: Tomás Cohen Arazi <tomascohen>
Severity: normal    
Priority: P5 - low CC: martin.renvoize, mtompset, tomascohen
Version: masterKeywords: dependency
Hardware: All   
OS: All   
Change sponsored?: --- Patch complexity: Trivial patch
Documentation contact: Documentation submission:
Text to go in the release notes:
Version(s) released in:
Bug Depends on: 18794    
Bug Blocks: 25551    
Attachments: Bug 20191: Make OAI/Server.t tests use timestamps from the DB
Bug 20191: Use find with unique key combination
Bug 20191: Try and fix random failure from Server.t - v3...
Bug 20191: Use Test::MockTime to hold time still
Bug 20191: Use Test::MockTime to hold time still
Bug 20191: (QA follow-up) Require Jessie's Test::MockTime

Description Jonathan Druart 2018-02-13 19:24:22 UTC

    
Comment 1 Jonathan Druart 2018-02-13 19:25:08 UTC
https://jenkins.koha-community.org/job/Koha_Master_D8/lastCompletedBuild/console

#   Failed test 'ListIdentifiers with resumptionToken 2'
#   at t/db_dependent/OAI/Server.t line 153.
#     Structures begin differing at:
#          $got->{ListIdentifiers}{header}[2]{datestamp} = '2018-02-13T17:46:23Z'
#     $expected->{ListIdentifiers}{header}[2]{datestamp} = '2018-02-13T17:46:22Z'
# PARAM:---
# resumptionToken: marcxml/6/1970-01-01T00:00:00Z/2018-02-13T23:59:59Z//0/0
# verb: ListIdentifiers
# EXPECTED:---
# ListIdentifiers:
#   header:
#     - datestamp: 2018-02-13T17:46:22Z
#       identifier: TEST:686
#     - datestamp: 2018-02-13T17:46:22Z
#       identifier: TEST:687
#     - datestamp: 2018-02-13T17:46:22Z
#       identifier: TEST:688
#   resumptionToken:
#     content: marcxml/9/1970-01-01T00:00:00Z/2018-02-13T23:59:59Z//0/0
#     cursor: 9
# request: http://localhost
# xmlns: http://www.openarchives.org/OAI/2.0/
# xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
# xsi:schemaLocation: http://www.openarchives.org/OAI/2.0/ http://www.openarchives.org/OAI/2.0/OAI-PMH.xsd
# RESPONSE:---
# ListIdentifiers:
#   header:
#     - datestamp: 2018-02-13T17:46:22Z
#       identifier: TEST:686
#     - datestamp: 2018-02-13T17:46:22Z
#       identifier: TEST:687
#     - datestamp: 2018-02-13T17:46:23Z
#       identifier: TEST:688
#   resumptionToken:
#     content: marcxml/9/1970-01-01T00:00:00Z/2018-02-13T23:59:59Z//0/0
#     cursor: 9
# request: http://localhost
# xmlns: http://www.openarchives.org/OAI/2.0/
# xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
# xsi:schemaLocation: http://www.openarchives.org/OAI/2.0/ http://www.openarchives.org/OAI/2.0/OAI-PMH.xsd

#   Failed test 'ListRecords marcxml with resumptionToken 2'
#   at t/db_dependent/OAI/Server.t line 153.
#     Structures begin differing at:
#          $got->{ListRecords}{record}[2]{header}{datestamp} = '2018-02-13T17:46:23Z'
#     $expected->{ListRecords}{record}[2]{header}{datestamp} = '2018-02-13T17:46:22Z'
# PARAM:---
# resumptionToken: marcxml/6/1970-01-01T00:00:00Z/2018-02-13T23:59:59Z//0/0
# verb: ListRecords
# EXPECTED:---
# ListRecords:
#   record:
#     - header:
#         datestamp: 2018-02-13T17:46:22Z
#         identifier: TEST:686
#       metadata:
#         record:
#           controlfield:
#             content: '                                   lng'
#             tag: 008
#           datafield:
#             - ind1: ' '
#               ind2: ' '
#               subfield:
#                 code: a
#                 content: Title 6
#               tag: 245
#             - ind1: ' '
#               ind2: ' '
#               subfield:
#                 - code: c
#                   content: 686
#                 - code: d
#                   content: 586
#               tag: 999
#           leader: 00126    a2200061   4500
#           xmlns: http://www.loc.gov/MARC21/slim
#           xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
#           xsi:schemaLocation: http://www.loc.gov/MARC21/slim http://www.loc.gov/standards/marcxml/schema/MARC21slim.xsd
#     - header:
#         datestamp: 2018-02-13T17:46:22Z
#         identifier: TEST:687
#       metadata:
#         record:
#           controlfield:
#             content: '                                   lng'
#             tag: 008
#           datafield:
#             - ind1: ' '
#               ind2: ' '
#               subfield:
#                 code: a
#                 content: Title 7
#               tag: 245
#             - ind1: ' '
#               ind2: ' '
#               subfield:
#                 - code: c
#                   content: 687
#                 - code: d
#                   content: 587
#               tag: 999
#           leader: 00126    a2200061   4500
#           xmlns: http://www.loc.gov/MARC21/slim
#           xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
#           xsi:schemaLocation: http://www.loc.gov/MARC21/slim http://www.loc.gov/standards/marcxml/schema/MARC21slim.xsd
#     - header:
#         datestamp: 2018-02-13T17:46:22Z
#         identifier: TEST:688
#       metadata:
#         record:
#           controlfield:
#             content: '                                   lng'
#             tag: 008
#           datafield:
#             - ind1: ' '
#               ind2: ' '
#               subfield:
#                 code: a
#                 content: Title 8
#               tag: 245
#             - ind1: ' '
#               ind2: ' '
#               subfield:
#                 - code: c
#                   content: 688
#                 - code: d
#                   content: 588
#               tag: 999
#           leader: 00126    a2200061   4500
#           xmlns: http://www.loc.gov/MARC21/slim
#           xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
#           xsi:schemaLocation: http://www.loc.gov/MARC21/slim http://www.loc.gov/standards/marcxml/schema/MARC21slim.xsd
#   resumptionToken:
#     content: marcxml/9/1970-01-01T00:00:00Z/2018-02-13T23:59:59Z//0/0
#     cursor: 9
# request: http://localhost
# xmlns: http://www.openarchives.org/OAI/2.0/
# xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
# xsi:schemaLocation: http://www.openarchives.org/OAI/2.0/ http://www.openarchives.org/OAI/2.0/OAI-PMH.xsd
# RESPONSE:---
# ListRecords:
#   record:
#     - header:
#         datestamp: 2018-02-13T17:46:22Z
#         identifier: TEST:686
#       metadata:
#         record:
#           controlfield:
#             content: '                                   lng'
#             tag: 008
#           datafield:
#             - ind1: ' '
#               ind2: ' '
#               subfield:
#                 code: a
#                 content: Title 6
#               tag: 245
#             - ind1: ' '
#               ind2: ' '
#               subfield:
#                 - code: c
#                   content: 686
#                 - code: d
#                   content: 586
#               tag: 999
#           leader: 00126    a2200061   4500
#           xmlns: http://www.loc.gov/MARC21/slim
#           xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
#           xsi:schemaLocation: http://www.loc.gov/MARC21/slim http://www.loc.gov/standards/marcxml/schema/MARC21slim.xsd
#     - header:
#         datestamp: 2018-02-13T17:46:22Z
#         identifier: TEST:687
#       metadata:
#         record:
#           controlfield:
#             content: '                                   lng'
#             tag: 008
#           datafield:
#             - ind1: ' '
#               ind2: ' '
#               subfield:
#                 code: a
#                 content: Title 7
#               tag: 245
#             - ind1: ' '
#               ind2: ' '
#               subfield:
#                 - code: c
#                   content: 687
#                 - code: d
#                   content: 587
#               tag: 999
#           leader: 00126    a2200061   4500
#           xmlns: http://www.loc.gov/MARC21/slim
#           xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
#           xsi:schemaLocation: http://www.loc.gov/MARC21/slim http://www.loc.gov/standards/marcxml/schema/MARC21slim.xsd
#     - header:
#         datestamp: 2018-02-13T17:46:23Z
#         identifier: TEST:688
#       metadata:
#         record:
#           controlfield:
#             content: '                                   lng'
#             tag: 008
#           datafield:
#             - ind1: ' '
#               ind2: ' '
#               subfield:
#                 code: a
#                 content: Title 8
#               tag: 245
#             - ind1: ' '
#               ind2: ' '
#               subfield:
#                 - code: c
#                   content: 688
#                 - code: d
#                   content: 588
#               tag: 999
#           leader: 00126    a2200061   4500
#           xmlns: http://www.loc.gov/MARC21/slim
#           xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
#           xsi:schemaLocation: http://www.loc.gov/MARC21/slim http://www.loc.gov/standards/marcxml/schema/MARC21slim.xsd
#   resumptionToken:
#     content: marcxml/9/1970-01-01T00:00:00Z/2018-02-13T23:59:59Z//0/0
#     cursor: 9
# request: http://localhost
# xmlns: http://www.openarchives.org/OAI/2.0/
# xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
# xsi:schemaLocation: http://www.openarchives.org/OAI/2.0/ http://www.openarchives.org/OAI/2.0/OAI-PMH.xsd

#   Failed test 'ListRecords oai_dc with resumptionToken 2'
#   at t/db_dependent/OAI/Server.t line 153.
#     Structures begin differing at:
#          $got->{ListRecords}{record}[2]{header}{datestamp} = '2018-02-13T17:46:23Z'
#     $expected->{ListRecords}{record}[2]{header}{datestamp} = '2018-02-13T17:46:22Z'
# PARAM:---
# resumptionToken: oai_dc/6/1970-01-01T00:00:00Z/2018-02-13T23:59:59Z//0/0
# verb: ListRecords
# EXPECTED:---
# ListRecords:
#   record:
#     - header:
#         datestamp: 2018-02-13T17:46:22Z
#         identifier: TEST:686
#       metadata:
#         oai_dc:dc:
#           dc:language: lng
#           dc:title: Title 6
#           dc:type: {}
#           xmlns:dc: http://purl.org/dc/elements/1.1/
#           xmlns:oai_dc: http://www.openarchives.org/OAI/2.0/oai_dc/
#           xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
#           xsi:schemaLocation: http://www.openarchives.org/OAI/2.0/oai_dc/ http://www.openarchives.org/OAI/2.0/oai_dc.xsd
#     - header:
#         datestamp: 2018-02-13T17:46:22Z
#         identifier: TEST:687
#       metadata:
#         oai_dc:dc:
#           dc:language: lng
#           dc:title: Title 7
#           dc:type: {}
#           xmlns:dc: http://purl.org/dc/elements/1.1/
#           xmlns:oai_dc: http://www.openarchives.org/OAI/2.0/oai_dc/
#           xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
#           xsi:schemaLocation: http://www.openarchives.org/OAI/2.0/oai_dc/ http://www.openarchives.org/OAI/2.0/oai_dc.xsd
#     - header:
#         datestamp: 2018-02-13T17:46:22Z
#         identifier: TEST:688
#       metadata:
#         oai_dc:dc:
#           dc:language: lng
#           dc:title: Title 8
#           dc:type: {}
#           xmlns:dc: http://purl.org/dc/elements/1.1/
#           xmlns:oai_dc: http://www.openarchives.org/OAI/2.0/oai_dc/
#           xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
#           xsi:schemaLocation: http://www.openarchives.org/OAI/2.0/oai_dc/ http://www.openarchives.org/OAI/2.0/oai_dc.xsd
#   resumptionToken:
#     content: oai_dc/9/1970-01-01T00:00:00Z/2018-02-13T23:59:59Z//0/0
#     cursor: 9
# request: http://localhost
# xmlns: http://www.openarchives.org/OAI/2.0/
# xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
# xsi:schemaLocation: http://www.openarchives.org/OAI/2.0/ http://www.openarchives.org/OAI/2.0/OAI-PMH.xsd
# RESPONSE:---
# ListRecords:
#   record:
#     - header:
#         datestamp: 2018-02-13T17:46:22Z
#         identifier: TEST:686
#       metadata:
#         oai_dc:dc:
#           dc:language: lng
#           dc:title: Title 6
#           dc:type: {}
#           xmlns:dc: http://purl.org/dc/elements/1.1/
#           xmlns:oai_dc: http://www.openarchives.org/OAI/2.0/oai_dc/
#           xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
#           xsi:schemaLocation: http://www.openarchives.org/OAI/2.0/oai_dc/ http://www.openarchives.org/OAI/2.0/oai_dc.xsd
#     - header:
#         datestamp: 2018-02-13T17:46:22Z
#         identifier: TEST:687
#       metadata:
#         oai_dc:dc:
#           dc:language: lng
#           dc:title: Title 7
#           dc:type: {}
#           xmlns:dc: http://purl.org/dc/elements/1.1/
#           xmlns:oai_dc: http://www.openarchives.org/OAI/2.0/oai_dc/
#           xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
#           xsi:schemaLocation: http://www.openarchives.org/OAI/2.0/oai_dc/ http://www.openarchives.org/OAI/2.0/oai_dc.xsd
#     - header:
#         datestamp: 2018-02-13T17:46:23Z
#         identifier: TEST:688
#       metadata:
#         oai_dc:dc:
#           dc:language: lng
#           dc:title: Title 8
#           dc:type: {}
#           xmlns:dc: http://purl.org/dc/elements/1.1/
#           xmlns:oai_dc: http://www.openarchives.org/OAI/2.0/oai_dc/
#           xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
#           xsi:schemaLocation: http://www.openarchives.org/OAI/2.0/oai_dc/ http://www.openarchives.org/OAI/2.0/oai_dc.xsd
#   resumptionToken:
#     content: oai_dc/9/1970-01-01T00:00:00Z/2018-02-13T23:59:59Z//0/0
#     cursor: 9
# request: http://localhost
# xmlns: http://www.openarchives.org/OAI/2.0/
# xmlns:xsi: http://www.w3.org/2001/XMLSchema-instance
# xsi:schemaLocation: http://www.openarchives.org/OAI/2.0/ http://www.openarchives.org/OAI/2.0/OAI-PMH.xsd
# Looks like you failed 3 tests of 29.
[17:46:24] t/db_dependent/OAI/Server.t ....................................
Comment 2 Jonathan Druart 2018-02-13 19:25:27 UTC
I did not manage to mock DateTime->now
Comment 4 Tomás Cohen Arazi 2018-02-15 17:15:04 UTC
Created attachment 71673 [details] [review]
Bug 20191: Make OAI/Server.t tests use timestamps from the DB

Signed-off-by: Tomas Cohen Arazi <tomascohen@theke.io>
Comment 5 Jonathan Druart 2018-02-15 19:29:15 UTC
+        Koha::Biblio::Metadatas->search({ biblionumber => $biblionumber })

Should use ->find instead, with (biblionumber, 'marcxml', 'MARC21'), do not you think?
Comment 6 Jonathan Druart 2018-02-16 15:14:37 UTC
Created attachment 71816 [details] [review]
Bug 20191: Use find with unique key combination

To prevent unexpected issues later.
Comment 7 Jonathan Druart 2018-02-16 16:02:14 UTC
Pushed to master, thanks Tomas!
Comment 8 Jonathan Druart 2018-02-18 20:48:13 UTC
still fails: https://jenkins.koha-community.org/job/Koha_Master_D8/377/console
Comment 9 Jonathan Druart 2018-02-20 14:20:58 UTC
and again: https://jenkins.koha-community.org/job/Koha_Master_D8/381/console
Comment 10 Jonathan Druart 2018-02-20 17:11:51 UTC
I tried with Time::Fake but failed.
Comment 11 Jonathan Druart 2018-02-20 18:08:50 UTC
Created attachment 72009 [details] [review]
Bug 20191: Try and fix random failure from Server.t - v3...
Comment 12 Jonathan Druart 2018-02-20 18:09:24 UTC
This is my try with Time::Fake, what's wrong?
Comment 13 Jonathan Druart 2018-02-20 18:10:00 UTC
I use `stress -c 4` to recreate the failures.
Comment 14 Jonathan Druart 2018-04-04 19:50:54 UTC
These tests are constantly failing, I am going to remove them once and for all if these random failures are not fixed.
Comment 15 Mark Tompsett 2018-04-05 01:28:59 UTC
(In reply to Jonathan Druart from comment #14)
> These tests are constantly failing, I am going to remove them once and for
> all if these random failures are not fixed.

The HTTP::OAI::Header grabs gmtime() which could change between the creation time and the call time... How about this impending counter patch?
Comment 16 Mark Tompsett 2018-04-05 01:37:46 UTC Comment hidden (obsolete)
Comment 17 Tomás Cohen Arazi 2018-04-05 13:07:32 UTC
Created attachment 73684 [details] [review]
Bug 20191: Use Test::MockTime to hold time still

The problem is the calls to HTTP::OAI::Header, etc.
may reference gmtime which is continually changing by
the second. By forcing time to lock for all the tests,
except the last one, we can be assured things should
not fail.

TEST PLAN
---------
install libtest-mocktime-perl
apply the patch
restart_all
in kshell, prove t/db_dependent/OAI/Server.t
run koha qa test tools

Signed-off-by: Tomas Cohen Arazi <tomascohen@theke.io>
Comment 18 Tomás Cohen Arazi 2018-04-05 13:07:38 UTC
Created attachment 73685 [details] [review]
Bug 20191: (QA follow-up) Require Jessie's Test::MockTime

Signed-off-by: Tomas Cohen Arazi <tomascohen@theke.io>
Comment 19 Tomás Cohen Arazi 2018-04-05 13:12:00 UTC
I tested with Mark's patch using 'stress -c 4' on a 2 cores kohadevbox (cpu load above 3). I managed to reproduce the issue without the patch, and can confirm the patch deals with the problem correctly. The solution is the right one too, one we talked about but didn't find the spot in which environment was leaking inside the tests. Good catch Mark!
Comment 20 Jonathan Druart 2018-04-05 14:34:15 UTC
Excellent Mark!
It works great thanks a lot!


Note for later: Maybe we should replace our mock of DateTime->now with this new module.

Pushed to master for 18.05