Bug 39713

Summary: SIP doen't log message in reply to a 97 (resend) request
Product: Koha Reporter: Marion Durand <marion.durand>
Component: SIP2Assignee: Bugs List <koha-bugs>
Status: NEW --- QA Contact: Testopia <testopia>
Severity: enhancement    
Priority: P5 - low    
Version: Main   
Hardware: All   
OS: All   
GIT URL: Change sponsored?: ---
Patch complexity: --- Documentation contact:
Documentation submission: Text to go in the release notes:
Version(s) released in:
Circulation function:

Description Marion Durand 2025-04-23 15:32:18 UTC
When connected, a self-checkout automate can send a message 97 (Request ACS Resend) to request Koha to send again the last message.
Koha comply and send the message, but this re-send isn't logged. 
While looking at the log, it is impossible to determine if Koha has sent the message or not.

Koha should log this message.

Testing this with ktd require to install telnet package as it is not possible to send the message 97 from the script sip_cli_emulator.pl


To test (all example work with default KTD)
1- start ktd on main

2- connect to ktd on root (`ktd --shell --root`)

3- in root check that sip is allowed and running (`koha-sip --status kohadev`)
3a- if it is not, then enable (`koha-sip --enable kohadev`) and start it (`koha-sip --start kohadev`)

4- outside your root session (`ktd --shell`), start a session with telnet on localhost and port 6001 (telnet 127.0.0.1 6001)
4a- you migh need to install telnet with your root session with command `apt-get update` then `apt-get install telnet`. You can now close your root session

5- In the telnet session : start a session with message 93
`9300CNterm1|COterm1|CPCPL|`
The anewser should be `941`

6- In the telnet session : request information about a patron (here cardnumber 23529000050113)
`6300120250423    151843          AOCPL|AA23529000050113|ACterm1|`
the answer should look like this
`64              00120250423    152422000000000000000000000000AOCPL|AA23529000050113|AEJordan Alford|BLY|BHUSD|BV0|CC5|BD5129 Library Rd. Centerville, CA 44262|BF(212) 555-1212|PB19520527|PCST|PIY|AFGreetings from Koha. |`

7- In the telnet session : send a request to send the last message again
`97`

8- check that Koha send you again the last message 
`64              00120250423    152422000000000000000000000000AOCPL|AA23529000050113|AEJordan Alford|BLY|BHUSD|BV0|CC5|BD5129 Library Rd. Centerville, CA 44262|BF(212) 555-1212|PB19520527|PCST|PIY|AFGreetings from Koha. |`

9- close the telnet session with ctrl + alt gr + ) (the same as ctrl + ] )

10- open the log file /var/log/koha/kohadevbox/sip-output.log

11- check that you can find the message 97 send but not the answer send again by Koha (it is on [INFO] level)
```
[2025/04/23 15:05:12] [970] [INFO] term1@127.0.0.1: INPUT MSG: '97' C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (319)
```
is not followed by the corresponding OUTPUT message
Other logs always have an INPUT and OUTPUT message (with [DEBUG] level message in between).
```
[2025/04/23 15:24:17] [3518] [INFO] [undef]@[undef]: INPUT MSG: '9300CNterm1|CO***|CPCPL' C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (319)
[2025/04/23 15:24:18] [3518] [INFO] [undef]@[undef]: OUTPUT MSG: '941' C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (319)

```
or
```
[2025/04/23 15:24:22] [3518] [INFO] term1@127.0.0.1: INPUT MSG: '6300120250423    151843          AOCPL|AA23529000050113|ACterm1' C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (319)
[2025/04/23 15:24:22] [3518] [INFO] term1@127.0.0.1: OUTPUT MSG: '64              00120250423    152422000000000000000000000000AOCPL|AA23529000050113|AEJordan Alford|BLY|BHUSD|BV0|CC5|BD5129 Library Rd. Centerville, CA 44262|BF(212)     555-1212|PB19520527|PCST|PIY|AFGreetings from Koha. |' C4::SIP::Sip::siplog /kohadevbox/koha/C4/SIP/Sip.pm (319)
```