[OPEN-ILS-DEV] SIP2 hard disconnect after particular series of messages

[Uhlman, Brandon EDUC:EX]

Hi, all.

I find myself dealing with a particularly perplexing problem.

One of our SIP2 vendors is experiencing a problem when connecting to our
Evergreen system where the SIP client detects a disconnection from the
server, and ends the transaction without warning, spitting out the
receipt almost right away.

We were able to replicate the disconnection by sending a message 64
(patron information request) immediately after sending a message 12, as
the particular self-check client does, with no discernable pause. A
natural human pause of about a second causes the error not to be issued,
which is why we were never able to reproduce the problem in testing
before seeing it in the logging.

02:56:58 PM  Open(): Opening connection to xxx.yyy.zzz.aa on port abcd
02:57:11 PM  WritePacket(): 9300CNusername|COpassword|AY0AZF6B2<0D>
02:57:11 PM  ReadPacket(): 941AY0AZFDFD<0D>
02:57:19 PM  WritePacket(): 9909992.00AY1AZFC8D<0D>
02:57:19 PM  ReadPacket(): 98YYYYNN60000320100608
1457342.00AOBPR|BXYYYYYYYYYNYNNNYN|AY1AZEE98<0D>
02:57:32 PM  WritePacket(): 63   20100608    145723
AOBPR|AA25180123456789|AY2AZF397<0D>
02:57:32 PM  ReadPacket(): 64  Y           20100608
145747000000020002000000000000AA25180123456789|AEBrandon Wade
Uhlman|BHUSD|BV10.00|BD My Home Address Lillooet  BC CA V0K
1V0|BEbrandon.uhlman at gov.bc.ca|AQBLP|BLY|PB1981-08-29|PCPL Circ +Full
Cat|PIUnfiltered|AFOK|AOBPR|AY2AZB426<0D>
02:58:10 PM  WritePacket(): 11NN20100608    14574720100622
145747AO|AA25180000031394|AB33294001302611|AC|AY4AZED73<0D>
02:58:12 PM  ReadPacket(): 121NYN20100608
145827AOBPR|AA25180000031394|AB33294001302611|AJThe Muppet Christmas
carol|AH2010-06-15 23:59:59|CK005|AY4AZDF2A<0D>
02:58:12 PM  WritePacket(): 63   20100608    145812
AOBPR|AA25180123456789|AY5AZF395<0D>
02:58:13 PM  ReadPacket(): No response
02:58:13 PM  WritePacket(): 63   20100608    145812
AOBPR|AA25180123456789|AY5AZF395<0D>
02:58:13 PM  Read(): Read error 64, The specified network name is no
longer available
02:58:13 PM  ReadPacket(): No response
02:58:13 PM  Read(): Read error 64, The specified network name is no
longer available
02:58:13 PM  Write(): Write error 64, The specified network name is no
longer available
02:58:13 PM  Read(): Read error 64, The specified network name is no
longer available
02:58:13 PM  Write(): Write error 64, The specified network name is no
longer available
02:58:13 PM  TSIPCommand::Execute(): Command failed
02:58:13 PM  TSIPCommand::Execute(): Communication failure, closing
network connection...
02:58:13 PM  Close(): Closing connection...
02:58:13 PM  SetStatus(): New session status is Busy
02:58:13 PM  Socket: Connection dropped
02:58:13 PM  SetStatus(): New session status is Inactive

I tried the naive solution of forcing the patron information request
(message 64) to always pause before executing using sleep, select(undef,
undef, undef, time) and Time::HiRes->usleep(); sleep caused a disconnect
always, and usleep had no effect.

I am uncertain what next steps to try. Anybody out in the big world with
any suggestions?

Brandon