We just had a similar and previously unobserved issue with our RFID system (3M) -- checkout was delayed by up to 50 seconds. After a lot of testing and considering every possible issue with our data, such as date formats, duplicate userid, lack of cardnumbers, etc. and investigating every possible connection problem between the selfcheck machines and the server, we finally figured out the cause: 1) *some* of our patrons had an expiration date of 9999 and Koha took ca. 50 seconds to run date calculations on the expiration date... after lowering the expiration dates, the problem was solved. 2) this did not turn out to be the problem but may help to be aware of: the timeout period on our sip devices was set to 15 seconds--with Koha taking over 50 seconds to calculate the expiration date, the transaction failed. It was only after increasing the timeout period to one minute that we noticed that the transaction actually completed. In retrospect, it's all obvious. It would be good to store such experiences and resolutions somewhere so that the community can do a search and find solutions quickly. Sebastian -- Sebastian Hierl, Ph.D. Drue Heinz Librarian, Arthur & Janet C. Ross Library American Academy in Rome Via Angelo Masina 5 00153 Rome Italy T: +39 06 5846 417 F: +39 06 5810 788 On Fri, May 8, 2015 at 3:13 AM, Justin <jsslade@hotmail.com> wrote:
I have a problem I hoping someone has come across before and able to point me in the right direction.
I have setup the SIP server on Koha and the connection works well along with the SIP 93, 99, 63 & 09 messages however when I try and send an 11 SIP checkout request the connection drops. I am testing with the 3M Emulator.
May 8 09:06:46 kohadebian koha_sip[3798]: Configuration::find_service: Trying 6001/tcp May 8 09:06:46 kohadebian koha_sip[3798]: Configuration::find_service: Trying *:6001/tcp May 8 09:06:46 kohadebian koha_sip[3798]: Configuration::find_service: Trying 192.168.1.16:6001/tcp May 8 09:06:46 kohadebian koha_sip[3798]: raw_transport: timeout is 60 May 8 09:06:47 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '9300CNtestpatron|COtestpassword|CPkohalibrary|' May 8 09:06:47 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '9300CNtestpatron|COtestpassword|CPkohalibrary' May 8 09:06:47 kohadebian koha_sip[3798]: read_SIP_packet, trimmed 1 character(s) (after chomps). May 8 09:06:47 kohadebian koha_sip[3798]: INPUT MSG: '9300CNtestpatron|COtestpassword|CPkohalibrary' May 8 09:06:47 kohadebian koha_sip[3798]: Sip::MsgType::new('Sip::MsgType', '9300CNtest...', '93'): seq.no '0', protocol 2 May 8 09:06:47 kohadebian koha_sip[3798]: Sip::MsgType::_initialize('Login', '00CNtestpatron|COtestpassword|CPkohalibrary', 'A1A1', '2', ...) May 8 09:06:47 kohadebian koha_sip[3798]: Successful login/auth for 'testpatron' of 'CPL' May 8 09:06:47 kohadebian koha_sip[3798]: login_core: $VAR1 = 'ILS'; May 8 09:06:47 kohadebian koha_sip[3798]: new ILS 'CPL' May 8 09:06:47 kohadebian koha_sip[3798]: OUTPUT MSG: '941' May 8 09:06:47 kohadebian koha_sip[3798]: raw_transport: uname/inst: 'testpatron/CPL' May 8 09:06:47 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '9900652.00' May 8 09:06:47 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '9900652.00' May 8 09:06:47 kohadebian koha_sip[3798]: INPUT MSG: '9900652.00' May 8 09:06:47 kohadebian koha_sip[3798]: Sip::MsgType::new('Sip::MsgType', '9900652.00...', '99'): seq.no '0', protocol 2 May 8 09:06:47 kohadebian koha_sip[3798]: Sip::MsgType::_initialize('SC Status', '00652.00', 'CA3A4', '8', ...) May 8 09:06:47 kohadebian koha_sip[3798]: OUTPUT MSG: '98YYYYNN02500520150508 0906472.00AOCPL|BXYYYYYYYYYYYNYYYY|' May 8 09:06:50 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '6300120150508 090704 AOCPL|AAC50085416D|' May 8 09:06:50 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '6300120150508 090704 AOCPL|AAC50085416D' May 8 09:06:50 kohadebian koha_sip[3798]: read_SIP_packet, trimmed 1 character(s) (after chomps). May 8 09:06:50 kohadebian koha_sip[3798]: INPUT MSG: '6300120150508 090704 AOCPL|AAC50085416D' May 8 09:06:50 kohadebian koha_sip[3798]: Sip::MsgType::new('Sip::MsgType', '6300120150...', '63'): seq.no '0', protocol 2 May 8 09:06:50 kohadebian koha_sip[3798]: Sip::MsgType::_initialize('Patron Info', '00120150508 090704 AOCPL|AAC50085416D', 'A3A18A10', '31', ...) May 8 09:06:50 kohadebian koha_sip[3798]: new ILS::Patron(C50085416D): found patron 'C50085416D' May 8 09:06:50 kohadebian koha_sip[3798]: patron_status_string: C50085416D charge_ok: 1 May 8 09:06:50 kohadebian koha_sip[3798]: OUTPUT MSG: '64 00120150508 090650000000000000000000000000AOCPL|AAC50085416D|AEKoha Patron|BLY|CC5|BD10 Hall Road Sydney Australia|BEtest@koha.com|BF0061 400 400 400|PB19670817|PCPT|PIY|AFGreetings from Koha. |' May 8 09:06:52 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '09N20150508 09070720150508 090707AP|AOCPL|ABA50136619B|AC|CH|BIN|' May 8 09:06:52 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '09N20150508 09070720150508 090707AP|AOCPL|ABA50136619B|AC|CH|BIN' May 8 09:06:52 kohadebian koha_sip[3798]: read_SIP_packet, trimmed 1 character(s) (after chomps). May 8 09:06:52 kohadebian koha_sip[3798]: INPUT MSG: '09N20150508 09070720150508 090707AP|AOCPL|ABA50136619B|AC|CH|BIN' May 8 09:06:52 kohadebian koha_sip[3798]: Sip::MsgType::new('Sip::MsgType', '09N2015050...', '09'): seq.no '0', protocol 2 May 8 09:06:52 kohadebian koha_sip[3798]: Sip::MsgType::_initialize('Checkin', 'N20150508 09070720150508 090707AP|AOCPL|ABA50136619B|AC|CH|BIN', 'CA18A18', '37', ...) May 8 09:06:53 kohadebian koha_sip[3798]: new ILS::Item('A50136619B'): found with title '100 New Zealand short stories 4 /' May 8 09:06:53 kohadebian koha_sip[3798]: OUTPUT MSG: '100YNY20150508 090653AOCPL|ABA50136619B|AQsp3|AJ100 New Zealand short stories 4 /|CS823/.0108993|CV04|AFItem not checked out|' May 8 09:06:58 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '3520150508 090712AOCPL|AAC50085416D|' May 8 09:06:58 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '3520150508 090712AOCPL|AAC50085416D' May 8 09:06:58 kohadebian koha_sip[3798]: read_SIP_packet, trimmed 1 character(s) (after chomps). May 8 09:06:58 kohadebian koha_sip[3798]: INPUT MSG: '3520150508 090712AOCPL|AAC50085416D' May 8 09:06:58 kohadebian koha_sip[3798]: Sip::MsgType::new('Sip::MsgType', '3520150508...', '35'): seq.no '0', protocol 2 May 8 09:06:58 kohadebian koha_sip[3798]: Sip::MsgType::_initialize('End Patron Session', '20150508 090712AOCPL|AAC50085416D', 'A18', '18', ...) May 8 09:06:58 kohadebian koha_sip[3798]: OUTPUT MSG: '36Y20150508 090658AOCPL|AAC50085416D|AFThank you !|' May 8 09:06:59 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '6300120150508 090714 AOCPL|AAC50085416D|' May 8 09:06:59 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '6300120150508 090714 AOCPL|AAC50085416D' May 8 09:06:59 kohadebian koha_sip[3798]: read_SIP_packet, trimmed 1 character(s) (after chomps). May 8 09:06:59 kohadebian koha_sip[3798]: INPUT MSG: '6300120150508 090714 AOCPL|AAC50085416D' May 8 09:06:59 kohadebian koha_sip[3798]: Sip::MsgType::new('Sip::MsgType', '6300120150...', '63'): seq.no '0', protocol 2 May 8 09:06:59 kohadebian koha_sip[3798]: Sip::MsgType::_initialize('Patron Info', '00120150508 090714 AOCPL|AAC50085416D', 'A3A18A10', '31', ...) May 8 09:06:59 kohadebian koha_sip[3798]: new ILS::Patron(C50085416D): found patron 'C50085416D' May 8 09:06:59 kohadebian koha_sip[3798]: patron_status_string: C50085416D charge_ok: 1 May 8 09:06:59 kohadebian koha_sip[3798]: OUTPUT MSG: '64 00120150508 090659000000000000000000000000AOCPL|AAC50085416D|AEKoha Patron|BLY|CC5|BD10 Hall Road Sydney Australia|BEtest@koha.com|BF0061 400 400 400|PB19670817|PCPT|PIY|AFGreetings from Koha. |' May 8 09:07:02 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '11YN20150508 09071720150508 090717AOCPL|AAC50085416D|ABA50136619B|AC|' May 8 09:07:02 kohadebian koha_sip[3798]: read_SIP_packet, INPUT MSG: '11YN20150508 09071720150508 090717AOCPL|AAC50085416D|ABA50136619B|AC' May 8 09:07:02 kohadebian koha_sip[3798]: read_SIP_packet, trimmed 1 character(s) (after chomps). May 8 09:07:02 kohadebian koha_sip[3798]: INPUT MSG: '11YN20150508 09071720150508 090717AOCPL|AAC50085416D|ABA50136619B|AC' May 8 09:07:02 kohadebian koha_sip[3798]: Sip::MsgType::new('Sip::MsgType', '11YN201505...', '11'): seq.no '0', protocol 2 May 8 09:07:02 kohadebian koha_sip[3798]: Sip::MsgType::_initialize('Checkout', 'YN20150508 09071720150508 090717AOCPL|AAC50085416D|ABA50136619B|AC', 'CCA18A18', '38', ...)
I have also tried testing in the root terminal and all messages work except the 11 message which returns:
Connection closed by foreign host.
Any help would be greatly appreciated.
Justin
_______________________________________________ Koha mailing list http://koha-community.org Koha@lists.katipo.co.nz https://lists.katipo.co.nz/mailman/listinfo/koha