[Bug 40910] New: Log pollution for undefined/empty barcodes
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 Bug ID: 40910 Summary: Log pollution for undefined/empty barcodes Change sponsored?: --- Product: Koha Version: unspecified Hardware: All OS: All Status: NEW Severity: enhancement Priority: P5 - low Component: SIP2 Assignee: koha-bugs@lists.koha-community.org Reporter: tomascohen@gmail.com QA Contact: testopia@bugs.koha-community.org 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. -- You are receiving this mail because: You are watching all bug changes. You are the assignee for the bug.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 Tomás Cohen Arazi (tcohen) <tomascohen@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |jesse@bywatersolutions.com, | |kyle@bywatersolutions.com, | |lisette@bywatersolutions.co | |m, tomascohen@gmail.com Status|NEW |ASSIGNED Assignee|koha-bugs@lists.koha-commun |tomascohen@gmail.com |ity.org | -- You are receiving this mail because: You are watching all bug changes. You are the assignee for the bug.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 Tomás Cohen Arazi (tcohen) <tomascohen@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Severity|enhancement |normal -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 Tomás Cohen Arazi (tcohen) <tomascohen@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|ASSIGNED |Needs Signoff Patch complexity|--- |Trivial patch -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 --- Comment #1 from Tomás Cohen Arazi (tcohen) <tomascohen@gmail.com> --- Created attachment 187106 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=187106&action=edit Bug 40910: Regression tests Signed-off-by: Tomás Cohen Arazi <tomascohen@theke.io> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 --- Comment #2 from Tomás Cohen Arazi (tcohen) <tomascohen@gmail.com> --- Created attachment 187107 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=187107&action=edit 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> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 Tomás Cohen Arazi (tcohen) <tomascohen@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- See Also| |https://bugs.koha-community | |.org/bugzilla3/show_bug.cgi | |?id=40911 -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 --- Comment #3 from Kyle M Hall (khall) <kyle@bywatersolutions.com> --- 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! -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 --- Comment #4 from Kyle M Hall (khall) <kyle@bywatersolutions.com> --- (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. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 Kyle M Hall (khall) <kyle@bywatersolutions.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #187106|0 |1 is obsolete| | --- Comment #5 from Kyle M Hall (khall) <kyle@bywatersolutions.com> --- Created attachment 187195 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=187195&action=edit Bug 40910: Regression tests Signed-off-by: Tomás Cohen Arazi <tomascohen@theke.io> Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 Kyle M Hall (khall) <kyle@bywatersolutions.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #187195|0 |1 is obsolete| | --- Comment #6 from Kyle M Hall (khall) <kyle@bywatersolutions.com> --- Created attachment 187196 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=187196&action=edit Bug 40910: Regression tests Signed-off-by: Tomás Cohen Arazi <tomascohen@theke.io> Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 Kyle M Hall (khall) <kyle@bywatersolutions.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #187107|0 |1 is obsolete| | --- Comment #7 from Kyle M Hall (khall) <kyle@bywatersolutions.com> --- Created attachment 187197 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=187197&action=edit 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> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 Kyle M Hall (khall) <kyle@bywatersolutions.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Needs Signoff |Signed Off -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |m.de.rooy@rijksmuseum.nl --- Comment #8 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- (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. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Signed Off |Failed QA QA Contact|testopia@bugs.koha-communit |m.de.rooy@rijksmuseum.nl |y.org | --- Comment #9 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- Needs feedback. Changing status -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 --- Comment #10 from Tomás Cohen Arazi (tcohen) <tomascohen@gmail.com> --- (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. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40910 --- Comment #11 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- (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. -- You are receiving this mail because: You are watching all bug changes.
participants (1)
-
bugzilla-daemon@bugs.koha-community.org