Noticed in production, when `C4::SIP::ILS::Item->new` is passed an `$item_id` that is not defined or empty -or barcodedecode makes it like that- (e.g. faulty plugins) logs get flooded with DBIx::Class errors when it should never reach the ORM with a query because there's nothing to search for. If `barcodedecode` empties the barcode, a debug log should be printed because it might be a sign of a misconfiguration or faulty plugin.
Created attachment 187106 [details] [review] Bug 40910: Regression tests Signed-off-by: Tomás Cohen Arazi <tomascohen@theke.io>
Created attachment 187107 [details] [review] Bug 40910: Reduce log pollution for undefined/empty barcodes This patch prevents warnings and DBIx::Class errors when C4::SIP::ILS::Item->new() receives undefined, empty, or whitespace-only item_id values that could occur from faulty plugins or malformed SIP requests. Changes: - Add early validation for undefined/empty item_id before barcodedecode() - Add validation for barcodedecode() result before Koha::Items->find() - Add debug logging when barcodedecode empties a barcode (indicates misconfiguration) - Prevent "Odd number of elements in anonymous hash" warnings - Prevent DBIx::Class constraint validation errors - No functional changes - behavior preserved for valid barcodes Test plan: 1. Apply the regression tests 2. Run: $ ktd --shell k$ prove t/db_dependent/SIP/Item.t => FAIL: Tests fail! 3. Apply this patch 4. Repeat 2 => SUCCESS: Tests pass! 5. Tests cover: - Valid barcode functionality (preserved) - Undefined item_id (no warnings) - Empty string item_id (no warnings) - Whitespace-only item_id (no warnings) - barcodedecode edge cases (tabs, newlines, mixed) - Nonexistent barcodes (expected warnings preserved) 6. Verify no warnings in SIP logs for malformed requests 7. Sign off :-D Signed-off-by: Tomás Cohen Arazi <tomascohen@theke.io>
I would recommend running barcode decode *after* doing all your checks on item_id, as barcodedecode can trigger plugins that will *generate* a new barcode if passed an empty barcode string ( https://github.com/bywatersolutions/koha-plugin-barcode-prefixer ) for example. By testing $item_id and returning if it's empty *before* running barcodedecode on it, we can ensure we don't accidentally generate a non-existent barcode for the message!
(In reply to Kyle M Hall (khall) from comment #3) > I would recommend running barcode decode *after* doing all your checks on > item_id, as barcodedecode can trigger plugins that will *generate* a new > barcode if passed an empty barcode string ( > https://github.com/bywatersolutions/koha-plugin-barcode-prefixer ) for > example. > > By testing $item_id and returning if it's empty *before* running > barcodedecode on it, we can ensure we don't accidentally generate a > non-existent barcode for the message! My entire comment is invalid as Tomas already added a return on line 88. I think the log level is good as well, we should be able to scroll back in the logs to see the message that triggered the error.
Created attachment 187195 [details] [review] Bug 40910: Regression tests Signed-off-by: Tomás Cohen Arazi <tomascohen@theke.io> Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Created attachment 187196 [details] [review] Bug 40910: Regression tests Signed-off-by: Tomás Cohen Arazi <tomascohen@theke.io> Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Created attachment 187197 [details] [review] Bug 40910: Reduce log pollution for undefined/empty barcodes This patch prevents warnings and DBIx::Class errors when C4::SIP::ILS::Item->new() receives undefined, empty, or whitespace-only item_id values that could occur from faulty plugins or malformed SIP requests. Changes: - Add early validation for undefined/empty item_id before barcodedecode() - Add validation for barcodedecode() result before Koha::Items->find() - Add debug logging when barcodedecode empties a barcode (indicates misconfiguration) - Prevent "Odd number of elements in anonymous hash" warnings - Prevent DBIx::Class constraint validation errors - No functional changes - behavior preserved for valid barcodes Test plan: 1. Apply the regression tests 2. Run: $ ktd --shell k$ prove t/db_dependent/SIP/Item.t => FAIL: Tests fail! 3. Apply this patch 4. Repeat 2 => SUCCESS: Tests pass! 5. Tests cover: - Valid barcode functionality (preserved) - Undefined item_id (no warnings) - Empty string item_id (no warnings) - Whitespace-only item_id (no warnings) - barcodedecode edge cases (tabs, newlines, mixed) - Nonexistent barcodes (expected warnings preserved) 6. Verify no warnings in SIP logs for malformed requests 7. Sign off :-D Signed-off-by: Tomás Cohen Arazi <tomascohen@theke.io> Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
(In reply to Tomás Cohen Arazi (tcohen) from comment #0) > Noticed in production, when `C4::SIP::ILS::Item->new` is passed an > `$item_id` that is not defined or empty -or barcodedecode makes it like > that- (e.g. faulty plugins) logs get flooded with DBIx::Class errors when it > should never reach the ORM with a query because there's nothing to search > for. You probably mean: DBIx::Class::Storage::DBI::select_single(): Query returned more than one row. SQL that returns multiple rows is DEPRECATED for ->find and ->single at /usr/share/koha/Koha/Objects.pm line 95 This only seems to occur when we look for undef. Not for empty string. Skipping a db search for undef or empty string is a good thing though. But do we really need 153 lines for that? t/db_dependent/SIP/Item.t | 153 ++++++++++++++++++++++++++++++++++++++ And if the argument is flooding the logs, we are still doing that here.
Needs feedback. Changing status
(In reply to Marcel de Rooy from comment #9) > Needs feedback. Changing status Fair. It is hard for me, because you arrive to an area lacking some behavior tests, and constraining it to just the small thing you’re fixing seems lame too, as you need to build the entire scenario anyway. I’ll revisit my tendency to write full test coverage when touching an untested/partially tested sub, but cannot promise to not do it. Will do my best. I need to come back to this soon, and the other one. The dependency is not defined but there was some.
(In reply to Tomás Cohen Arazi (tcohen) from comment #10) > (In reply to Marcel de Rooy from comment #9) > > Needs feedback. Changing status > > Fair. It is hard for me, because you arrive to an area lacking some behavior > tests, and constraining it to just the small thing you’re fixing seems lame > too, as you need to build the entire scenario anyway. > > I’ll revisit my tendency to write full test coverage when touching an > untested/partially tested sub, but cannot promise to not do it. Will do my > best. Full test coverage is fine obviously. But you could always ask how far should you go? Do you need to test every trivial return? etc.