Bugzilla – Attachment 72087 Details for
Bug 20270
SIP2 Connection Issue
Home
|
New
|
Browse
|
Search
|
[?]
|
Reports
|
Help
|
New Account
|
Log In
[x]
|
Forgot Password
Login:
[x]
SIP Log
SIP.log (text/plain), 45.05 KB, created by
Anil Tiwari
on 2018-02-22 13:39:14 UTC
(
hide
)
Description:
SIP Log
Filename:
MIME Type:
Creator:
Anil Tiwari
Created:
2018-02-22 13:39:14 UTC
Size:
45.05 KB
patch
obsolete
>2018-02-22 18:06:56,904 INFO [primary] SipLogger - ***** SIP Start ***** >2018-02-22 18:06:56,956 INFO [primary] SipCirculationProvider - Using transport provider: MMM.LibrarySystems.Circulation.Transports.TcpTransportProvider >2018-02-22 18:06:56,960 INFO [primary] SipCirculationProvider - Using message formatter: MMM.LibrarySystems.Circulation.SIP.Protocol.MessageFormatter >2018-02-22 18:07:01,542 INFO [primary] App - Assembly: PresentationFramework-SystemXml, 4.0.30319.18408; assembly=4.0.0.0 >2018-02-22 18:07:05,384 INFO [primary] App - Assembly: PresentationFramework-SystemData, 4.0.30319.18408; assembly=4.0.0.0 >2018-02-22 18:07:05,605 INFO [12] App - Assembly: System.ServiceModel.Channels, 4.0.30319.18408 built by: FX451RTMGREL; assembly=4.0.0.0 >2018-02-22 18:07:05,659 INFO [12] App - Assembly: System.IdentityModel, 4.0.30319.18408 built by: FX451RTMGREL; assembly=4.0.0.0 >2018-02-22 18:07:05,630 INFO [14] TcpTransportProvider - TCP: Opening connection to: 192.168.200.12:6001 >2018-02-22 18:07:05,998 INFO [22] App - Assembly: System.Numerics, 4.0.30319.18408 built by: FX451RTMGREL; assembly=4.0.0.0 >2018-02-22 18:07:06,003 INFO [22] App - Assembly: System.Data.OracleClient, 4.0.30319.18408 built by: FX451RTMGREL; assembly=4.0.0.0 >2018-02-22 18:07:10,677 INFO [24] SipCirculationProvider - Opened SIP circulation provider with address: 192.168.200.12:6001 >2018-02-22 18:07:10,750 INFO [24] SipCirculationProvider - Processing request MMM.LibrarySystems.Circulation.SIP.Messages.LoginRequest and response MMM.LibrarySystems.Circulation.SIP.Messages.LoginResponse >2018-02-22 18:07:10,917 INFO [24] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:07:11,043 TRACE [24] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY1AZF685\r >2018-02-22 18:07:11,100 TRACE [ 5] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 31 41 5A 46 36 38 35 0D >2018-02-22 18:07:11,103 TRACE [ 5] TcpTransportProvider - TCP: 35 bytes written; 40 ms >2018-02-22 18:07:11,373 INFO [31] App - Assembly: Microsoft.CSharp, 4.0.30319.18408; assembly=4.0.0.0 >2018-02-22 18:07:11,424 INFO [31] App - Assembly: System.Dynamic, 4.0.30319.18408; assembly=4.0.0.0 >2018-02-22 18:07:16,822 DEBUG [primary] App - Startup duration = 41.7s >2018-02-22 18:07:31,357 TRACE [12] TcpTransportProvider - TCP: read >2018-02-22 18:07:31,357 TRACE [12] TcpTransportProvider - TCP: 0 bytes read; 20234 ms >2018-02-22 18:07:31,357 DEBUG [12] SipCirculationProvider - Duration of operation: 20564 ms >2018-02-22 18:07:32,367 WARN [ 5] SipCirculationProvider - Retry #1 >2018-02-22 18:07:32,367 INFO [ 5] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:07:32,367 TRACE [ 5] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY1AZF685\r >2018-02-22 18:07:32,367 TRACE [21] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 31 41 5A 46 36 38 35 0D >2018-02-22 18:07:32,367 TRACE [21] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:07:52,874 TRACE [24] TcpTransportProvider - TCP: read >2018-02-22 18:07:52,874 TRACE [24] TcpTransportProvider - TCP: 0 bytes read; 20507 ms >2018-02-22 18:07:52,874 DEBUG [24] SipCirculationProvider - Duration of operation: 20508 ms >2018-02-22 18:07:53,874 WARN [14] SipCirculationProvider - Retry #2 >2018-02-22 18:07:53,874 INFO [14] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:07:53,874 TRACE [14] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY1AZF685\r >2018-02-22 18:07:53,874 TRACE [22] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 31 41 5A 46 36 38 35 0D >2018-02-22 18:07:53,874 TRACE [22] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:08:14,383 TRACE [ 5] TcpTransportProvider - TCP: read >2018-02-22 18:08:14,383 TRACE [ 5] TcpTransportProvider - TCP: 0 bytes read; 20509 ms >2018-02-22 18:08:14,383 DEBUG [ 5] SipCirculationProvider - Duration of operation: 20510 ms >2018-02-22 18:08:14,393 INFO [ 5] TcpTransportProvider - TCP: Closing connection to: 192.168.200.12:6001 >2018-02-22 18:08:14,393 INFO [ 5] SipCirculationProvider - Closed SIP circulation provider from address: 192.168.200.12:6001 >2018-02-22 18:08:14,625 INFO [primary] App - Assembly: PresentationFramework-SystemXmlLinq, 4.0.30319.18408; assembly=4.0.0.0 >2018-02-22 18:08:29,505 INFO [24] SipCirculationProvider - Resetting from error state >2018-02-22 18:08:29,505 INFO [24] TcpTransportProvider - TCP: Opening connection to: 192.168.200.12:6001 >2018-02-22 18:08:29,505 INFO [28] SipCirculationProvider - Opened SIP circulation provider with address: 192.168.200.12:6001 >2018-02-22 18:08:29,505 INFO [28] SipCirculationProvider - Processing request MMM.LibrarySystems.Circulation.SIP.Messages.LoginRequest and response MMM.LibrarySystems.Circulation.SIP.Messages.LoginResponse >2018-02-22 18:08:29,515 INFO [28] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:08:29,515 TRACE [28] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY2AZF684\r >2018-02-22 18:08:29,515 TRACE [36] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 32 41 5A 46 36 38 34 0D >2018-02-22 18:08:29,515 TRACE [36] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:08:50,012 TRACE [24] TcpTransportProvider - TCP: read >2018-02-22 18:08:50,012 TRACE [24] TcpTransportProvider - TCP: 0 bytes read; 20497 ms >2018-02-22 18:08:50,012 DEBUG [24] SipCirculationProvider - Duration of operation: 20501 ms >2018-02-22 18:08:51,022 WARN [24] SipCirculationProvider - Retry #1 >2018-02-22 18:08:51,022 INFO [24] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:08:51,032 TRACE [24] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY2AZF684\r >2018-02-22 18:08:51,032 TRACE [ 5] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 32 41 5A 46 36 38 34 0D >2018-02-22 18:08:51,032 TRACE [ 5] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:09:11,530 TRACE [14] TcpTransportProvider - TCP: read >2018-02-22 18:09:11,530 TRACE [14] TcpTransportProvider - TCP: 0 bytes read; 20498 ms >2018-02-22 18:09:11,530 DEBUG [14] SipCirculationProvider - Duration of operation: 20509 ms >2018-02-22 18:09:12,530 WARN [35] SipCirculationProvider - Retry #2 >2018-02-22 18:09:12,530 INFO [35] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:09:12,530 TRACE [35] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY2AZF684\r >2018-02-22 18:09:12,530 TRACE [36] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 32 41 5A 46 36 38 34 0D >2018-02-22 18:09:12,530 TRACE [36] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:09:33,034 TRACE [ 4] TcpTransportProvider - TCP: read >2018-02-22 18:09:33,034 TRACE [ 4] TcpTransportProvider - TCP: 0 bytes read; 20504 ms >2018-02-22 18:09:33,034 DEBUG [ 4] SipCirculationProvider - Duration of operation: 20505 ms >2018-02-22 18:09:33,034 INFO [ 4] TcpTransportProvider - TCP: Closing connection to: 192.168.200.12:6001 >2018-02-22 18:09:33,034 INFO [ 4] SipCirculationProvider - Closed SIP circulation provider from address: 192.168.200.12:6001 >2018-02-22 18:10:33,183 INFO [25] SipCirculationProvider - Resetting from error state >2018-02-22 18:10:33,183 INFO [25] TcpTransportProvider - TCP: Opening connection to: 192.168.200.12:6001 >2018-02-22 18:10:33,183 INFO [26] SipCirculationProvider - Opened SIP circulation provider with address: 192.168.200.12:6001 >2018-02-22 18:10:33,183 INFO [26] SipCirculationProvider - Processing request MMM.LibrarySystems.Circulation.SIP.Messages.LoginRequest and response MMM.LibrarySystems.Circulation.SIP.Messages.LoginResponse >2018-02-22 18:10:33,203 INFO [26] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:10:33,203 TRACE [26] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY3AZF683\r >2018-02-22 18:10:33,203 TRACE [25] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 33 41 5A 46 36 38 33 0D >2018-02-22 18:10:33,203 TRACE [25] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:10:36,713 TRACE [23] TcpTransportProvider - TCP: read 39 34 31 41 59 33 41 5A 46 44 46 41 0D 0A >2018-02-22 18:10:36,713 TRACE [23] TcpTransportProvider - TCP: 14 bytes read; 3510 ms >2018-02-22 18:10:36,723 TRACE [23] MessageFormatter - Parsing: 941AY3AZFDFA >2018-02-22 18:10:36,743 INFO [23] MessageFormatter - Parsed: [94] Login Response {ok = 1} >2018-02-22 18:10:36,763 DEBUG [23] SipCirculationProvider - Duration of operation: 3578 ms >2018-02-22 18:10:36,793 INFO [23] MessageFormatter - Formatting: [99] SC Status {status code = UnitIsOk, max print width = 30, protocol version = "2.00"} >2018-02-22 18:10:36,793 TRACE [23] MessageFormatter - Formatted: 9900302.00AY4AZFCA2\r >2018-02-22 18:10:36,793 TRACE [22] TcpTransportProvider - TCP: write 39 39 30 30 33 30 32 2E 30 30 41 59 34 41 5A 46 43 41 32 0D >2018-02-22 18:10:36,793 TRACE [22] TcpTransportProvider - TCP: 20 bytes written; 0 ms >2018-02-22 18:10:36,793 TRACE [22] MessageFormatter - Additional data is required to parse message: \n >2018-02-22 18:10:36,803 TRACE [22] TcpTransportProvider - TCP: read 39 38 59 59 59 59 4E 4E 31 30 30 30 30 35 32 30 31 38 30 32 32 32 20 20 20 20 31 38 31 30 35 31 32 2E 30 30 41 4F 4D 41 49 4E 7C 42 58 59 59 59 59 59 59 59 59 59 59 59 4E 59 59 59 59 7C 41 59 34 41 5A 45 45 33 33 0D 0A >2018-02-22 18:10:36,803 TRACE [22] TcpTransportProvider - TCP: 73 bytes read; 10 ms >2018-02-22 18:10:36,813 TRACE [22] MessageFormatter - Skipping 1 extra character(s) in data: \n >2018-02-22 18:10:36,813 TRACE [22] MessageFormatter - Parsing: 98YYYYNN10000520180222 1810512.00AOMAIN|BXYYYYYYYYYYYNYYYY|AY4AZEE33 >2018-02-22 18:10:36,833 INFO [22] MessageFormatter - Parsed: [98] ACS Status {on-line status = True, checkin ok = True, checkout ok = True, ACS renewal policy = True, status update ok = False, off-line ok = False, timeout period = 100, retries allowed = 5, date time sync = 2018-02-22 18:10:51, protocol version = "2.00", [AO] institution id = "MAIN", [BX] supported messages = PatronStatus, CheckOut, CheckIn, BlockPatron, ScAcsStatus, RequestResend, Login, PatronInformation, EndPatronSession, FeePaid, ItemInformation, PatronEnable, Hold, Renew, RenewAll} >2018-02-22 18:10:36,833 DEBUG [22] SipCirculationProvider - Duration of operation: 46 ms >2018-02-22 18:10:36,860 INFO [22] SipCirculationProvider - Supported message flags changed to: PatronStatus, CheckOut, CheckIn, BlockPatron, ScAcsStatus, RequestResend, Login, PatronInformation, EndPatronSession, FeePaid, ItemInformation, PatronEnable, Hold, Renew, RenewAll >2018-02-22 18:10:36,860 INFO [22] SipCirculationProvider - Permission flags changed to: CheckInAllowed, CheckOutAllowed, RenewalAllowed >2018-02-22 18:11:58,234 INFO [primary] App - Exiting >2018-02-22 18:11:58,461 INFO [22] MessageFormatter - Formatting: [99] SC Status {status code = ShuttingDown, max print width = 30, protocol version = "2.00"} >2018-02-22 18:11:58,466 TRACE [22] MessageFormatter - Formatted: 9920302.00AY5AZFC9F\r >2018-02-22 18:11:58,466 TRACE [56] TcpTransportProvider - TCP: write 39 39 32 30 33 30 32 2E 30 30 41 59 35 41 5A 46 43 39 46 0D >2018-02-22 18:11:58,466 TRACE [56] TcpTransportProvider - TCP: 20 bytes written; 0 ms >2018-02-22 18:11:58,466 TRACE [56] MessageFormatter - Additional data is required to parse message: \n >2018-02-22 18:11:58,476 TRACE [56] TcpTransportProvider - TCP: read 39 38 59 59 59 59 4E 4E 31 30 30 30 30 35 32 30 31 38 30 32 32 32 20 20 20 20 31 38 31 32 31 33 32 2E 30 30 41 4F 4D 41 49 4E 7C 42 58 59 59 59 59 59 59 59 59 59 59 59 4E 59 59 59 59 7C 41 59 35 41 5A 45 45 33 32 0D 0A >2018-02-22 18:11:58,476 TRACE [56] TcpTransportProvider - TCP: 73 bytes read; 10 ms >2018-02-22 18:11:58,476 TRACE [56] MessageFormatter - Skipping 1 extra character(s) in data: \n >2018-02-22 18:11:58,476 TRACE [56] MessageFormatter - Parsing: 98YYYYNN10000520180222 1812132.00AOMAIN|BXYYYYYYYYYYYNYYYY|AY5AZEE32 >2018-02-22 18:11:58,486 INFO [56] MessageFormatter - Parsed: [98] ACS Status {on-line status = True, checkin ok = True, checkout ok = True, ACS renewal policy = True, status update ok = False, off-line ok = False, timeout period = 100, retries allowed = 5, date time sync = 2018-02-22 18:12:13, protocol version = "2.00", [AO] institution id = "MAIN", [BX] supported messages = PatronStatus, CheckOut, CheckIn, BlockPatron, ScAcsStatus, RequestResend, Login, PatronInformation, EndPatronSession, FeePaid, ItemInformation, PatronEnable, Hold, Renew, RenewAll} >2018-02-22 18:11:58,486 DEBUG [56] SipCirculationProvider - Duration of operation: 30 ms >2018-02-22 18:11:58,486 INFO [56] TcpTransportProvider - TCP: Closing connection to: 192.168.200.12:6001 >2018-02-22 18:11:58,486 INFO [56] SipCirculationProvider - Closed SIP circulation provider from address: 192.168.200.12:6001 >2018-02-22 18:11:59,348 INFO [primary] App - End >2018-02-22 18:14:06,600 INFO [primary] SipLogger - ***** SIP Start ***** >2018-02-22 18:14:06,646 INFO [primary] SipCirculationProvider - Using transport provider: MMM.LibrarySystems.Circulation.Transports.TcpTransportProvider >2018-02-22 18:14:06,648 INFO [primary] SipCirculationProvider - Using message formatter: MMM.LibrarySystems.Circulation.SIP.Protocol.MessageFormatter >2018-02-22 18:14:11,051 INFO [primary] App - Assembly: PresentationFramework-SystemXml, 4.0.30319.18408; assembly=4.0.0.0 >2018-02-22 18:14:14,542 INFO [primary] App - Assembly: PresentationFramework-SystemData, 4.0.30319.18408; assembly=4.0.0.0 >2018-02-22 18:14:14,867 INFO [19] TcpTransportProvider - TCP: Opening connection to: 192.168.200.12:6001 >2018-02-22 18:14:15,033 INFO [13] SipCirculationProvider - Opened SIP circulation provider with address: 192.168.200.12:6001 >2018-02-22 18:14:15,082 INFO [ 3] App - Assembly: System.ServiceModel.Channels, 4.0.30319.18408 built by: FX451RTMGREL; assembly=4.0.0.0 >2018-02-22 18:14:15,247 INFO [ 3] App - Assembly: System.IdentityModel, 4.0.30319.18408 built by: FX451RTMGREL; assembly=4.0.0.0 >2018-02-22 18:14:15,273 INFO [13] SipCirculationProvider - Processing request MMM.LibrarySystems.Circulation.SIP.Messages.LoginRequest and response MMM.LibrarySystems.Circulation.SIP.Messages.LoginResponse >2018-02-22 18:14:15,389 INFO [20] App - Assembly: System.Numerics, 4.0.30319.18408 built by: FX451RTMGREL; assembly=4.0.0.0 >2018-02-22 18:14:15,415 INFO [20] App - Assembly: System.Data.OracleClient, 4.0.30319.18408 built by: FX451RTMGREL; assembly=4.0.0.0 >2018-02-22 18:14:15,516 INFO [13] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:14:15,590 TRACE [13] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY1AZF685\r >2018-02-22 18:14:15,677 TRACE [19] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 31 41 5A 46 36 38 35 0D >2018-02-22 18:14:15,692 TRACE [19] TcpTransportProvider - TCP: 35 bytes written; 79 ms >2018-02-22 18:14:21,913 INFO [33] App - Assembly: Microsoft.CSharp, 4.0.30319.18408; assembly=4.0.0.0 >2018-02-22 18:14:21,943 INFO [33] App - Assembly: System.Dynamic, 4.0.30319.18408; assembly=4.0.0.0 >2018-02-22 18:14:24,522 DEBUG [primary] App - Startup duration = 38.8s >2018-02-22 18:14:41,860 TRACE [18] TcpTransportProvider - TCP: read >2018-02-22 18:14:41,860 TRACE [18] TcpTransportProvider - TCP: 0 bytes read; 26141 ms >2018-02-22 18:14:41,860 DEBUG [18] SipCirculationProvider - Duration of operation: 26454 ms >2018-02-22 18:14:42,870 WARN [ 3] SipCirculationProvider - Retry #1 >2018-02-22 18:14:42,870 INFO [ 3] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:14:42,870 TRACE [ 3] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY1AZF685\r >2018-02-22 18:14:42,870 TRACE [24] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 31 41 5A 46 36 38 35 0D >2018-02-22 18:14:42,870 TRACE [24] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:14:53,260 INFO [primary] App - Assembly: PresentationFramework-SystemXmlLinq, 4.0.30319.18408; assembly=4.0.0.0 >2018-02-22 18:14:56,672 INFO [primary] App - Assembly: Accessibility, 4.0.30319.18408 built by: FX451RTMGREL; assembly=4.0.0.0 >2018-02-22 18:14:59,462 INFO [primary] App - Assembly: SelfCheck.Configurator, 1.70.0.20; assembly=1.70.0.0 >2018-02-22 18:15:03,372 TRACE [ 4] TcpTransportProvider - TCP: read >2018-02-22 18:15:03,372 TRACE [ 4] TcpTransportProvider - TCP: 0 bytes read; 20502 ms >2018-02-22 18:15:03,372 DEBUG [ 4] SipCirculationProvider - Duration of operation: 20502 ms >2018-02-22 18:15:04,382 WARN [24] SipCirculationProvider - Retry #2 >2018-02-22 18:15:04,382 INFO [24] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:15:04,392 TRACE [24] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY1AZF685\r >2018-02-22 18:15:04,392 TRACE [ 3] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 31 41 5A 46 36 38 35 0D >2018-02-22 18:15:04,392 TRACE [ 3] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:15:24,902 TRACE [18] TcpTransportProvider - TCP: read >2018-02-22 18:15:24,902 TRACE [18] TcpTransportProvider - TCP: 0 bytes read; 20510 ms >2018-02-22 18:15:24,902 DEBUG [18] SipCirculationProvider - Duration of operation: 20522 ms >2018-02-22 18:15:24,912 INFO [18] TcpTransportProvider - TCP: Closing connection to: 192.168.200.12:6001 >2018-02-22 18:15:24,912 INFO [18] SipCirculationProvider - Closed SIP circulation provider from address: 192.168.200.12:6001 >2018-02-22 18:15:39,981 INFO [ 5] SipCirculationProvider - Resetting from error state >2018-02-22 18:15:39,981 INFO [ 5] TcpTransportProvider - TCP: Opening connection to: 192.168.200.12:6001 >2018-02-22 18:15:39,981 INFO [32] SipCirculationProvider - Opened SIP circulation provider with address: 192.168.200.12:6001 >2018-02-22 18:15:39,981 INFO [32] SipCirculationProvider - Processing request MMM.LibrarySystems.Circulation.SIP.Messages.LoginRequest and response MMM.LibrarySystems.Circulation.SIP.Messages.LoginResponse >2018-02-22 18:15:39,981 INFO [32] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:15:39,981 TRACE [32] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY2AZF684\r >2018-02-22 18:15:39,981 TRACE [ 3] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 32 41 5A 46 36 38 34 0D >2018-02-22 18:15:39,991 TRACE [ 3] TcpTransportProvider - TCP: 35 bytes written; 10 ms >2018-02-22 18:16:00,491 TRACE [18] TcpTransportProvider - TCP: read >2018-02-22 18:16:00,491 TRACE [18] TcpTransportProvider - TCP: 0 bytes read; 20500 ms >2018-02-22 18:16:00,491 DEBUG [18] SipCirculationProvider - Duration of operation: 20506 ms >2018-02-22 18:16:01,501 WARN [27] SipCirculationProvider - Retry #1 >2018-02-22 18:16:01,501 INFO [27] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:16:01,501 TRACE [27] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY2AZF684\r >2018-02-22 18:16:01,501 TRACE [18] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 32 41 5A 46 36 38 34 0D >2018-02-22 18:16:01,501 TRACE [18] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:16:22,004 TRACE [23] TcpTransportProvider - TCP: read >2018-02-22 18:16:22,004 TRACE [23] TcpTransportProvider - TCP: 0 bytes read; 20503 ms >2018-02-22 18:16:22,004 DEBUG [23] SipCirculationProvider - Duration of operation: 20504 ms >2018-02-22 18:16:23,014 WARN [ 4] SipCirculationProvider - Retry #2 >2018-02-22 18:16:23,014 INFO [ 4] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:16:23,014 TRACE [ 4] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY2AZF684\r >2018-02-22 18:16:23,014 TRACE [20] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 32 41 5A 46 36 38 34 0D >2018-02-22 18:16:23,014 TRACE [20] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:16:43,524 TRACE [23] TcpTransportProvider - TCP: read >2018-02-22 18:16:43,524 TRACE [23] TcpTransportProvider - TCP: 0 bytes read; 20510 ms >2018-02-22 18:16:43,524 DEBUG [23] SipCirculationProvider - Duration of operation: 20510 ms >2018-02-22 18:16:43,524 INFO [23] TcpTransportProvider - TCP: Closing connection to: 192.168.200.12:6001 >2018-02-22 18:16:43,524 INFO [23] SipCirculationProvider - Closed SIP circulation provider from address: 192.168.200.12:6001 >2018-02-22 18:17:43,669 INFO [ 4] SipCirculationProvider - Resetting from error state >2018-02-22 18:17:43,669 INFO [ 4] TcpTransportProvider - TCP: Opening connection to: 192.168.200.12:6001 >2018-02-22 18:17:43,679 INFO [33] SipCirculationProvider - Opened SIP circulation provider with address: 192.168.200.12:6001 >2018-02-22 18:17:43,679 INFO [33] SipCirculationProvider - Processing request MMM.LibrarySystems.Circulation.SIP.Messages.LoginRequest and response MMM.LibrarySystems.Circulation.SIP.Messages.LoginResponse >2018-02-22 18:17:43,699 INFO [33] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:17:43,699 TRACE [33] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY3AZF683\r >2018-02-22 18:17:43,709 TRACE [ 7] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 33 41 5A 46 36 38 33 0D >2018-02-22 18:17:43,709 TRACE [ 7] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:18:04,183 TRACE [ 7] TcpTransportProvider - TCP: read >2018-02-22 18:18:04,183 TRACE [ 7] TcpTransportProvider - TCP: 0 bytes read; 20474 ms >2018-02-22 18:18:04,183 DEBUG [ 7] SipCirculationProvider - Duration of operation: 20502 ms >2018-02-22 18:18:05,200 WARN [ 4] SipCirculationProvider - Retry #1 >2018-02-22 18:18:05,200 INFO [ 4] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:18:05,200 TRACE [ 4] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY3AZF683\r >2018-02-22 18:18:05,200 TRACE [13] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 33 41 5A 46 36 38 33 0D >2018-02-22 18:18:05,200 TRACE [13] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:18:25,706 TRACE [ 4] TcpTransportProvider - TCP: read >2018-02-22 18:18:25,706 TRACE [ 4] TcpTransportProvider - TCP: 0 bytes read; 20506 ms >2018-02-22 18:18:25,706 DEBUG [ 4] SipCirculationProvider - Duration of operation: 20506 ms >2018-02-22 18:18:26,716 WARN [26] SipCirculationProvider - Retry #2 >2018-02-22 18:18:26,716 INFO [26] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:18:26,716 TRACE [26] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY3AZF683\r >2018-02-22 18:18:26,716 TRACE [ 5] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 33 41 5A 46 36 38 33 0D >2018-02-22 18:18:26,716 TRACE [ 5] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:18:47,223 TRACE [26] TcpTransportProvider - TCP: read >2018-02-22 18:18:47,223 TRACE [26] TcpTransportProvider - TCP: 0 bytes read; 20507 ms >2018-02-22 18:18:47,223 DEBUG [26] SipCirculationProvider - Duration of operation: 20508 ms >2018-02-22 18:18:47,223 INFO [26] TcpTransportProvider - TCP: Closing connection to: 192.168.200.12:6001 >2018-02-22 18:18:47,223 INFO [26] SipCirculationProvider - Closed SIP circulation provider from address: 192.168.200.12:6001 >2018-02-22 18:19:47,235 INFO [ 5] SipCirculationProvider - Resetting from error state >2018-02-22 18:19:47,235 INFO [ 5] TcpTransportProvider - TCP: Opening connection to: 192.168.200.12:6001 >2018-02-22 18:19:47,245 INFO [33] SipCirculationProvider - Opened SIP circulation provider with address: 192.168.200.12:6001 >2018-02-22 18:19:47,245 INFO [33] SipCirculationProvider - Processing request MMM.LibrarySystems.Circulation.SIP.Messages.LoginRequest and response MMM.LibrarySystems.Circulation.SIP.Messages.LoginResponse >2018-02-22 18:19:47,245 INFO [33] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:19:47,245 TRACE [33] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY4AZF682\r >2018-02-22 18:19:47,245 TRACE [20] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 34 41 5A 46 36 38 32 0D >2018-02-22 18:19:47,245 TRACE [20] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:20:07,755 TRACE [30] TcpTransportProvider - TCP: read >2018-02-22 18:20:07,755 TRACE [30] TcpTransportProvider - TCP: 0 bytes read; 20510 ms >2018-02-22 18:20:07,755 DEBUG [30] SipCirculationProvider - Duration of operation: 20509 ms >2018-02-22 18:20:08,765 WARN [ 5] SipCirculationProvider - Retry #1 >2018-02-22 18:20:08,765 INFO [ 5] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:20:08,765 TRACE [ 5] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY4AZF682\r >2018-02-22 18:20:08,765 TRACE [26] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 34 41 5A 46 36 38 32 0D >2018-02-22 18:20:08,765 TRACE [26] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:20:29,270 TRACE [ 7] TcpTransportProvider - TCP: read >2018-02-22 18:20:29,270 TRACE [ 7] TcpTransportProvider - TCP: 0 bytes read; 20505 ms >2018-02-22 18:20:29,270 DEBUG [ 7] SipCirculationProvider - Duration of operation: 20505 ms >2018-02-22 18:20:30,280 WARN [ 5] SipCirculationProvider - Retry #2 >2018-02-22 18:20:30,280 INFO [ 5] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:20:30,290 TRACE [ 5] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY4AZF682\r >2018-02-22 18:20:30,290 TRACE [32] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 34 41 5A 46 36 38 32 0D >2018-02-22 18:20:30,290 TRACE [32] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:20:50,781 TRACE [32] TcpTransportProvider - TCP: read >2018-02-22 18:20:50,781 TRACE [32] TcpTransportProvider - TCP: 0 bytes read; 20491 ms >2018-02-22 18:20:50,781 DEBUG [32] SipCirculationProvider - Duration of operation: 20501 ms >2018-02-22 18:20:50,781 INFO [32] TcpTransportProvider - TCP: Closing connection to: 192.168.200.12:6001 >2018-02-22 18:20:50,781 INFO [32] SipCirculationProvider - Closed SIP circulation provider from address: 192.168.200.12:6001 >2018-02-22 18:21:50,789 INFO [20] SipCirculationProvider - Resetting from error state >2018-02-22 18:21:50,789 INFO [20] TcpTransportProvider - TCP: Opening connection to: 192.168.200.12:6001 >2018-02-22 18:21:50,789 INFO [13] SipCirculationProvider - Opened SIP circulation provider with address: 192.168.200.12:6001 >2018-02-22 18:21:50,789 INFO [13] SipCirculationProvider - Processing request MMM.LibrarySystems.Circulation.SIP.Messages.LoginRequest and response MMM.LibrarySystems.Circulation.SIP.Messages.LoginResponse >2018-02-22 18:21:50,789 INFO [13] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:21:50,799 TRACE [13] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY5AZF681\r >2018-02-22 18:21:50,799 TRACE [32] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 35 41 5A 46 36 38 31 0D >2018-02-22 18:21:50,799 TRACE [32] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:22:11,301 TRACE [ 7] TcpTransportProvider - TCP: read >2018-02-22 18:22:11,301 TRACE [ 7] TcpTransportProvider - TCP: 0 bytes read; 20502 ms >2018-02-22 18:22:11,301 DEBUG [ 7] SipCirculationProvider - Duration of operation: 20509 ms >2018-02-22 18:22:12,308 WARN [30] SipCirculationProvider - Retry #1 >2018-02-22 18:22:12,328 INFO [30] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:22:12,338 TRACE [30] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY5AZF681\r >2018-02-22 18:22:12,338 TRACE [ 7] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 35 41 5A 46 36 38 31 0D >2018-02-22 18:22:12,338 TRACE [ 7] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:22:32,817 TRACE [ 5] TcpTransportProvider - TCP: read >2018-02-22 18:22:32,818 TRACE [ 5] TcpTransportProvider - TCP: 0 bytes read; 20480 ms >2018-02-22 18:22:32,819 DEBUG [ 5] SipCirculationProvider - Duration of operation: 20510 ms >2018-02-22 18:22:33,829 WARN [ 7] SipCirculationProvider - Retry #2 >2018-02-22 18:22:33,834 INFO [ 7] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:22:33,841 TRACE [ 7] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY5AZF681\r >2018-02-22 18:22:33,842 TRACE [ 7] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 35 41 5A 46 36 38 31 0D >2018-02-22 18:22:33,842 TRACE [ 7] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:22:54,339 TRACE [ 7] TcpTransportProvider - TCP: read >2018-02-22 18:22:54,339 TRACE [ 7] TcpTransportProvider - TCP: 0 bytes read; 20496 ms >2018-02-22 18:22:54,339 DEBUG [ 7] SipCirculationProvider - Duration of operation: 20510 ms >2018-02-22 18:22:54,339 INFO [ 7] TcpTransportProvider - TCP: Closing connection to: 192.168.200.12:6001 >2018-02-22 18:22:54,339 INFO [ 7] SipCirculationProvider - Closed SIP circulation provider from address: 192.168.200.12:6001 >2018-02-22 18:23:54,347 INFO [ 7] SipCirculationProvider - Resetting from error state >2018-02-22 18:23:54,347 INFO [ 7] TcpTransportProvider - TCP: Opening connection to: 192.168.200.12:6001 >2018-02-22 18:23:54,347 INFO [13] SipCirculationProvider - Opened SIP circulation provider with address: 192.168.200.12:6001 >2018-02-22 18:23:54,347 INFO [13] SipCirculationProvider - Processing request MMM.LibrarySystems.Circulation.SIP.Messages.LoginRequest and response MMM.LibrarySystems.Circulation.SIP.Messages.LoginResponse >2018-02-22 18:23:54,357 INFO [13] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:23:54,378 TRACE [13] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY6AZF680\r >2018-02-22 18:23:54,378 TRACE [ 4] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 36 41 5A 46 36 38 30 0D >2018-02-22 18:23:54,378 TRACE [ 4] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:24:14,857 TRACE [ 4] TcpTransportProvider - TCP: read >2018-02-22 18:24:14,859 TRACE [ 4] TcpTransportProvider - TCP: 0 bytes read; 20481 ms >2018-02-22 18:24:14,861 DEBUG [ 4] SipCirculationProvider - Duration of operation: 20506 ms >2018-02-22 18:24:15,874 WARN [26] SipCirculationProvider - Retry #1 >2018-02-22 18:24:15,874 INFO [26] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:24:15,874 TRACE [26] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY6AZF680\r >2018-02-22 18:24:15,874 TRACE [ 3] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 36 41 5A 46 36 38 30 0D >2018-02-22 18:24:15,874 TRACE [ 3] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:24:36,384 TRACE [30] TcpTransportProvider - TCP: read >2018-02-22 18:24:36,384 TRACE [30] TcpTransportProvider - TCP: 0 bytes read; 20510 ms >2018-02-22 18:24:36,384 DEBUG [30] SipCirculationProvider - Duration of operation: 20510 ms >2018-02-22 18:24:37,404 WARN [38] SipCirculationProvider - Retry #2 >2018-02-22 18:24:37,404 INFO [38] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:24:37,404 TRACE [38] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY6AZF680\r >2018-02-22 18:24:37,404 TRACE [24] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 36 41 5A 46 36 38 30 0D >2018-02-22 18:24:37,404 TRACE [24] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:24:57,914 TRACE [18] TcpTransportProvider - TCP: read >2018-02-22 18:24:57,914 TRACE [18] TcpTransportProvider - TCP: 0 bytes read; 20510 ms >2018-02-22 18:24:57,914 DEBUG [18] SipCirculationProvider - Duration of operation: 20510 ms >2018-02-22 18:24:57,914 INFO [18] TcpTransportProvider - TCP: Closing connection to: 192.168.200.12:6001 >2018-02-22 18:24:57,914 INFO [18] SipCirculationProvider - Closed SIP circulation provider from address: 192.168.200.12:6001 >2018-02-22 18:25:57,930 INFO [30] SipCirculationProvider - Resetting from error state >2018-02-22 18:25:57,930 INFO [30] TcpTransportProvider - TCP: Opening connection to: 192.168.200.12:6001 >2018-02-22 18:25:57,930 INFO [13] SipCirculationProvider - Opened SIP circulation provider with address: 192.168.200.12:6001 >2018-02-22 18:25:57,930 INFO [13] SipCirculationProvider - Processing request MMM.LibrarySystems.Circulation.SIP.Messages.LoginRequest and response MMM.LibrarySystems.Circulation.SIP.Messages.LoginResponse >2018-02-22 18:25:57,930 INFO [13] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:25:57,940 TRACE [13] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY7AZF67F\r >2018-02-22 18:25:57,940 TRACE [38] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 37 41 5A 46 36 37 46 0D >2018-02-22 18:25:57,940 TRACE [38] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:26:18,432 TRACE [25] TcpTransportProvider - TCP: read >2018-02-22 18:26:18,432 TRACE [25] TcpTransportProvider - TCP: 0 bytes read; 20492 ms >2018-02-22 18:26:18,432 DEBUG [25] SipCirculationProvider - Duration of operation: 20498 ms >2018-02-22 18:26:19,442 WARN [25] SipCirculationProvider - Retry #1 >2018-02-22 18:26:19,442 INFO [25] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:26:19,442 TRACE [25] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY7AZF67F\r >2018-02-22 18:26:19,442 TRACE [25] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 37 41 5A 46 36 37 46 0D >2018-02-22 18:26:19,442 TRACE [25] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:26:39,950 TRACE [24] TcpTransportProvider - TCP: read >2018-02-22 18:26:39,950 TRACE [24] TcpTransportProvider - TCP: 0 bytes read; 20508 ms >2018-02-22 18:26:39,950 DEBUG [24] SipCirculationProvider - Duration of operation: 20509 ms >2018-02-22 18:26:40,950 WARN [ 7] SipCirculationProvider - Retry #2 >2018-02-22 18:26:40,950 INFO [ 7] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:26:40,970 TRACE [ 7] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY7AZF67F\r >2018-02-22 18:26:40,970 TRACE [ 4] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 37 41 5A 46 36 37 46 0D >2018-02-22 18:26:40,970 TRACE [ 4] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:27:01,453 TRACE [ 4] TcpTransportProvider - TCP: read >2018-02-22 18:27:01,453 TRACE [ 4] TcpTransportProvider - TCP: 0 bytes read; 20483 ms >2018-02-22 18:27:01,453 DEBUG [ 4] SipCirculationProvider - Duration of operation: 20504 ms >2018-02-22 18:27:01,453 INFO [ 4] TcpTransportProvider - TCP: Closing connection to: 192.168.200.12:6001 >2018-02-22 18:27:01,453 INFO [ 4] SipCirculationProvider - Closed SIP circulation provider from address: 192.168.200.12:6001 >2018-02-22 18:28:01,469 INFO [38] SipCirculationProvider - Resetting from error state >2018-02-22 18:28:01,469 INFO [38] TcpTransportProvider - TCP: Opening connection to: 192.168.200.12:6001 >2018-02-22 18:28:01,469 INFO [13] SipCirculationProvider - Opened SIP circulation provider with address: 192.168.200.12:6001 >2018-02-22 18:28:01,469 INFO [13] SipCirculationProvider - Processing request MMM.LibrarySystems.Circulation.SIP.Messages.LoginRequest and response MMM.LibrarySystems.Circulation.SIP.Messages.LoginResponse >2018-02-22 18:28:01,469 INFO [13] MessageFormatter - Formatting: [93] Login {UID algorithm = 0, PWD algorithm = 0, [CN] login user id = "sip1", [CO] login password = "sip1", [CP] location code = "MAIN"} >2018-02-22 18:28:01,469 TRACE [13] MessageFormatter - Formatted: 9300CNsip1|COsip1|CPMAIN|AY8AZF67E\r >2018-02-22 18:28:01,469 TRACE [18] TcpTransportProvider - TCP: write 39 33 30 30 43 4E 73 69 70 31 7C 43 4F 73 69 70 31 7C 43 50 4D 41 49 4E 7C 41 59 38 41 5A 46 36 37 45 0D >2018-02-22 18:28:01,469 TRACE [18] TcpTransportProvider - TCP: 35 bytes written; 0 ms >2018-02-22 18:28:01,529 TRACE [25] TcpTransportProvider - TCP: read 39 34 31 41 59 38 41 5A 46 44 46 35 0D 0A >2018-02-22 18:28:01,529 TRACE [25] TcpTransportProvider - TCP: 14 bytes read; 60 ms >2018-02-22 18:28:01,539 TRACE [25] MessageFormatter - Parsing: 941AY8AZFDF5 >2018-02-22 18:28:01,549 INFO [25] MessageFormatter - Parsed: [94] Login Response {ok = 1} >2018-02-22 18:28:01,559 DEBUG [25] SipCirculationProvider - Duration of operation: 95 ms >2018-02-22 18:28:01,579 INFO [25] MessageFormatter - Formatting: [99] SC Status {status code = UnitIsOk, max print width = 30, protocol version = "2.00"} >2018-02-22 18:28:01,579 TRACE [25] MessageFormatter - Formatted: 9900302.00AY9AZFC9D\r >2018-02-22 18:28:01,589 TRACE [19] TcpTransportProvider - TCP: write 39 39 30 30 33 30 32 2E 30 30 41 59 39 41 5A 46 43 39 44 0D >2018-02-22 18:28:01,589 TRACE [19] TcpTransportProvider - TCP: 20 bytes written; 0 ms >2018-02-22 18:28:01,589 TRACE [19] MessageFormatter - Additional data is required to parse message: \n >2018-02-22 18:28:01,589 TRACE [37] TcpTransportProvider - TCP: read 39 38 59 59 59 59 4E 4E 31 30 30 30 30 35 32 30 31 38 30 32 32 32 20 20 20 20 31 38 32 38 31 36 32 2E 30 30 41 4F 4D 41 49 4E 7C 42 58 59 59 59 59 59 59 59 59 59 59 59 4E 59 59 59 59 7C 41 59 39 41 5A 45 45 32 34 0D 0A >2018-02-22 18:28:01,589 TRACE [37] TcpTransportProvider - TCP: 73 bytes read; 0 ms >2018-02-22 18:28:01,589 TRACE [37] MessageFormatter - Skipping 1 extra character(s) in data: \n >2018-02-22 18:28:01,589 TRACE [37] MessageFormatter - Parsing: 98YYYYNN10000520180222 1828162.00AOMAIN|BXYYYYYYYYYYYNYYYY|AY9AZEE24 >2018-02-22 18:28:01,609 INFO [37] MessageFormatter - Parsed: [98] ACS Status {on-line status = True, checkin ok = True, checkout ok = True, ACS renewal policy = True, status update ok = False, off-line ok = False, timeout period = 100, retries allowed = 5, date time sync = 2018-02-22 18:28:16, protocol version = "2.00", [AO] institution id = "MAIN", [BX] supported messages = PatronStatus, CheckOut, CheckIn, BlockPatron, ScAcsStatus, RequestResend, Login, PatronInformation, EndPatronSession, FeePaid, ItemInformation, PatronEnable, Hold, Renew, RenewAll} >2018-02-22 18:28:01,609 DEBUG [37] SipCirculationProvider - Duration of operation: 30 ms >2018-02-22 18:28:01,619 INFO [37] SipCirculationProvider - Supported message flags changed to: PatronStatus, CheckOut, CheckIn, BlockPatron, ScAcsStatus, RequestResend, Login, PatronInformation, EndPatronSession, FeePaid, ItemInformation, PatronEnable, Hold, Renew, RenewAll >2018-02-22 18:28:01,619 INFO [37] SipCirculationProvider - Permission flags changed to: CheckInAllowed, CheckOutAllowed, RenewalAllowed >2018-02-22 18:32:09,744 INFO [primary] App - Exiting >2018-02-22 18:32:09,880 INFO [26] MessageFormatter - Formatting: [99] SC Status {status code = ShuttingDown, max print width = 30, protocol version = "2.00"} >2018-02-22 18:32:09,884 TRACE [26] MessageFormatter - Formatted: 9920302.00AY0AZFCA4\r >2018-02-22 18:32:09,884 TRACE [31] TcpTransportProvider - TCP: write 39 39 32 30 33 30 32 2E 30 30 41 59 30 41 5A 46 43 41 34 0D >2018-02-22 18:32:09,885 TRACE [31] TcpTransportProvider - TCP: 20 bytes written; 1 ms >2018-02-22 18:32:09,886 TRACE [31] MessageFormatter - Additional data is required to parse message: \n >2018-02-22 18:32:09,887 TRACE [31] TcpTransportProvider - TCP: read 39 38 59 59 59 59 4E 4E 31 30 30 30 30 35 32 30 31 38 30 32 32 32 20 20 20 20 31 38 33 32 32 34 32 2E 30 30 41 4F 4D 41 49 4E 7C 42 58 59 59 59 59 59 59 59 59 59 59 59 4E 59 59 59 59 7C 41 59 30 41 5A 45 45 33 33 0D 0A >2018-02-22 18:32:09,887 TRACE [31] TcpTransportProvider - TCP: 73 bytes read; 1 ms >2018-02-22 18:32:09,887 TRACE [31] MessageFormatter - Skipping 1 extra character(s) in data: \n >2018-02-22 18:32:09,888 TRACE [31] MessageFormatter - Parsing: 98YYYYNN10000520180222 1832242.00AOMAIN|BXYYYYYYYYYYYNYYYY|AY0AZEE33 >2018-02-22 18:32:09,896 INFO [31] MessageFormatter - Parsed: [98] ACS Status {on-line status = True, checkin ok = True, checkout ok = True, ACS renewal policy = True, status update ok = False, off-line ok = False, timeout period = 100, retries allowed = 5, date time sync = 2018-02-22 18:32:24, protocol version = "2.00", [AO] institution id = "MAIN", [BX] supported messages = PatronStatus, CheckOut, CheckIn, BlockPatron, ScAcsStatus, RequestResend, Login, PatronInformation, EndPatronSession, FeePaid, ItemInformation, PatronEnable, Hold, Renew, RenewAll} >2018-02-22 18:32:09,896 DEBUG [31] SipCirculationProvider - Duration of operation: 17 ms >2018-02-22 18:32:09,897 INFO [31] TcpTransportProvider - TCP: Closing connection to: 192.168.200.12:6001 >2018-02-22 18:32:09,897 INFO [31] SipCirculationProvider - Closed SIP circulation provider from address: 192.168.200.12:6001 >2018-02-22 18:32:10,536 INFO [primary] App - End
You cannot view the attachment while viewing its details because your browser does not support IFRAMEs.
View the attachment on a separate page
.
View Attachment As Raw
Actions:
View
Attachments on
bug 20270
: 72087