Bug 35246 - Bad data erorrs should provide better logs for api/v1/biblios
Summary: Bad data erorrs should provide better logs for api/v1/biblios
Status: Pushed to main
Alias: None
Product: Koha
Classification: Unclassified
Component: REST API (show other bugs)
Version: Main
Hardware: All All
: P5 - low minor
Assignee: Tomás Cohen Arazi (tcohen)
QA Contact:
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2023-11-03 10:49 UTC by Marcel de Rooy
Modified: 2025-02-19 16:07 UTC (History)
3 users (show)

See Also:
Change sponsored?: ---
Patch complexity: Trivial patch
Documentation contact:
Documentation submission:
Text to go in the release notes:
Version(s) released in:
25.05.00
Circulation function:


Attachments
Bug 35246: Unit tests (2.64 KB, patch)
2025-02-13 13:03 UTC, Tomás Cohen Arazi (tcohen)
Details | Diff | Splinter Review
Bug 35246: Make Koha::Biblio->to_api throw relevant exception if no biblioitem row (1.64 KB, patch)
2025-02-13 13:03 UTC, Tomás Cohen Arazi (tcohen)
Details | Diff | Splinter Review
Bug 35246: Make Koha::Biblio->to_api throw relevant exception if no biblioitem row (3.64 KB, patch)
2025-02-13 13:22 UTC, Tomás Cohen Arazi (tcohen)
Details | Diff | Splinter Review
Bug 35246: Unit tests (2.73 KB, patch)
2025-02-13 15:23 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 35246: Make Koha::Biblio->to_api throw relevant exception if no biblioitem row (3.73 KB, patch)
2025-02-13 15:23 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 35246: Make Koha::Biblio->to_api throw relevant exception if no biblioitem row (3.75 KB, patch)
2025-02-18 11:58 UTC, Nick Clemens (kidclamp)
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Marcel de Rooy 2023-11-03 10:49:29 UTC
See also bug 33960. Found it testing there.

[2023/11/03 10:33:00] [ERROR] GET /api/v1/biblios: unhandled exception (Mojo::Exception)<<Can't call method "to_api" on an undefined value at /usr/share/koha/Koha/Biblio.pm line 1433.>>
=>     my $json_biblioitem = $self->biblioitem->to_api( $args );

