Bug 25514

Summary: REST/Plugin/Objects.t is failing randomly
Product: Koha Reporter: Jonathan Druart <jonathan.druart>
Component: Test SuiteAssignee: Jonathan Druart <jonathan.druart>
Status: RESOLVED FIXED QA Contact: Testopia <testopia>
Severity: normal    
Priority: P5 - low CC: andrew, tomascohen, victor
Version: unspecified   
Hardware: All   
OS: All   
See Also: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=24229
Change sponsored?: --- Patch complexity: ---
Text to go in the release notes:
Version(s) released in:
20.11.00, 20.05.07
Bug Depends on: 24502    
Bug Blocks: 25551    
Attachments: Bug 25514: Try to fix random failure from REST/Plugin/Objects.t
Bug 25514: Try to fix random failure from REST/Plugin/Objects.t

Description Jonathan Druart 2020-05-15 13:28:43 UTC
Master_U18 (#785)

13:53:07 koha_1       |     # Premature connection close
13:53:07 koha_1       | 
13:53:07 koha_1       |     #   Failed test 'GET /biblios'
13:53:07 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 270.
13:53:07 koha_1       | 
13:53:07 koha_1       |     #   Failed test 'there should be 1 biblio with suggestions of patron 1'
13:53:07 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 270.
13:53:07 koha_1       |     #          got: undef
13:53:07 koha_1       |     #     expected: '1'
13:53:07 koha_1       |     # Looks like you failed 2 tests of 4.
13:53:07 koha_1       | 
13:53:07 koha_1       | #   Failed test 'object.search helper with query parameter'
13:53:07 koha_1       | #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 277.
Comment 1 Jonathan Druart 2020-06-25 08:16:21 UTC
Master_D9_MDB_Latest (#333)

18:28:12 koha_1       |     # Premature connection close
18:28:12 koha_1       | 
18:28:12 koha_1       |     #   Failed test 'GET /biblios'
18:28:12 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 310.
18:28:12 koha_1       | 
18:28:12 koha_1       |     #   Failed test 'there should be 1 biblio with suggestions of patron 1'
18:28:12 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 310.
18:28:12 koha_1       |     #          got: undef
18:28:12 koha_1       |     #     expected: '1'
18:28:12 koha_1       |     # Looks like you failed 2 tests of 4.
18:28:12 koha_1       | 
18:28:12 koha_1       | #   Failed test 'object.search helper with query parameter'
18:28:12 koha_1       | #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 317.
18:28:30 koha_1       |     # Premature connection close
18:28:30 koha_1       | 
18:28:30 koha_1       |     #   Failed test 'GET /biblios?q={"suggestions.suggester.patron_id": "79"}'
18:28:30 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 333.
18:28:30 koha_1       | 
18:28:30 koha_1       |     #   Failed test 'there should be 1 biblio with suggestions of patron 1'
18:28:30 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 333.
18:28:30 koha_1       |     #          got: undef
18:28:30 koha_1       |     #     expected: '1'
18:28:30 koha_1       |     # Looks like you failed 2 tests of 4.
18:28:30 koha_1       | 
18:28:30 koha_1       | #   Failed test 'object.search helper with q parameter'
18:28:30 koha_1       | #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 340.
18:28:49 koha_1       |     # Premature connection close
18:28:49 koha_1       | 
18:28:49 koha_1       |     #   Failed test 'GET /biblios'
18:28:49 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 356.
18:28:49 koha_1       | 
18:28:49 koha_1       |     #   Failed test 'there should be 1 biblio with suggestions of patron 1'
18:28:49 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 356.
18:28:49 koha_1       |     #          got: undef
18:28:49 koha_1       |     #     expected: '1'
18:28:49 koha_1       |     # Looks like you failed 2 tests of 4.
18:28:49 koha_1       | 
18:28:49 koha_1       | #   Failed test 'object.search helper with x-koha-query header'
18:28:49 koha_1       | #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 363.
18:29:07 koha_1       |     # Premature connection close
18:29:07 koha_1       | 
18:29:07 koha_1       |     #   Failed test 'GET /biblios?q={"suggestions.suggester.firstname": "patron1"}'
18:29:07 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 379.
18:29:07 koha_1       | 
18:29:07 koha_1       |     #   Failed test 'there should be 1 biblio with suggestions of patron 1'
18:29:07 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 379.
18:29:07 koha_1       |     #          got: undef
18:29:07 koha_1       |     #     expected: '1'
18:29:08 koha_1       |     # Looks like you failed 2 tests of 6.
18:29:08 koha_1       | 
18:29:08 koha_1       | #   Failed test 'object.search helper with all query methods'
18:29:08 koha_1       | #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 389.
Comment 2 Jonathan Druart 2020-07-24 07:52:58 UTC
Master_U18 #844
Comment 3 Jonathan Druart 2020-11-10 10:51:57 UTC
This is still valid

Master_D9_My8 #459


14:30:42 koha_1       |     # Premature connection close
14:30:42 koha_1       | 
14:30:42 koha_1       |     #   Failed test 'GET /biblios'
14:30:42 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 322.
14:30:42 koha_1       | 
14:30:42 koha_1       |     #   Failed test 'there should be 1 biblio with suggestions of patron 1'
14:30:42 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 322.
14:30:42 koha_1       |     #          got: undef
14:30:42 koha_1       |     #     expected: '1'
14:30:42 koha_1       |     # Looks like you failed 2 tests of 4.
14:30:42 koha_1       | 
14:30:42 koha_1       | #   Failed test 'object.search helper with query parameter'
14:30:42 koha_1       | #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 329.
14:30:57 koha_1       |     # Premature connection close
14:30:57 koha_1       | 
14:30:57 koha_1       |     #   Failed test 'GET /biblios?q={"suggestions.suggester.patron_id": "76"}'
14:30:57 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 345.
14:30:57 koha_1       | 
14:30:57 koha_1       |     #   Failed test 'there should be 1 biblio with suggestions of patron 1'
14:30:57 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 345.
14:30:57 koha_1       |     #          got: undef
14:30:57 koha_1       |     #     expected: '1'
14:30:58 koha_1       |     # Looks like you failed 2 tests of 4.
14:30:58 koha_1       | 
14:30:58 koha_1       | #   Failed test 'object.search helper with q parameter'
14:30:58 koha_1       | #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 352.
14:31:27 koha_1       |     # Premature connection close
14:31:27 koha_1       | 
14:31:27 koha_1       |     #   Failed test 'GET /biblios?q={"suggestions.suggester.firstname": "patron1"}'
14:31:27 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 391.
14:31:27 koha_1       | 
14:31:27 koha_1       |     #   Failed test 'there should be 1 biblio with suggestions of patron 1'
14:31:27 koha_1       |     #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 391.
14:31:27 koha_1       |     #          got: undef
14:31:27 koha_1       |     #     expected: '1'
14:31:28 koha_1       |     # Looks like you failed 2 tests of 6.
14:31:28 koha_1       | 
14:31:28 koha_1       | #   Failed test 'object.search helper with all query methods'
14:31:28 koha_1       | #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 401.
14:31:38 koha_1       | # Looks like you failed 3 tests of 10.
14:31:38 koha_1       | [13:31:38] t/db_dependent/Koha/REST/Plugin/Objects.t ............................... 
14:31:38 koha_1       | Dubious, test returned 3 (wstat 768, 0x300)
14:31:38 koha_1       | Failed 3/10 subtests
Comment 4 Jonathan Druart 2020-11-10 11:06:27 UTC
Created attachment 113342 [details] [review]
Bug 25514: Try to fix random failure from REST/Plugin/Objects.t

It's causing a "Premature connection close" error

https://docs.mojolicious.org/Mojolicious/Guides/FAQ#What-does-Premature-connection-close-mean

This is just a guess but maybe it would help to have the Test::Mojo
object initiated just before the get?
Comment 5 Tomás Cohen Arazi 2020-11-10 11:23:29 UTC
(In reply to Jonathan Druart from comment #4)
> Created attachment 113342 [details] [review] [review]
> Bug 25514: Try to fix random failure from REST/Plugin/Objects.t
> 
> It's causing a "Premature connection close" error
> 
> https://docs.mojolicious.org/Mojolicious/Guides/FAQ#What-does-Premature-
> connection-close-mean
> 
> This is just a guess but maybe it would help to have the Test::Mojo
> object initiated just before the get?

It is not a 'timeout' per-se, usually. But some exception making the controller terminates before sending an answer to the caller.
Comment 6 Jonathan Druart 2020-11-10 15:15:05 UTC
Again on Koha_Master_D9_My8 #460
Comment 7 Victor Grousset/tuxayo 2020-11-11 18:13:02 UTC
It seem it's possible to reproduce locally by running in parallel `stress --hdd 1` it should fail after 5 min at most. Likely the first errors come first.

t/db_dependent/Koha/REST/Plugin/Objects.t .. 3/10     # Premature connection close

    #   Failed test 'GET /orders?order_id=1'
    #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 269.

    #   Failed test 'exact match for JSON Pointer "/0"'
    #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 269.
    #     Structures begin differing at:
    #          $got = undef
    #     $expected = HASH(0x558d657c4810)
    # Looks like you failed 2 tests of 2.
t/db_dependent/Koha/REST/Plugin/Objects.t .. 4/10 
#   Failed test 'objects.search helper, embed'
#   at t/db_dependent/Koha/REST/Plugin/Objects.t line 273.
t/db_dependent/Koha/REST/Plugin/Objects.t .. 5/10     # Premature connection close

    #   Failed test 'GET /biblios'
    #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 322.

    #   Failed test 'there should be 1 biblio with suggestions of patron 1'
    #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 322.
    #          got: undef
    #     expected: '1'
    # Looks like you failed 2 tests of 4.
t/db_dependent/Koha/REST/Plugin/Objects.t .. 6/10 
#   Failed test 'object.search helper with query parameter'
#   at t/db_dependent/Koha/REST/Plugin/Objects.t line 329.
t/db_dependent/Koha/REST/Plugin/Objects.t .. 7/10     # Premature connection close

    #   Failed test 'GET /biblios'
    #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 368.

    #   Failed test 'there should be 1 biblio with suggestions of patron 1'
    #   at t/db_dependent/Koha/REST/Plugin/Objects.t line 368.
    #          got: undef
    #     expected: '1'
    # Looks like you failed 2 tests of 4.
t/db_dependent/Koha/REST/Plugin/Objects.t .. 8/10 

#### ETC more similar error ####
Comment 8 Jonathan Druart 2020-11-11 20:27:41 UTC
Same with the patch, Victor?
Comment 9 Victor Grousset/tuxayo 2020-11-12 00:26:23 UTC
Created attachment 113539 [details] [review]
Bug 25514: Try to fix random failure from REST/Plugin/Objects.t

It's causing a "Premature connection close" error

https://docs.mojolicious.org/Mojolicious/Guides/FAQ#What-does-Premature-connection-close-mean

This is just a guess but maybe it would help to have the Test::Mojo
object initiated just before the get?

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>
Comment 10 Victor Grousset/tuxayo 2020-11-12 00:33:41 UTC
I though it wasn't going to work but actually yes! :D

Some inconsistencies like suddenly regardless of with or without the patch it wouldn't fail.
One or two instances of failure with the patch.
But nonetheless after numerous attempts: without the patch, it fails after a short amount of time. While with the patch, it doesn't fail even after waiting at least two or three times the previous amount of time.
Comment 12 Jonathan Druart 2020-11-20 09:37:38 UTC
Pushed to master for 20.11, thanks to everybody involved!
Comment 13 Andrew Fuerste-Henry 2020-12-10 21:49:29 UTC
Backported to 20.05.x for 20.05.07
Comment 14 Victor Grousset/tuxayo 2020-12-11 16:28:31 UTC
Missing dependencies for 19.11.x, can't backport.