Bug 37816

Summary: Stop SIP2 from logging passwords
Product: Koha Reporter: Magnus Enger <magnus>
Component: SIP2Assignee: Magnus Enger <magnus>
Status: RESOLVED FIXED QA Contact: Marcel de Rooy <m.de.rooy>
Severity: normal    
Priority: P5 - low CC: alexbuckley, dcook, didier.gautheron, fridolin.somers, jesse, jonathan.druart, katrin.fischer, laurent.ducos, lisette, lucas, m.de.rooy, martin.renvoize, nick, paul.derscheid, philippe.blouin, tomascohen, victor
Version: Main   
Hardware: All   
OS: All   
See Also: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=39469
Change sponsored?: --- Patch complexity: Small patch
Documentation contact: Documentation submission:
Text to go in the release notes:
Version(s) released in:
25.05.00,24.11.02,24.05.07,23.11.12,22.11.24
Circulation function:
Attachments: Bug 37816: Stop SIP2 from logging passwords
Bug 37816: Stop SIP2 from logging passwords
Bug 37816: Stop SIP2 from logging passwords
Bug 37816: Stop SIP2 from logging passwords
Bug 37816: Stop SIP2 from logging passwords
Bug 37816: (QA follow-up) Avoid repetition, typo and pipe test

Description Magnus Enger 2024-09-03 08:49:13 UTC
SIP2 logs all incoming requests verbatim, including passwords for the user that the SIP2 client is authenticating as and the passwords of end users. 

Could we identify password fields and replace actual passwords with something like "***" before requests are logged?
Comment 1 David Cook 2024-09-04 05:36:26 UTC
This has been on my mind recently too...

I think the most important place would be in C4::SIP::SIPServer:
siplog( 'LOG_INFO', "INPUT MSG: '$buffer'" );

Perhaps LOG_INFO should be changed to LOG_DEBUG. 

If we're processing INPUT MSG before showing INPUT MSG, it sort of defeats the point of even having it. 

There's other places in the logs where info could leak out a well... the SIP logs have issues...
Comment 2 Magnus Enger 2024-09-04 06:26:06 UTC Comment hidden (obsolete)
Comment 3 Magnus Enger 2024-09-04 06:28:46 UTC
(In reply to David Cook from comment #1)
> This has been on my mind recently too...
> 
> I think the most important place would be in C4::SIP::SIPServer:
> siplog( 'LOG_INFO', "INPUT MSG: '$buffer'" );
> 
> Perhaps LOG_INFO should be changed to LOG_DEBUG. 
> 
> If we're processing INPUT MSG before showing INPUT MSG, it sort of defeats
> the point of even having it. 
> 
> There's other places in the logs where info could leak out a well... the SIP
> logs have issues...

I have tried a different approach, looking for, and replacing, password fields just before strings are written to the logs. Happy to sign off patches from others if there are better ways to do it. :-)
Comment 4 David Cook 2024-09-04 06:47:04 UTC
(In reply to Magnus Enger from comment #3)
> I have tried a different approach, looking for, and replacing, password
> fields just before strings are written to the logs. Happy to sign off
> patches from others if there are better ways to do it. :-)

Sounds pretty good to me!

Since it's just the logging, it should be fairly low risk too. Like worst case should just be that it does nothing, right? I can't see that causing any unexpected fatal errors.

--

At a glance, you wouldn't need t/db_dependent/SIP/Sip.t  to be in db_dependent, since you're just massaging a string.
Comment 5 Magnus Enger 2024-09-04 06:59:27 UTC
(In reply to David Cook from comment #4)
> At a glance, you wouldn't need t/db_dependent/SIP/Sip.t  to be in
> db_dependent, since you're just massaging a string.

My thought was that there are other subs in C4::SIP::Sip that should be tested in the same file, but I guess most of them are just string manipulations anyway. Should I move it?
Comment 6 Victor Grousset/tuxayo 2024-12-01 05:31:03 UTC Comment hidden (obsolete)
Comment 7 Victor Grousset/tuxayo 2024-12-01 05:32:38 UTC
It works ! :)
Comment 8 Victor Grousset/tuxayo 2024-12-01 05:34:59 UTC
(In reply to Magnus Enger from comment #5)
> (In reply to David Cook from comment #4)
> > At a glance, you wouldn't need t/db_dependent/SIP/Sip.t  to be in
> > db_dependent, since you're just massaging a string.
> 
> My thought was that there are other subs in C4::SIP::Sip that should be
> tested in the same file, but I guess most of them are just string
> manipulations anyway. Should I move it?

Yep, and there is already t/SIP/Sip.t testing string manipulations.
Comment 9 Victor Grousset/tuxayo 2024-12-01 05:40:43 UTC
Comment on attachment 175039 [details] [review]
Bug 37816: Stop SIP2 from logging passwords

Review of attachment 175039 [details] [review]:
-----------------------------------------------------------------

::: C4/SIP/Sip.pm
@@ +257,5 @@
> +#   19 Item Status Update - AC terminal password
> +#   25 Patron Enable - AC terminal password- AD patron password
> +#   15 Hold - AC terminal password - AD patron password
> +#   29 Renew - AC terminal password - AD patron password
> +#   65 Renew All - AC terminal password - AD patron password

POD syntax is missing:
https://wiki.koha-community.org/wiki/Coding_Guidelines#Subroutine

Thanks for documenting the messages and field! :D
Comment 10 Victor Grousset/tuxayo 2024-12-01 05:43:33 UTC
QA script finds tidy issues.

 WARN	C4/SIP/Sip.pm
   WARN	  tidiness
		The file is less tidy than before (bad/messy lines before: 41, now: 43)

 FAIL	t/db_dependent/SIP/Sip.t
   FAIL	  file permissions
		File must have the exec flag
   WARN	  tidiness
		The file is less tidy than before (bad/messy lines before: 0, now: 16)
Comment 11 Magnus Enger 2024-12-03 14:55:18 UTC Comment hidden (obsolete)
Comment 12 Victor Grousset/tuxayo 2024-12-18 08:21:01 UTC
Created attachment 175639 [details] [review]
Bug 37816: Stop SIP2 from logging passwords

Koha's SIP2 server does a lot of logging, including all incoming
requests, in full. This means that passwords are logged, both for
the user the SIP2 client uses for logging into Koha, as well as
for the end users who provide a password to e.g. check something
out. This patch replaces passwords with three asterisks in
log strings, before they are written to the log.

To test, in ktd:
- Run the new tests:
  $ prove t/db_dependent/SIP/Sip.t
- Tail the SIP2 logs:
  $ sudo tail -f /var/log/koha/kohadev/sip*.log
- Telnet into the SIP2 server:
  $ telnet localhost 6001
- Try logging in by pasting this into the telnet session:
  "9300CNterm1|COmypassword|CPCPL|"
- Verify that "mypassword" is replaced by "***" in the logs
- Try different values for the password, including the correct password
  which is "term1" in ktd
- Try other SIP2 messages that include password fields (AC, AD, CO)

Update 2024-12-03: Fix issues pointed out by QA.

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>
Comment 13 Victor Grousset/tuxayo 2024-12-18 08:27:27 UTC
Previous issues fixed :)

After comparing diff, no change that would require full retesting.
Tests still pass.

Patch reattached with signoff line.

Note for QA: false positive from the script:

 FAIL	C4/SIP/Sip.pm
   FAIL	  pod coverage
Comment 14 Marcel de Rooy 2025-01-10 08:55:04 UTC
What about a delimiter that is part of the password?
If I enter a pipe char in the qwerty test, SIP.t will fail.

Not sure if Koha/SIP would suffer currently from users with pipe char in pwd?
Comment 15 Marcel de Rooy 2025-01-10 09:10:34 UTC
Typo replcing btw
Comment 16 Magnus Enger 2025-01-10 09:57:02 UTC
(In reply to Marcel de Rooy from comment #14)
> What about a delimiter that is part of the password?
> If I enter a pipe char in the qwerty test, SIP.t will fail.

Good point. The solution I can think of right now is to change the matching from

delimiter + [AC|AD|CO] + something + delimiter

to 

delimiter + [AC|AD|CO] + something + delimiter + [end of string | two uppercase letters]

This would still not be perfect, but better. Not sure if it would be good enough? It might leave a part of the password in the logs, which is still better than the current situation, where every password is logged. 

> Not sure if Koha/SIP would suffer currently from users with pipe char in pwd?

Another good point! We should test that. I suspect a password with a pipe followed by two uppercase letters will be problematic, at least if those letters correspond to an actual SIP2 field.
Comment 17 Magnus Enger 2025-01-10 10:05:06 UTC
Yup! 

$ telnet localhost 6001
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
9300CNterm1|COterm1|CPCPL|             
941

Then I changed the password of term1 to "term1|CPterm2" both in SIPconfig.xml and in Koha: 

$ telnet localhost 6001
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
9300CNterm1|COterm1|CPterm2|CPCPL|
940

So it looks like pipes in passwords are not handled well... Not sure what to do about it, though.
Comment 18 Marcel de Rooy 2025-01-17 10:23:41 UTC
(In reply to Magnus Enger from comment #17)
> Yup! 
> 
> $ telnet localhost 6001
> Trying 127.0.0.1...
> Connected to localhost.
> Escape character is '^]'.
> 9300CNterm1|COterm1|CPCPL|             
> 941
> 
> Then I changed the password of term1 to "term1|CPterm2" both in
> SIPconfig.xml and in Koha: 
> 
> $ telnet localhost 6001
> Trying 127.0.0.1...
> Connected to localhost.
> Escape character is '^]'.
> 9300CNterm1|COterm1|CPterm2|CPCPL|
> 940
> 
> So it looks like pipes in passwords are not handled well... Not sure what to
> do about it, though.

Thanks for confirming. Will be passing QA with a comment or so.
Comment 19 Marcel de Rooy 2025-01-17 10:55:31 UTC
Created attachment 176717 [details] [review]
Bug 37816: Stop SIP2 from logging passwords

Koha's SIP2 server does a lot of logging, including all incoming
requests, in full. This means that passwords are logged, both for
the user the SIP2 client uses for logging into Koha, as well as
for the end users who provide a password to e.g. check something
out. This patch replaces passwords with three asterisks in
log strings, before they are written to the log.

To test, in ktd:
- Run the new tests:
  $ prove t/db_dependent/SIP/Sip.t
- Tail the SIP2 logs:
  $ sudo tail -f /var/log/koha/kohadev/sip*.log
- Telnet into the SIP2 server:
  $ telnet localhost 6001
- Try logging in by pasting this into the telnet session:
  "9300CNterm1|COmypassword|CPCPL|"
- Verify that "mypassword" is replaced by "***" in the logs
- Try different values for the password, including the correct password
  which is "term1" in ktd
- Try other SIP2 messages that include password fields (AC, AD, CO)

Update 2024-12-03: Fix issues pointed out by QA.

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 20 Marcel de Rooy 2025-01-17 10:55:34 UTC
Created attachment 176718 [details] [review]
Bug 37816: (QA follow-up) Avoid repetition, typo and pipe test

Combining three regexes into one. Typo replcing.
Adding a test with pipe in pwd.

Test plan:
Run t/SIP/Sip.t

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 21 Alex Buckley 2025-02-05 01:52:38 UTC
Applied to 24.05.x-security branch.

Note: In the test plan it says to run 'prove t/db_dependent/SIP/Sip.t' , however, that file doesn't exist. 

You need to run: 'prove t/SIP/Sip.t'
Comment 22 Fridolin Somers 2025-02-14 14:12:33 UTC
Applied to 23.11.x-security branch
Comment 23 Jesse Maseto 2025-02-18 20:58:13 UTC
Applied to 22.11.x-security branch
Comment 24 Paul Derscheid 2025-02-22 18:17:50 UTC
Applied to 24.11.x-security
Comment 25 Katrin Fischer 2025-03-06 12:56:12 UTC
Pushed for 25.05!

Well done everyone, thank you!