Just testing /api/v1/biblios with Accept=application/json.
Note that Accept=application/marc works fine.
Comment 1 David Cook 2025-02-13 00:22:47 UTC
Is this still an issue?
Comment 2 Tomás Cohen Arazi (tcohen) 2025-02-13 12:06:00 UTC
(In reply to Marcel de Rooy from comment #0)
> See also bug 33960. Found it testing there.
> 
> [2023/11/03 10:33:00] [ERROR] GET /api/v1/biblios: unhandled exception
> (Mojo::Exception)<<Can't call method "to_api" on an undefined value at
> /usr/share/koha/Koha/Biblio.pm line 1433.>>
> =>     my $json_biblioitem = $self->biblioitem->to_api( $args );

That means the DB is f*d up? Missing a biblioitems entry
Comment 3 Tomás Cohen Arazi (tcohen) 2025-02-13 12:14:41 UTC
I'd say the 'issue' here is the unhandled exception. We could detect the situation and raise a relevant exception, and return a meaningful error in the logs instead.
Comment 4 Tomás Cohen Arazi (tcohen) 2025-02-13 13:03:46 UTC
Created attachment 178001 [details] [review]
Bug 35246: Unit tests
Comment 5 Tomás Cohen Arazi (tcohen) 2025-02-13 13:03:49 UTC Comment hidden (obsolete)
Comment 6 Tomás Cohen Arazi (tcohen) 2025-02-13 13:22:53 UTC
Created attachment 178007 [details] [review]
Bug 35246: Make Koha::Biblio->to_api throw relevant exception if no biblioitem row

This patch makes the `to_api()` method return an proper exception when
the `$self->biblioitem` accessor returns `undef`. This is a bad data
scenario and we could do better in terms of logging the situation.

The new exception will be correctly rendered in the logs by the
`unhandled_exception` Mojolicious helper and no behavior change on the
API.

I wasn't sure to keep the api tests I wrote. I originally added handling
for the specific exception in the controller, but it become obvious it
was not worth: too much code, the `GET /biblios` endpoint would need the
same treatment, etc. And the current `500 Internal server error` is good
enough as a response, and the logs explain the situation correctly.

To test:
1. On a fresh `KTD` pick a biblio (say biblionumber=1)
2. Use your favourite REST tool (Postman?) to access the record with
   `Accept: application/json`. i.e.

```
GET kohadev.localhost/api/v1/biblios/1
Accept: application/json
```

=> SUCCESS: All good
3. Delete the related `biblioitems` row:
   $ ktd --shell
  k$ koha-mysql kohadev
   > DELETE FROM biblioitems WHERE biblionumber=1; \q
4. Repeat 2
=> SUCCESS: You get a 500 error
5. Check the logs
=> FAIL: You get a cryptic message about accessing a method on an
undefined object:

```
2025/02/13 13:15:00] [ERROR] GET /api/v1/biblios: unhandled exception (Mojo::Exception)<<Can't call method "to_api" on an undefined value at /usr/share/koha/Koha/Biblio.pm line 1433.>>
```

6. Apply this patch
7. Restart things:
  k$ restart_all
8. Repeat 2
=> SUCCESS: You get a 500 error
9. Check the logs
=> SUCCESS: You get a more meaningful exception:

```
[2025/02/13 13:20:00] [ERROR] GET /api/v1/biblios/1: unhandled exception (Koha::Exceptions::RelatedObjectNotFound)<<Exception 'Koha::Exceptions::RelatedObjectNotFound' thrown 'The requested related object does not exist' with accessor => biblioitem, class => Koha::Biblioitem>>
```

10. Run the tests:
  k$ prove t/db_dependent/Koha/Biblio.t \
           t/db_dependent/api/v1/biblios.t
=> SUCCESS: They pass!
11. Sign off :-D
Comment 7 Marcel de Rooy 2025-02-13 15:23:57 UTC
Created attachment 178018 [details] [review]
Bug 35246: Unit tests

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 8 Marcel de Rooy 2025-02-13 15:23:59 UTC
Created attachment 178019 [details] [review]
Bug 35246: Make Koha::Biblio->to_api throw relevant exception if no biblioitem row

This patch makes the `to_api()` method return an proper exception when
the `$self->biblioitem` accessor returns `undef`. This is a bad data
scenario and we could do better in terms of logging the situation.

The new exception will be correctly rendered in the logs by the
`unhandled_exception` Mojolicious helper and no behavior change on the
API.

I wasn't sure to keep the api tests I wrote. I originally added handling
for the specific exception in the controller, but it become obvious it
was not worth: too much code, the `GET /biblios` endpoint would need the
same treatment, etc. And the current `500 Internal server error` is good
enough as a response, and the logs explain the situation correctly.

To test:
1. On a fresh `KTD` pick a biblio (say biblionumber=1)
2. Use your favourite REST tool (Postman?) to access the record with
   `Accept: application/json`. i.e.

```
GET kohadev.localhost/api/v1/biblios/1
Accept: application/json
```

=> SUCCESS: All good
3. Delete the related `biblioitems` row:
   $ ktd --shell
  k$ koha-mysql kohadev
   > DELETE FROM biblioitems WHERE biblionumber=1; \q
4. Repeat 2
=> SUCCESS: You get a 500 error
5. Check the logs
=> FAIL: You get a cryptic message about accessing a method on an
undefined object:

```
2025/02/13 13:15:00] [ERROR] GET /api/v1/biblios: unhandled exception (Mojo::Exception)<<Can't call method "to_api" on an undefined value at /usr/share/koha/Koha/Biblio.pm line 1433.>>
```

6. Apply this patch
7. Restart things:
  k$ restart_all
8. Repeat 2
=> SUCCESS: You get a 500 error
9. Check the logs
=> SUCCESS: You get a more meaningful exception:

```
[2025/02/13 13:20:00] [ERROR] GET /api/v1/biblios/1: unhandled exception (Koha::Exceptions::RelatedObjectNotFound)<<Exception 'Koha::Exceptions::RelatedObjectNotFound' thrown 'The requested related object does not exist' with accessor => biblioitem, class => Koha::Biblioitem>>
```

10. Run the tests:
  k$ prove t/db_dependent/Koha/Biblio.t \
           t/db_dependent/api/v1/biblios.t
=> SUCCESS: They pass!
11. Sign off :-D

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 9 Nick Clemens (kidclamp) 2025-02-18 11:58:46 UTC
Created attachment 178173 [details] [review]
Bug 35246: Make Koha::Biblio->to_api throw relevant exception if no biblioitem row

This patch makes the `to_api()` method return an proper exception when
the `$self->biblioitem` accessor returns `undef`. This is a bad data
scenario and we could do better in terms of logging the situation.

The new exception will be correctly rendered in the logs by the
`unhandled_exception` Mojolicious helper and no behavior change on the
API.

I wasn't sure to keep the api tests I wrote. I originally added handling
for the specific exception in the controller, but it become obvious it
was not worth: too much code, the `GET /biblios` endpoint would need the
same treatment, etc. And the current `500 Internal server error` is good
enough as a response, and the logs explain the situation correctly.

To test:
1. On a fresh `KTD` pick a biblio (say biblionumber=1)
2. Use your favourite REST tool (Postman?) to access the record with
   `Accept: application/json`. i.e.

```
GET kohadev.localhost/api/v1/biblios/1
Accept: application/json
```

=> SUCCESS: All good
3. Delete the related `biblioitems` row:
   $ ktd --shell
  k$ koha-mysql kohadev
   > DELETE FROM biblioitems WHERE biblionumber=1; \q
4. Repeat 2
=> SUCCESS: You get a 500 error
5. Check the logs
=> FAIL: You get a cryptic message about accessing a method on an
undefined object:

```
2025/02/13 13:15:00] [ERROR] GET /api/v1/biblios: unhandled exception (Mojo::Exception)<<Can't call method "to_api" on an undefined value at /usr/share/koha/Koha/Biblio.pm line 1433.>>
```

6. Apply this patch
7. Restart things:
  k$ restart_all
8. Repeat 2
=> SUCCESS: You get a 500 error
9. Check the logs
=> SUCCESS: You get a more meaningful exception:

```
[2025/02/13 13:20:00] [ERROR] GET /api/v1/biblios/1: unhandled exception (Koha::Exceptions::RelatedObjectNotFound)<<Exception 'Koha::Exceptions::RelatedObjectNotFound' thrown 'The requested related object does not exist' with accessor => biblioitem, class => Koha::Biblioitem>>
```

10. Run the tests:
  k$ prove t/db_dependent/Koha/Biblio.t \
           t/db_dependent/api/v1/biblios.t
=> SUCCESS: They pass!
11. Sign off :-D

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Signed-off-by: Nick Clemens <nick@bywatersolutions.com>
Comment 10 Katrin Fischer 2025-02-19 16:07:22 UTC
Pushed for 25.05!

Well done everyone, thank you!