Adding a log thread trace for an occurrence of this that happened on 10/11. This threadtrace contains references to a Jabber layer error in the osrfsys.log:
2017-10-11 08:40:58 brick1 open-ils.search: [INFO:37294:Application.pm:159:1507725612372544] CALL: open-ils.search open-ils.search.callnumber.fleshed.retrieve.authoritative 17936192
2017-10-11 08:40:58 brick1 open-ils.search: [INFO:37294:Event.pm:64:1507725612372544] Loading events xml file /openils/var/data/ils_events.xml
2017-10-11 08:40:58 brick1 open-ils.cstore: [INFO:37095:osrf_app_session.c:1177:1507725612372544] [open-ils.cstore] sent 194 bytes of data to opensrf@brick1-private/open-ils.search_drone_at_brick1.noblenet.org_37294
2017-10-11 08:40:58 brick1 open-ils.cstore: [INFO:37095:osrf_stack.c:163:1507725612372544] Message processing duration 0.000124
2017-10-11 08:40:58 brick1 open-ils.cstore: [INFO:37095:transport_session.c:648:1507725612372544] Received <error> message with type cancel and code 503
2017-10-11 08:40:58 brick1 open-ils.cstore: [WARN:37095:osrf_stack.c:134:1507725612372544] !!! Received Jabber layer error message
2017-10-11 08:40:58 brick1 open-ils.cstore: [WARN:37095:osrf_stack.c:144:1507725612372544] * Jabber Error is for top level remote id [opensrf@brick1-private/open-ils.search_drone_at_brick1.noblenet.org_37294], no one to send my message to! Cutting request short...
2017-10-11 08:40:58 brick1 open-ils.cstore: [INFO:37095:osrf_stack.c:163:1507725612372544] Message processing duration 0.000018
2017-10-11 08:41:04 brick1 open-ils.cstore: [INFO:37095:osrf_prefork.c:496:1507725612372544] No request was received in 6 seconds, exiting stateful session
2017-10-11 08:41:04 brick1 open-ils.cstore: [INFO:37095:osrf_app_session.c:1177:1507725612372544] [open-ils.cstore] sent 196 bytes of data to opensrf@brick1-private/open-ils.search_drone_at_brick1.noblenet.org_37294
2017-10-11 08:41:05 brick1 open-ils.cstore: [INFO:37095:osrf_app_session.c:1177:1507725612372544] [open-ils.cstore] sent 189 bytes of data to opensrf@brick1-private/open-ils.circ_drone_at_brick1.noblenet.org_37273
2017-10-11 08:41:05 brick1 open-ils.cstore: [INFO:37095:osrf_stack.c:163:1507725612372544] Message processing duration 0.001870
2017-10-11 08:41:05 brick1 open-ils.circ: [INFO:37273:CStoreEditor.pm:139:1507725612372544] editor[0|334] request returned no data : open-ils.cstore.direct.action.has_holds_count.retrieve
2017-10-11 08:41:05 brick1 open-ils.circ: [INFO:37273:Transport.pm:163:1507725612372544] Message processing duration: 0.012
Also, from the gateway.log:
2017-10-11 08:40:58 brick1 osrf_json_gw: [INFO:37254:osrf_app_session.c:1177:1507725612372544] [open-ils.search] sent 248 bytes of data to router@brick1/open-ils.search
2017-10-11 08:40:58 brick1 osrf_json_gw: [INFO:37254:./osrf_json_gateway.c:328:1507725612372544] [192.168.0.19] [b5bde9a4ff2f68f21ab45808d0fbec24] [en-US] open-ils.search open-ils.search.callnumber.fleshed.retrieve.authoritative 17936192
2017-10-11 08:41:58 brick1 osrf_json_gw: [INFO:37254:osrf_app_session.c:394:1507725612372544] Returning NULL from app_request_recv after timeout: open-ils.search.callnumber.fleshed.retrieve.authoritative [17936192]
2017-10-11 08:41:58 brick1 osrf_json_gw: [INFO:37254:./osrf_json_gateway.c:435:1507725612372544] Completed processing service=open-ils.search, method=open-ils.search.callnumber.fleshed.retrieve.authoritative
Adding a log thread trace for an occurrence of this that happened on 10/11. This threadtrace contains references to a Jabber layer error in the osrfsys.log:
2017-10-11 08:40:58 brick1 open-ils.search: [INFO:37294: Application. pm:159: 150772561237254 4] CALL: open-ils.search open-ils. search. callnumber. fleshed. retrieve. authoritative 17936192 Event.pm: 64:150772561237 2544] Loading events xml file /openils/ var/data/ ils_events. xml osrf_app_ session. c:1177: 150772561237254 4] [open-ils.cstore] sent 194 bytes of data to opensrf@ brick1- private/ open-ils. search_ drone_at_ brick1. noblenet. org_37294 osrf_stack. c:163:150772561 2372544] Message processing duration 0.000124 transport_ session. c:648:150772561 2372544] Received <error> message with type cancel and code 503 osrf_stack. c:134:150772561 2372544] !!! Received Jabber layer error message osrf_stack. c:144:150772561 2372544] * Jabber Error is for top level remote id [opensrf@ brick1- private/ open-ils. search_ drone_at_ brick1. noblenet. org_37294] , no one to send my message to! Cutting request short... osrf_stack. c:163:150772561 2372544] Message processing duration 0.000018 osrf_prefork. c:496:150772561 2372544] No request was received in 6 seconds, exiting stateful session osrf_app_ session. c:1177: 150772561237254 4] [open-ils.cstore] sent 196 bytes of data to opensrf@ brick1- private/ open-ils. search_ drone_at_ brick1. noblenet. org_37294 osrf_app_ session. c:1177: 150772561237254 4] [open-ils.cstore] sent 189 bytes of data to opensrf@ brick1- private/ open-ils. circ_drone_ at_brick1. noblenet. org_37273 osrf_stack. c:163:150772561 2372544] Message processing duration 0.001870 CStoreEditor. pm:139: 150772561237254 4] editor[0|334] request returned no data : open-ils. cstore. direct. action. has_holds_ count.retrieve Transport. pm:163: 150772561237254 4] Message processing duration: 0.012
2017-10-11 08:40:58 brick1 open-ils.search: [INFO:37294:
2017-10-11 08:40:58 brick1 open-ils.cstore: [INFO:37095:
2017-10-11 08:40:58 brick1 open-ils.cstore: [INFO:37095:
2017-10-11 08:40:58 brick1 open-ils.cstore: [INFO:37095:
2017-10-11 08:40:58 brick1 open-ils.cstore: [WARN:37095:
2017-10-11 08:40:58 brick1 open-ils.cstore: [WARN:37095:
2017-10-11 08:40:58 brick1 open-ils.cstore: [INFO:37095:
2017-10-11 08:41:04 brick1 open-ils.cstore: [INFO:37095:
2017-10-11 08:41:04 brick1 open-ils.cstore: [INFO:37095:
2017-10-11 08:41:05 brick1 open-ils.cstore: [INFO:37095:
2017-10-11 08:41:05 brick1 open-ils.cstore: [INFO:37095:
2017-10-11 08:41:05 brick1 open-ils.circ: [INFO:37273:
2017-10-11 08:41:05 brick1 open-ils.circ: [INFO:37273:
Also, from the gateway.log:
2017-10-11 08:40:58 brick1 osrf_json_gw: [INFO:37254: osrf_app_ session. c:1177: 150772561237254 4] [open-ils.search] sent 248 bytes of data to router@ brick1/ open-ils. search ./osrf_ json_gateway. c:328:150772561 2372544] [192.168.0.19] [b5bde9a4ff2f68 f21ab45808d0fbe c24] [en-US] open-ils.search open-ils. search. callnumber. fleshed. retrieve. authoritative 17936192 osrf_app_ session. c:394:150772561 2372544] Returning NULL from app_request_recv after timeout: open-ils. search. callnumber. fleshed. retrieve. authoritative [17936192] ./osrf_ json_gateway. c:435:150772561 2372544] Completed processing service= open-ils. search, method= open-ils. search. callnumber. fleshed. retrieve. authoritative
2017-10-11 08:40:58 brick1 osrf_json_gw: [INFO:37254:
2017-10-11 08:41:58 brick1 osrf_json_gw: [INFO:37254:
2017-10-11 08:41:58 brick1 osrf_json_gw: [INFO:37254: