| Summary: | The DIE handler in C4::SIP::Trapper is logging non-SIP errors, causing log flooding | ||
|---|---|---|---|
| Product: | Koha | Reporter: | Johanna Räisä <johanna.raisa> |
| Component: | SIP2 | Assignee: | Johanna Räisä <johanna.raisa> |
| Status: | Signed Off --- | QA Contact: | Testopia <testopia> |
| Severity: | enhancement | ||
| Priority: | P5 - low | CC: | bibliothek, cornelius.hertfelder, david, dcook, lari.taskula |
| Version: | Main | ||
| Hardware: | All | ||
| OS: | All | ||
| See Also: | https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=40915 | ||
| GIT URL: | Initiative type: | --- | |
| Sponsorship status: | --- | Comma delimited list of Sponsors: | |
| Crowdfunding goal: | 0 | Crowdfunding committed: | 0 |
| Crowdfunding contact: | Patch complexity: | --- | |
| Documentation contact: | Documentation submission: | ||
| Text to go in the release notes: | Version(s) released in: | ||
| Circulation function: | |||
| Attachments: |
Bug 41707: Modify C4::SIP::Trapper DIE handling for better logging
Bug 41707: Modify C4::SIP::Trapper DIE handling for better logging Bug 41707: Modify C4::SIP::Trapper DIE handling for better logging |
||
|
Description
Johanna Räisä
2026-01-26 09:05:52 UTC
Created attachment 192093 [details] [review] Bug 41707: Modify C4::SIP::Trapper DIE handling for better logging This patch improves the error handling in the SIP Trapper module by logging only SIP-related errors as errors and non-SIP errors as warnings. This change aims to reduce noise in the logs and make it easier to identify genuine SIP-related issues. Test plan: 1. Apply the patch 2. prove -lv t/db_dependent/SIP/Trapper.t 3. Ensure all tests pass without errors 4. Start the server: perl C4/SIP/SIPServer.pm /etc/koha/SIPconfig.xml 5. misc/sip_cli_emulator.pl -a 127.0.0.1 -p 6001 -su koha -sp koha -l MPL --patron koha -m patron_information 6. Verify that only SIP-related errors are logged as errors and non-SIP errors are warned. Sponsored-by: Koha-Suomi Oy I attempted to test (using KTD, so step 4 is not required as the SIP server is running), but I'm not really sure about step 6 and what I should be seeing.
Tests pass.
There are only log entries in sip-output.log and nothing in sip-error.log.
So will leave for someone else who is more familiar with SIP to sign off.
Here is what is in the sip-output.log after issuing the command in step 5:
118 [2026/03/05 18:08:17] [10534] [WARN] [undef]@[undef]: Setting gid to "1000 1000" Net::Server::log /usr/share/perl5/Net/Server.pm (962)
119 [2026/03/05 18:09:05] [10615] [WARN] [undef]@[undef]: Couldn't find sip2_resource_last_modified, considering configuration not up to date C4::SIP::Sip::siplo g /kohadevbox/koha/C4/SIP/Sip.pm (327)
120 [2026/03/05 18:09:05] [10615] [ERROR] [undef]@[undef]: ERROR: Institution kohalibrary does does not match a branchcode. This can cause unexpected behavior. C 4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
121 [2026/03/05 18:09:05] [10615] [ERROR] [undef]@[undef]: ERROR: Institution MAIN does does not match a branchcode. This can cause unexpected behavior. C4::SIP: :Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
122 [2026/03/05 18:09:05] [10615] [ERROR] [undef]@[undef]: ERROR: Institution kohalibrary2 does does not match a branchcode. This can cause unexpected behavior. C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
123 [2026/03/05 18:09:05] [10615] [DEBUG] [undef]@[undef]: Configuration::find_service: Trying 6001/tcp C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
124 [2026/03/05 18:09:05] [10615] [DEBUG] [undef]@[undef]: Configuration::find_service: Trying *:6001/tcp C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (32 7)
125 [2026/03/05 18:09:05] [10615] [DEBUG] [undef]@[undef]: Configuration::find_service: Trying 127.0.0.1:6001/tcp C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Si p.pm (327)
126 [2026/03/05 18:09:05] [10615] [DEBUG] [undef]@[undef]: raw_transport: timeout is 60 C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
127 [2026/03/05 18:09:05] [10615] [INFO] [undef]@[undef]: INPUT MSG: '9300CNkoha|CO***|CPMPL|' C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
128 [2026/03/05 18:09:05] [10615] [DEBUG] [undef]@[undef]: Sip::MsgType::new('C4::SIP::Sip::MsgType', '9300CNkoha...', '93'): seq.no '0', protocol 2 C4::SIP::Sip ::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
129 [2026/03/05 18:09:05] [10615] [DEBUG] [undef]@[undef]: Sip::MsgType::_initialize('Login', '00CNkoha|CO***|CPMPL|', 'A1A1', '2', ...) C4::SIP::Sip::siplog /ko hadevbox/koha/C4/SIP/Sip.pm (327)
130 [2026/03/05 18:09:05] [10615] [INFO] [undef]@[undef]: Successful login/auth for 'koha' of 'kohalibrary' C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm ( 327)
131 [2026/03/05 18:09:05] [10615] [DEBUG] [undef]@[undef]: login_core: $VAR1 = 'ILS'; C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
132 [2026/03/05 18:09:05] [10615] [DEBUG] [undef]@[undef]: new ILS 'kohalibrary' C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
133 [2026/03/05 18:09:05] [10615] [INFO] [undef]@[undef]: OUTPUT MSG: '941' C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
134 [2026/03/05 18:09:05] [10615] [DEBUG] koha@127.0.0.1: raw_transport: uname/inst: 'koha/kohalibrary' C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
135 [2026/03/05 18:09:05] [10615] [DEBUG] koha@127.0.0.1: read_request trimmed 1 character(s) C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
136 [2026/03/05 18:09:05] [10615] [INFO] koha@127.0.0.1: INPUT MSG: '6300120260305 180905 AOMPL|AAkoha|AC***|' C4::SIP::Sip::siplog /kohadevbox/koha/ C4/SIP/Sip.pm (327)
137 [2026/03/05 18:09:05] [10615] [DEBUG] koha@127.0.0.1: Sip::MsgType::new('C4::SIP::Sip::MsgType', '6300120260...', '63'): seq.no '0', protocol 2 C4::SIP::Sip: :siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
138 [2026/03/05 18:09:05] [10615] [DEBUG] koha@127.0.0.1: Sip::MsgType::_initialize('Patron Info', '00120260305 180905 AOMPL|AAkoha|AC***|', 'A3A18A1 0', '31', ...) C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
139 [2026/03/05 18:09:05] [10615] [DEBUG] koha@127.0.0.1: Debarred = undef : C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
140 [2026/03/05 18:09:05] [10615] [DEBUG] koha@127.0.0.1: new ILS::Patron(koha): found patron '42' C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
141 [2026/03/05 18:09:05] [10615] [DEBUG] koha@127.0.0.1: patron_status_string: 42 charge_ok: 1 C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
142 [2026/03/05 18:09:05] [10615] [INFO] koha@127.0.0.1: OUTPUT MSG: '64 00120260305 180905000000000000000000000000AOkohalibrary|AA42|AE koha|BLY |BHUSD|BV0|CC5|PCS|PIY|AFGreetings from Koha. |' C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
143 [2026/03/05 18:09:05] [10615] [DEBUG] koha@127.0.0.1: read_request trimmed 1 character(s) C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
144 [2026/03/05 18:09:05] [10615] [INFO] koha@127.0.0.1: INPUT MSG: '' C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
145 [2026/03/05 18:09:05] [10615] [INFO] koha@127.0.0.1: raw_transport: shutting down C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (327)
Created attachment 194719 [details] [review] Bug 41707: Modify C4::SIP::Trapper DIE handling for better logging This patch improves the error handling in the SIP Trapper module by logging only SIP-related errors as errors and non-SIP errors as warnings. This change aims to reduce noise in the logs and make it easier to identify genuine SIP-related issues. Test plan: 1. Apply the patch 2. prove -lv t/db_dependent/SIP/Trapper.t 3. Ensure all tests pass without errors 4. Start the server: perl C4/SIP/SIPServer.pm /etc/koha/SIPconfig.xml 5. misc/sip_cli_emulator.pl -a 127.0.0.1 -p 6001 -su koha -sp koha -l MPL --patron koha -m patron_information 6. Verify that only SIP-related errors are logged as errors and non-SIP errors are warned. Sponsored-by: Koha-Suomi Oy Signed-off-by: Jan Kissig <bibliothek@th-wildau.de> Remarks for testing: before applying the patch when running f.e. misc/sip_cli_emulator.pl -a 127.0.0.1 -p 6001 -su term1 -sp term1 -l MPL --patron koha -m patron_information there were a lot of output lines like [2026/03/06 13:33:02] [14661] [ERROR] [undef]@[undef]: DBIx::Class::ResultSource::_minimal_valueset_satisfying_constraint(): Unable to satisfy requested constraint 'primary', missing values for column(s): 'borrowernumber' at /kohadevbox/koha/Koha/Objects.pm line 95 C4::SIP::Trapper::__ANON__ /kohadevbox/koha/C4/SIP/Trapper.pm (70) After applying these errors starting with 'DBIx' were gone and only SIP2 related errors/warnings were left. Created attachment 194762 [details] [review] Bug 41707: Modify C4::SIP::Trapper DIE handling for better logging This patch improves the error handling in the SIP Trapper module by logging only SIP-related errors as errors and non-SIP errors as warnings. This change aims to reduce noise in the logs and make it easier to identify genuine SIP-related issues. Test plan: 1. Apply the patch 2. prove -lv t/db_dependent/SIP/Trapper.t 3. Ensure all tests pass without errors 4. Start the server: perl C4/SIP/SIPServer.pm /etc/koha/SIPconfig.xml 5. misc/sip_cli_emulator.pl -a 127.0.0.1 -p 6001 -su koha -sp koha -l MPL --patron koha -m patron_information 6. Verify that only SIP-related errors are logged as errors and non-SIP errors are warned. Sponsored-by: Koha-Suomi Oy Signed-off-by: Jan Kissig <bibliothek@th-wildau.de> Signed-off-by: David Nind <david@davidnind.com> Thanks Jan! I've added my sign off in case you are able to do the QA. David (In reply to David Nind from comment #6) > Thanks Jan! > > I've added my sign off in case you are able to do the QA. > > David Thanks David, but I would leave this to someone more capable. |