Bug 24813

Summary: api/v1/holds.t is failing randomly
Product: Koha Reporter: Jonathan Druart <jonathan.druart>
Component: Test SuiteAssignee: Jonathan Druart <jonathan.druart>
Status: CLOSED FIXED QA Contact: Marcel de Rooy <m.de.rooy>
Severity: normal    
Priority: P5 - low CC: 1joynelson, david, hayleypelham, lucas, m.de.rooy, martin.renvoize, tomascohen
Version: unspecified   
Hardware: All   
OS: All   
See Also: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=28670
Change sponsored?: --- Patch complexity: Trivial patch
Documentation contact: Documentation submission:
Text to go in the release notes:
Version(s) released in:
20.05.00, 19.11.05, 19.05.10, 18.11.16
Bug Depends on: 22206    
Bug Blocks: 25551    
Attachments: Bug 24813: Prevent api/v1/holds.t to fail randomly
Bug 24813: Prevent api/v1/holds.t to fail randomly
Bug 24813: Prevent api/v1/holds.t to fail randomly
Bug 24813: Prevent api/v1/holds.t to fail randomly

Description Jonathan Druart 2020-03-05 15:26:35 UTC
t/db_dependent/api/v1/holds.t .. 3/8
    #   Failed test 'Hold suspension created'
    #   at t/db_dependent/api/v1/holds.t line 400.
    #          got: '400'
    #     expected: '201'

    #   Failed test 'Hold is suspended'
    #   at t/db_dependent/api/v1/holds.t line 405.

    #   Failed test 'Hold is suspended'
    #   at t/db_dependent/api/v1/holds.t line 418.

    #   Failed test 'Hold suspension has correct end date'
    #   at t/db_dependent/api/v1/holds.t line 419.
    #          got: undef
    #     expected: '2020-03-05'

    #   Failed test 'Hold suspension created'
    #   at t/db_dependent/api/v1/holds.t line 435.
    #          got: '400'
    #     expected: '201'

    #   Failed test 'exact match for JSON Pointer "/end_date"'
    #   at t/db_dependent/api/v1/holds.t line 435.
    #          got: undef
    #     expected: '2020-03-10'

    #   Failed test 'The Location header is set'
    #   at t/db_dependent/api/v1/holds.t line 435.
    #          got: undef
    #     expected: '/api/v1/holds/287/suspension'
    # Looks like you failed 7 tests of 24.
t/db_dependent/api/v1/holds.t .. 7/8 
#   Failed test 'suspend and resume tests'
#   at t/db_dependent/api/v1/holds.t line 464.
t/db_dependent/api/v1/holds.t .. 8/8 # Looks like you failed 1 test of 8.
t/db_dependent/api/v1/holds.t .. Dubious, test returned 1 (wstat 256, 0x100)
Failed 1/8 subtests
Comment 1 Jonathan Druart 2020-03-05 15:33:42 UTC
Created attachment 100200 [details] [review]
Bug 24813: Prevent api/v1/holds.t to fail randomly

