Bug 36421 - Better logging of 500 errors in V1/Auth.pm
Summary: Better logging of 500 errors in V1/Auth.pm
Status: Pushed to oldstable
Alias: None
Product: Koha
Classification: Unclassified
Component: REST API (show other bugs)
Version: Main
Hardware: All All
: P5 - low normal (vote)
Assignee: Kyle M Hall
QA Contact: Marcel de Rooy
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2024-03-25 18:41 UTC by Kyle M Hall
Modified: 2024-05-28 16:24 UTC (History)
5 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:
24.05.00,23.11.06,23.05.12


Attachments
Bug 36421: REST API 500 errors say to check the logs, but suppress errors that would be there (1.51 KB, patch)
2024-03-25 18:42 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 36421: Make sure pre-controller errors are correctly logged (2.75 KB, patch)
2024-03-27 12:35 UTC, Tomás Cohen Arazi
Details | Diff | Splinter Review
Bug 36421: Make sure pre-controller errors are correctly logged (2.80 KB, patch)
2024-03-27 12:42 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 36421: Make sure pre-controller errors are correctly logged (2.98 KB, patch)
2024-03-29 09:09 UTC, Marcel de Rooy
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Kyle M Hall 2024-03-25 18:41:25 UTC
If a REST auth error happens that that is unblessed or uncaught, we should warn the value to the logs.

Test Plan:
1) Install the curbside pickups plugin
2) create a patron with the userid 'puser' and the cardnumber 'pcard'
3) GET /api/v1/contrib/curbsidepickup/patrons/XXX/pickups using basic auth with the username 'pcard' where XXX is the patron borrowernumber
4) Note there is no error in the logs
Comment 1 Kyle M Hall 2024-03-25 18:42:55 UTC
Created attachment 163856 [details] [review]
Bug 36421: REST API 500 errors say to check the logs, but suppress errors that would be there

If a REST auth error happens that that is unblessed or uncaught, we should warn the value to the logs.

Test Plan:
1) Install the curbside pickups plugin
2) create a patron with the userid 'puser' and the cardnumber 'pcard'
3) GET /api/v1/contrib/curbsidepickup/patrons/XXX/pickups using basic auth with the username 'pcard' where XXX is the patron borrowernumber
4) Note there is no error in the logs
5) Apply this patch
6) Repeat step 3
7) You should now see an error in the logs!
Comment 2 Tomás Cohen Arazi 2024-03-27 12:14:27 UTC
I noticed a bug in the basic Auth code that makes it easy to highlight this issue. If you don't mind, Kyle, I'll provide an alternate patch for this.
Comment 3 Tomás Cohen Arazi 2024-03-27 12:35:54 UTC
Created attachment 163994 [details] [review]
Bug 36421: Make sure pre-controller errors are correctly logged

If something explodes in Koha::REST::V1::Auth chances are that no logging will happen.

This patch makes sure they are!

To test:
1. Make sure you do NOT have 36420 on your tree
2. Make sure you are looking at the logs:
   $ ktd --shell
  k$ koha-plack --restart kohadev; tail -f /var/log/koha/kohadev/*.log
3. Use Postman or similar for hitting some known endpoint. Use
   the user's cardnumber instead of the userid. On a default KTD launch, the
   generated user's cardnumber is '42'.
   GET /patrons
=> FAIL: You get a 500 error (expected, fixed on 36420) but no useful logging found.
4. Apply this patch
5. Ctrl+c on the logs and re-run the command
6. Repeat 3
=> SUCCESS: You get a 500, but you also get the exception information logged!
7. Sign off :-D
Comment 4 Kyle M Hall 2024-03-27 12:42:18 UTC
Created attachment 163995 [details] [review]
Bug 36421: Make sure pre-controller errors are correctly logged

If something explodes in Koha::REST::V1::Auth chances are that no logging will happen.

This patch makes sure they are!

To test:
1. Make sure you do NOT have 36420 on your tree
2. Make sure you are looking at the logs:
   $ ktd --shell
  k$ koha-plack --restart kohadev; tail -f /var/log/koha/kohadev/*.log
3. Use Postman or similar for hitting some known endpoint. Use
   the user's cardnumber instead of the userid. On a default KTD launch, the
   generated user's cardnumber is '42'.
   GET /patrons
=> FAIL: You get a 500 error (expected, fixed on 36420) but no useful logging found.
4. Apply this patch
5. Ctrl+c on the logs and re-run the command
6. Repeat 3
=> SUCCESS: You get a 500, but you also get the exception information logged!
7. Sign off :-D

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Comment 5 Marcel de Rooy 2024-03-29 09:09:33 UTC
Created attachment 164117 [details] [review]
Bug 36421: Make sure pre-controller errors are correctly logged

If something explodes in Koha::REST::V1::Auth chances are that no logging will happen.

This patch makes sure they are!

To test:
1. Make sure you do NOT have 36420 on your tree
2. Make sure you are looking at the logs:
   $ ktd --shell
  k$ koha-plack --restart kohadev; tail -f /var/log/koha/kohadev/*.log
3. Use Postman or similar for hitting some known endpoint. Use
   the user's cardnumber instead of the userid. On a default KTD launch, the
   generated user's cardnumber is '42'.
   GET /patrons
=> FAIL: You get a 500 error (expected, fixed on 36420) but no useful logging found.
4. Apply this patch
5. Ctrl+c on the logs and re-run the command
6. Repeat 3
=> SUCCESS: You get a 500, but you also get the exception information logged!
7. Sign off :-D

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
[OK] prove t/db_dependent/api/v1/items.t t/db_dependent/api/v1/unhandled_exceptions.t
Comment 6 Katrin Fischer 2024-04-04 13:25:48 UTC
Pushed for 24.05!

Well done everyone, thank you!
Comment 7 Fridolin Somers 2024-05-23 09:06:38 UTC
Pushed to 23.11.x for 23.11.06
Comment 8 Lucas Gass 2024-05-28 16:24:57 UTC
Backported to 23.05.x for upcoming 23.05.12