Bug 15438

Summary: Checking out an on-hold item sends holder's borrowernumber in AF (screen message) field.
Product: Koha Reporter: Barton Chittenden <barton>
Component: SIP2Assignee: Colin Campbell <colin.campbell>
Status: Needs Signoff --- QA Contact: Testopia <testopia>
Severity: critical    
Priority: P3 CC: cbrannon, colin.campbell, danielle, jonathan.druart, katrin.fischer, mtj, nick, rkuiper, veron
Version: master   
Hardware: All   
OS: All   
Whiteboard:
Change sponsored?: --- Patch complexity: ---
Bot Control: --- When did the bot last check this:
Who signed the patch off: Text to go in the release notes:
Attachments: Bug 15438: Do not display irrelevant errors when checking out via SIP
Proposed patch
Patch rebased
Bug 15438: Stop leaking data into SIP screen message
Bug 15438 - Checking out an on-hold item sends holder's borrowernumber in AF (screen message) field.
Bug 15438 [Alternate Solution] - Checking out an on-hold item sends holder's borrowernumber in AF (screen message) field.

Description Barton Chittenden 2015-12-29 15:33:58 UTC
Replicated in master.

Description: Let's say that 'Holding Patron' puts a hold on title 'ASDF'. If 'SIP  Patron' then tries to check out ASDF, Holding Patron's card number appears in the AF (i.e. Screen Message) field. This only occurs if the hold has *not* yet been finalized -- If ASDF is waiting for Holding Patron, the screen message will read "Item is on hold shelf for another patron."

The screen message containing only the Holding Patron's borrowernumber is confusing because a) It contains no context as to the nature of the number showing on the screen b) SIP devices work with borrower card numbers, so the number being returned has the wrong context. Furthermore, we're leaking patron information in a place where we probably would never check.

Replicating the problem:

Set up instance with two patrons, as well as a bib/item to put on hold/check out.
Make sure that circ rules allow holds.
Set up SIPconfig.xml to allow checkouts on the IP/port of your choice.
Start SIP2. Make sure that authentication, checkin and check out work for the 'SIP Patron'.
Ensure that AllowItemsOnHoldCheckout is set to "Don't Allow".

In the steps to replicate, the Title/barcode of the item on hold/being checked out will be 'asdf'. The Holding Patron will be referred to as 'holder' and the checkout patron will be referred to as 'sipper'. Let's say that sipper's borrowernumber is 52.

1/ Place a biblio level hold for asdf, with holder as the holding patron.
2/ Start `sudo tail -f /var/log/syslog | grep sip`
3/ Attempt to check out asdf to sipper. You will see the sip checkout message '11...' followed by a '120...|AF52|...' sip checkout response. This indicates that the checkout has failed (which we would expect), and that the screen message is '52'.

Example using ./misc/sip_cli_emulator.pl

$ ./misc/sip_cli_emulator.pl -a 127.0.0.1 -p 6001 -su staff -sp staff -l CPL --patron 23529001223636
--password 1234 --item 1234 -m checkout
Attempting socket connection to 127.0.0.1:6001...connected!
SEND: 9300CNstaff|COstaff|CPCPL|
READ: 941

Trying 'checkout'
SEND: 11YN20151229    05321120151229    053211AOCPL|AA23529001223636|AB1234|ACstaff|AD1234|BON|BIN|
READ: 120NUN20151229    053211AOCPL|AA23529001223636|AB1234|AJTheories of human development :|AH|AF52|BLY|BV5.00|BHUSD|BT06|
Comment 1 Nick Clemens 2016-04-07 20:48:06 UTC
Raising the severity, marking as a bug.

Repeated messages will return any one of:
borrowernumber
firstname
surname
cardnumber
reservedate
reservebranch

I believe in the code below we are just shoving the issuingimpossible hash into screen_msg and ending with any one of the values:

[koha.git] / C4 / SIP / ILS / Transaction / Checkout.pm
  67     if (scalar keys %$issuingimpossible) {
  68         foreach (keys %$issuingimpossible) {
  69             # do something here so we pass these errors
  70             $self->screen_msg($_ . ': ' . $issuingimpossible->{$_});
  71             $noerror = 0;
  72         }
  73     } else {
Comment 2 Nick Clemens 2016-04-07 21:26:50 UTC
(In reply to Nick Clemens from comment #1)

NVM - error is below, we loop through each reasonforconfirmation, some of these are borrower fields, when we hit those we print them as the screen message, we should instead check for the presence of any of these reasons and then log failed unknown if not equal and output and error to the screen_msg:


  74         foreach my $confirmation (keys %{$needsconfirmation}) {
  75             if ($confirmation eq 'RENEW_ISSUE'){
  76                 $self->screen_msg("Item already checked out to you: renewing item.");
  77             } elsif ($confirmation eq 'RESERVED' or $confirmation eq 'RESERVE_WAITING') {
  78                 my $x = $self->{item}->available($patron_barcode);
  79                 if ($x) {
  80                     $self->screen_msg("Item was reserved for you.");
  81                 } else {
  82                     $self->screen_msg("Item is reserved for another patron upon return.");
  83                     # $noerror = 0;
  84                 }
  85             } elsif ($confirmation eq 'ISSUED_TO_ANOTHER') {
  86                 $self->screen_msg("Item already checked out to another patron.  Please return item for check-in.");
  87                 $noerror = 0;
  88             } elsif ($confirmation eq 'DEBT') {
  89                 $self->screen_msg('Outstanding Fines block issue');
  90                 $noerror = 0;
  91             } elsif ($confirmation eq 'HIGHHOLDS') {
  92                 $overridden_duedate = $needsconfirmation->{$confirmation}->{returndate};
  93                 $self->screen_msg('Loan period reduced for high-demand item');
  94             } elsif ($confirmation eq 'RENTALCHARGE') {
  95                 if ($self->{fee_ack} ne 'Y') {
  96                     $noerror = 0;
  97                 }
  98             } else {
  99                 $self->screen_msg($needsconfirmation->{$confirmation});
 100                 $noerror = 0;
 101                 syslog('LOG_DEBUG', "Blocking checkout Reason:$confirmation");
 102             }
 103         }
 104     }
Comment 3 Christopher Brannon 2016-08-22 21:12:31 UTC
I have just confirmed this issue.  I have tested the SIP response and can see the AF field cycling through different responses each time we scan the item.  This is pretty messed up.  Our self check has been showing the name of the patron the item is on hold for in some instances.  Would love to see this fixed ASAP.
Comment 4 Jonathan Druart 2016-08-23 17:00:39 UTC Comment hidden (obsolete)
Comment 5 Jonathan Druart 2016-08-23 17:02:07 UTC
Christopher,
Since my understanding of the code under C4/SIP is closed to 0, I have tried to fix what you described but did not try the patch.
I am not sure at all it's the best way to fix it, but at least we have a patch to start :)
Comment 6 Colin Campbell 2016-08-23 19:29:08 UTC
Think whats being exposed here is that CanBookBeIssued is returning a 3 element return (although still documented as being 2!!) and the Sip routine does not reflect that change.
The Sip code should not pass a borrowernumber into AF you should see a 'on hold for another patron' message. The crude add all reasons logic is there because new reasons get added to C4/Circulation but not to the sip interface and theres a danger of saying "Not issued because --" The fix would be to make the call match how it now appears in C4::Circulation
Comment 7 Christopher Brannon 2016-08-23 20:22:37 UTC
(In reply to Jonathan Druart from comment #5)
> Christopher,
> Since my understanding of the code under C4/SIP is closed to 0, I have tried
> to fix what you described but did not try the patch.
> I am not sure at all it's the best way to fix it, but at least we have a
> patch to start :)

Are there instructions somewhere to setup and configure SIP on the backend?  If so, I could try to setup a test environment on my VM and test the patch.
Comment 8 Nick Clemens 2016-08-23 21:08:01 UTC
(In reply to Christopher Brannon from comment #7)
> Are there instructions somewhere to setup and configure SIP on the backend? 
> If so, I could try to setup a test environment on my VM and test the patch.

Some documentation here:
https://wiki.koha-community.org/wiki/Koha_SIP2_server_setup

Basically you can:
1 - enable and start sip using package commands
2 - make sure the patrons listed in SIPconfig.xml exist in Koha
3 - Use sip_cli_emulator from the koha-shell
Use localhost and port 6001

That should do it
Comment 9 Colin Campbell 2016-08-24 10:10:10 UTC
The description of the bug above is incorrect. Has anyone been able to reproduce the bug on current master? Heres the output I see following the setup as described: 
Request:11YN20160824    10574720160828    093005AO|AA23529001203323|AB502326000812|AC|AD|
Response:120NUN20160824    105747AOCPL|AA23529001203323|AB502326000812|AJThe flying gun /|AH|AFItem is reserved for another patron upon return.|BLY|[0d]
Comment 10 Jonathan Druart 2016-08-24 10:33:25 UTC
(In reply to Colin Campbell from comment #9)
> The description of the bug above is incorrect. Has anyone been able to
> reproduce the bug on current master? Heres the output I see following the
> setup as described: 
> Request:11YN20160824    10574720160828   
> 093005AO|AA23529001203323|AB502326000812|AC|AD|
> Response:120NUN20160824    105747AOCPL|AA23529001203323|AB502326000812|AJThe
> flying gun /|AH|AFItem is reserved for another patron upon return.|BLY|[0d]

As it depends on the keys order, I'd say the behavior may change randomly.
Comment 11 Colin Campbell 2016-08-24 11:34:26 UTC
OK this was introduced in a fix for Bug 4946 which changed how CanBookBEIssued returns data to the caller. Previously the routine returned a hashref of reasons for confirmation denial and each entry could be a key for further data this flattened it out and returns borrowernumber, surname and firstname as top level keys (i.e. they appear where the caller expects reasons) If you repeatedly try to issue the same item we then get these being fed in turn. 
CanBookBeIssued is a bit of a mess (the number of things passed back to the caller can vary according to circumstances) The Sip check out needs some logic to make sense of the return as the sub itself fails to
Comment 12 Colin Campbell 2016-08-24 11:40:28 UTC
The logic in C4::Circulation is that causes are returned in Uppercase and data associated with causes are in lower case (In some cases the data is still appearing as hash elemrnts of the uppercase entry but in these cases the case distinction holds) Its a godawful design - but by wrapping the call in a rtn that drops any lowercase "pseudo" causes we can fix the bug in hand.
Comment 13 Colin Campbell 2016-08-24 13:30:48 UTC
Created attachment 54827 [details] [review]
Proposed patch

This patch strips the unwanted data out of the hashrefs returned to the routine. Taking on board Jonathan's earlier patch I've made an explicit end to the loop once we've blocked the issue - This stops the anomalous data from appearing in screen message


Its tempting to refactor the routine in C4::Circulation too but that should probably not be contemplated while sober.

please test, theres lots of room here for odd corner cases
Comment 14 Jonathan Druart 2016-08-24 14:07:56 UTC
(In reply to Colin Campbell from comment #12)
> The logic in C4::Circulation is that causes are returned in Uppercase and
> data associated with causes are in lower case (In some cases the data is
> still appearing as hash elemrnts of the uppercase entry but in these cases
> the case distinction holds) Its a godawful design - but by wrapping the call
> in a rtn that drops any lowercase "pseudo" causes we can fix the bug in hand.

This is really awkward indeed :)
I'd prefer to list all the available error codes and add a big warning to CanBookBeIssued to inform the devs that this white-list need to be updated as well.
Comment 15 Colin Campbell 2016-11-17 10:23:53 UTC
(In reply to Jonathan Druart from comment #14)
> (In reply to Colin Campbell from comment #12)
> > The logic in C4::Circulation is that causes are returned in Uppercase and
> > data associated with causes are in lower case (In some cases the data is
> > still appearing as hash elemrnts of the uppercase entry but in these cases
> > the case distinction holds) Its a godawful design - but by wrapping the call
> > in a rtn that drops any lowercase "pseudo" causes we can fix the bug in hand.
> 
> This is really awkward indeed :)
> I'd prefer to list all the available error codes and add a big warning to
> CanBookBeIssued to inform the devs that this white-list need to be updated
> as well.

Yes I think that the returns need a rethink, a bit of design and proper documentation. We should probably do that as a separate bug as the implications could be quite large. I did not try to address that in this patch but to address how Sip was handly the current api to fix the problems it was causing users
Comment 16 Nick Clemens 2016-11-22 03:55:35 UTC
I tried testing but this doesn't seem to repair the issue, I am still seeing a random return of one element from the hash, occasionally patron surname firstname or cardnumber
Comment 17 rkuiper 2017-03-03 21:42:19 UTC
Do we have any movement on this bug fix.  This is a privacy concern for our patrons.
Rhonda Kuiper
Comment 18 Colin Campbell 2017-03-30 15:16:23 UTC
Created attachment 61738 [details] [review]
Patch rebased

Patch rebased against master
Comment 19 Colin Campbell 2017-03-30 15:34:20 UTC
Have done some testing on the patch and while inelegant - it does suppress the random data elements. This bit of debug shows the nature of the problem:

The debug statements were in the wrapper the patch adds It outputs the keys found in the issuingimposible and needsconfirmation hashes (2 indicates needsconfirmation) and the keys "Remaining" in those hashs after sanitization


Mar 30 15:38:49 zazou koha_sip[28864]: Key 2:RESERVED
Mar 30 15:38:49 zazou koha_sip[28864]: Key 2:resfirstname
Mar 30 15:38:49 zazou koha_sip[28864]: Key 2:resreservedate
Mar 30 15:38:49 zazou koha_sip[28864]: Key 2:resbranchcode
Mar 30 15:38:49 zazou koha_sip[28864]: Key 2:ressurname
Mar 30 15:38:49 zazou koha_sip[28864]: Key 2:resborrowernumber
Mar 30 15:38:49 zazou koha_sip[28864]: Key 2:rescardnumber
Mar 30 15:38:49 zazou koha_sip[28864]: Remaining I:
Mar 30 15:38:49 zazou koha_sip[28864]: Remaining C:RESERVED

TBH reading the code of CanBookBeIssued is a bit dispiriting parameters have been tacked on that are used in one place and its logic is full of special (and not so special) cases. I'm sure it could be made clearer and more efficient as  befits such a central routine. I'm taking the liberty of reseting the status to Needs Signoff as some people are getting burned by this (some sites dont suffer because their syspreferences avoid setting of fields like the above). 
If testing remember to stop and restart the sipsever you are testing against after code changes as the sip server runs persistently unlike cgi processes
Comment 20 Nick Clemens 2017-03-31 10:43:07 UTC
Hi Colin,

with this patch I do get:

"AFItem is reserved for another patron upon return."

However, the checkout also succeeds and the item is issued to the borrower despite the hold.
Comment 21 Colin Campbell 2017-04-18 07:51:57 UTC
(In reply to Nick Clemens from comment #20)
> Hi Colin,
> 
> with this patch I do get:
> 
> "AFItem is reserved for another patron upon return."
> 
> However, the checkout also succeeds and the item is issued to the borrower
> despite the hold.

That should be governed by the system preference can you confirm how thats set
Comment 22 Nick Clemens 2017-05-10 10:54:04 UTC
(In reply to Colin Campbell from comment #21)
> That should be governed by the system preference can you confirm how thats
> set

Both prefs below are set to 'Don't Allow'
AllowItemsOnHoldCheckout
AllowItemsOnHoldCheckoutSCO

Before the patch, checkout is denied
After the patch, checkout is successful
Comment 23 Kyle M Hall 2017-06-13 17:38:38 UTC
Created attachment 64264 [details] [review]
Bug 15438: Stop leaking data into SIP screen message

The returns from C4::Circulation::CanBookBeIssued used
to be structured as a hashref of entries like
   REASON => {
       data => 'foo',
       moredata => 'bar',
   };
Some entries still are. But many are now
   REASON => 1,
   data   => 'foo',
   moredata => 'bar',

The sip Checkout routine still assumed the former, as it
reports any causes it was not aware of (to maintain support for
a changing api) The data fields could leak into the screen message
field of the response. e.g. the borrowernumber or surname of the
borrower who has a hold on an issued title. Some real messages were
getting obscured by this

This patch sanatizes the return from from CanBookBeIssued
by removing keys which are not all uppercase
It also fixes a case where the key's data element was used
for the screen message when we should use the key itself

Updated the documentation of CanBookBeIssued to flag up
the assumption re case and the fact that 3 elements rather
than two may be returned

The loop through the returned keys was a bit bogus
so we now explicitly jump out if noerror is unset
Comment 24 Kyle M Hall 2017-06-13 17:39:28 UTC
Created attachment 64265 [details] [review]
Bug 15438 - Checking out an on-hold item sends holder's borrowernumber in AF (screen message) field.

The returns from C4::Circulation::CanBookBeIssued used
to be structured as a hashref of entries like
   REASON => {
       data => 'foo',
       moredata => 'bar',
   };
Some entries still are. But many are now
   REASON => 1,
   data   => 'foo',
   moredata => 'bar',

The sip Checkout routine still assumed the former, as it
reports any causes it was not aware of (to maintain support for
a changing api) The data fields could leak into the screen message
field of the response. e.g. the borrowernumber or surname of the
borrower who has a hold on an issued title. Some real messages were
getting obscured by this

This patch sanatizes the return from from CanBookBeIssued
by removing keys which are not all uppercase
It also fixes a case where the key's data element was used
for the screen message when we should use the key itself

Updated the documentation of CanBookBeIssued to flag up
the assumption re case and the fact that 3 elements rather
than two may be returned

The loop through the returned keys was a bit bogus
so we now explicitly jump out if noerror is unset
Comment 25 Kyle M Hall 2017-06-13 17:40:44 UTC
Created attachment 64266 [details] [review]
Bug 15438 [Alternate Solution] - Checking out an on-hold item sends holder's borrowernumber in AF (screen message) field.

Description: Let's say that 'Holding Patron' puts a hold on title 'ASDF'. If 'SIP  Patron' then tries to check out ASDF, Holding Patron's card number appears in the AF (i.e. Screen Message) field. This only occurs if the hold has *not* yet been finalized -- If ASDF is waiting for Holding Patron, the screen message will read "Item is on hold shelf for another patron."

The screen message containing only the Holding Patron's borrowernumber is confusing because a) It contains no context as to the nature of the number showing on the screen b) SIP devices work with borrower card numbers, so the number being returned has the wrong context. Furthermore, we're leaking patron information in a place where we probably would never check.

Replicating the problem:

Set up instance with two patrons, as well as a bib/item to put on hold/check out.
Make sure that circ rules allow holds.
Set up SIPconfig.xml to allow checkouts on the IP/port of your choice.
Start SIP2. Make sure that authentication, checkin and check out work for the 'SIP Patron'.
Ensure that AllowItemsOnHoldCheckout is set to "Don't Allow".

In the steps to replicate, the Title/barcode of the item on hold/being checked out will be 'asdf'. The Holding Patron will be referred to as 'holder' and the checkout patron will be referred to as 'sipper'. Let's say that sipper's borrowernumber is 52.

1/ Place a biblio level hold for asdf, with holder as the holding patron.
2/ Start `sudo tail -f /var/log/syslog | grep sip`
3/ Attempt to check out asdf to sipper. You will see the sip checkout message '11...' followed by a '120...|AF52|...' sip checkout response. This indicates that the checkout has failed (which we would expect), and that the screen message is '52'.

Example using ./misc/sip_cli_emulator.pl

$ ./misc/sip_cli_emulator.pl -a 127.0.0.1 -p 6001 -su staff -sp staff -l CPL --patron 23529001223636
--password 1234 --item 1234 -m checkout
Attempting socket connection to 127.0.0.1:6001...connected!
SEND: 9300CNstaff|COstaff|CPCPL|
READ: 941

Trying 'checkout'
SEND: 11YN20151229    05321120151229    053211AOCPL|AA23529001223636|AB1234|ACstaff|AD1234|BON|BIN|
READ: 120NUN20151229    053211AOCPL|AA23529001223636|AB1234|AJTheories of human development :|AH|AF52|BLY|BV5.00|BHUSD|BT06|
Comment 26 Nick Clemens 2017-06-13 18:18:16 UTC
There was a fair bit of discussion here that underlying code needs a rewrite - between the two options here I think I would vote for the Alternate, simply because it fixes the problem without locking us into the Capitalization, less new code on top of code the needs rewritten.

Obsoleting the original patch in favor of the new, I appreciate everyone's work here and would love to see this one move ahead quickly.