Hold cannot be suspended if found=W:
Koha::Hold->suspend_hold
 90     if ( $self->is_found ) {    # We can't suspend found holds

So when TestBuilder generate a hold with found=W the test fail.

A question however:
Why did not we have the correct exception displayed somewhere? That
would be much more helpful to find the problem!
Comment 2 Jonathan Druart 2020-03-05 15:35:12 UTC
Created attachment 100201 [details] [review]
Bug 24813: Prevent api/v1/holds.t to fail randomly

Hold cannot be suspended if found=W:
Koha::Hold->suspend_hold
 90     if ( $self->is_found ) {    # We can't suspend found holds

So when TestBuilder generate a hold with found=W the test fail.

A question however:
Why did not we have the correct exception displayed somewhere? That
would be much more helpful to find the problem!
Comment 3 David Nind 2020-03-05 18:33:22 UTC
Created attachment 100204 [details] [review]
Bug 24813: Prevent api/v1/holds.t to fail randomly

Hold cannot be suspended if found=W:
Koha::Hold->suspend_hold
 90     if ( $self->is_found ) {    # We can't suspend found holds

So when TestBuilder generate a hold with found=W the test fail.

A question however:
Why did not we have the correct exception displayed somewhere? That
would be much more helpful to find the problem!

Signed-off-by: David Nind <david@davidnind.com>
Comment 4 David Nind 2020-03-05 18:34:16 UTC
For me, the tests passed both before and after applying the patch.
Comment 5 Marcel de Rooy 2020-03-06 07:18:15 UTC
Created attachment 100210 [details] [review]
Bug 24813: Prevent api/v1/holds.t to fail randomly

Hold cannot be suspended if found=W:
Koha::Hold->suspend_hold
 90     if ( $self->is_found ) {    # We can't suspend found holds

So when TestBuilder generate a hold with found=W the test fail.

A question however:
Why did not we have the correct exception displayed somewhere? That
would be much more helpful to find the problem!

Signed-off-by: David Nind <david@davidnind.com>

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 6 Martin Renvoize 2020-03-06 09:09:43 UTC
Hoping to get an answer from Tomas on this one regarding Jonathan's question.. we would like to know if the API should really be returning the actual exception error in the 500 response.
Comment 7 Martin Renvoize 2020-03-06 10:05:18 UTC
Nice work everyone!

Pushed to master for 20.05
Comment 8 Tomás Cohen Arazi 2020-03-06 12:03:44 UTC
(In reply to Martin Renvoize from comment #6)
> Hoping to get an answer from Tomas on this one regarding Jonathan's
> question.. we would like to know if the API should really be returning the
> actual exception error in the 500 response.

The usual pattern is:

        unless ( blessed $_ && $_->can('rethrow') ) {
            return $c->render(
                status  => 500,
                openapi => {
                    error =>
                      "Something went wrong, check Koha logs for details."
                }
            );
        }
        return $c->render(
            status  => 500,
            openapi => { error => "$_" }
        );

So if it is not showing the exception info it is because it is not an exception. In both cases I'd feel comfortable with a change to send the exception to the logs, unless debugging is set (i.e. no need to give the consumer details about the internal problems in Koha). So I vote for all unhandled exceptions to return a generic internal server error and warn the exception info.
Comment 9 Tomás Cohen Arazi 2020-03-06 12:04:47 UTC
(In reply to Tomás Cohen Arazi from comment #8)
> (In reply to Martin Renvoize from comment #6)
> > Hoping to get an answer from Tomas on this one regarding Jonathan's
> > question.. we would like to know if the API should really be returning the
> > actual exception error in the 500 response.
> 
> The usual pattern is:

I forgot to say I'm sure there's probably not 100% consistency on this.
Comment 10 Jonathan Druart 2020-03-06 12:32:44 UTC
It's not related to 500 but 400. There is a Koha::Exceptions::Hold::CannotSuspendFound that is raised and we need to see it somewhere.
Comment 11 Tomás Cohen Arazi 2020-03-06 13:55:38 UTC
(In reply to Jonathan Druart from comment #10)
> It's not related to 500 but 400. There is a
> Koha::Exceptions::Hold::CannotSuspendFound that is raised and we need to see
> it somewhere.

My gut feeling is we should somehow overload Test::Mojo so it does ->or( sub { diag $t->tx->res->to_string } ), or just add it everywhere and enforce it as a coding guideline.

This would give us more light on handled exceptions, but we still need something for unhandled exceptions, in the lines of bug 18206 (probably making use of a helper instead, but you get the point).
Comment 12 Jonathan Druart 2020-03-30 09:24:54 UTC
(In reply to Tomás Cohen Arazi from comment #11)
> (In reply to Jonathan Druart from comment #10)
> > It's not related to 500 but 400. There is a
> > Koha::Exceptions::Hold::CannotSuspendFound that is raised and we need to see
> > it somewhere.
> 
> My gut feeling is we should somehow overload Test::Mojo so it does ->or( sub
> { diag $t->tx->res->to_string } ), or just add it everywhere and enforce it
> as a coding guideline.
> 
> This would give us more light on handled exceptions, but we still need
> something for unhandled exceptions, in the lines of bug 18206 (probably
> making use of a helper instead, but you get the point).

That's not only API related, it's exception related.

For instance I get that this morning:

t/db_dependent/Koha/Object.t .. 9/20     # No tests run!

#   Failed test 'No tests run for subtest "attributes_from_api() tests"'
#   at t/db_dependent/Koha/Object.t line 568.
[A bad parameter was given]# Looks like your test exited with 255 just after 14.

It's impossible to track down where it comes from...
Comment 13 Joy Nelson 2020-04-01 22:44:54 UTC
Pushed to 19.11.x for 19.11.05
Comment 14 Lucas Gass 2020-04-09 20:18:22 UTC
backported to 19.05.x for 19.05.10
Comment 15 Hayley Pelham 2020-04-14 22:25:51 UTC
Backported to 18.11.x for 18.11.16