[2017-08-27 14:14:02] open-ils.search [INFO:14468:Application.pm:152:15038079312222267] CALL: open-ils.search open-ils.search.z3950.search_class c7ef671342a2bd832074e86826aced23, HASH(0x4870170)
open-ils.auth 2017-08-27 14:14:02 [INFO:14443:osrf_application.c:1059:15038079312222267] CALL: open-ils.auth open-ils.auth.session.retrieve "c7ef671342a2bd832074e86826aced23",1
open-ils.auth 2017-08-27 14:14:02 [INFO:14443:oils_event.c:46:15038079312222267] Creating new event: SUCCESS
open-ils.auth 2017-08-27 14:14:02 [INFO:14443:osrf_app_session.c:1017:15038079312222267] [open-ils.auth] sent 759 bytes of data to opensrf@private.localhost/open-ils.search_drone_at_localhost_14468
open-ils.auth 2017-08-27 14:14:02 [INFO:14443:osrf_stack.c:163:15038079312222267] Message processing duration 0.000475
[2017-08-27 14:14:02] open-ils.search [INFO:14468:CStoreEditor.pm:139:15038079312222267] editor[0|1] checking perms user=1, org=103, perm=REMOTE_Z3950_QUERY
[2017-08-27 14:14:02] open-ils.search [INFO:14468:CStoreEditor.pm:139:15038079312222267] editor[0|1] request en-US open-ils.cstore.json_query.atomic {"where":{"id":"1"},"select":{"au":[{"alias":"has_perm","column":"id","params":["REMOTE_Z3950_QUERY","103"],"transform":"permission.usr_has_perm"}]},"from":"au"}
open-ils.cstore 2017-08-27 14:14:02 [INFO:14741:osrf_application.c:1059:15038079312222267] CALL: open-ils.cstore open-ils.cstore.json_query.atomic {"where":{"id":"1"},"from":"au","select":{"au":[{"params":["REMOTE_Z3950_QUERY","103"],"column":"id","alias":"has_perm","transform":"permission.usr_has_perm"}]}}
open-ils.cstore 2017-08-27 14:14:02 [INFO:14741:osrf_app_session.c:1017:15038079312222267] [open-ils.cstore] sent 385 bytes of data to opensrf@private.localhost/open-ils.search_drone_at_localhost_14468
open-ils.cstore 2017-08-27 14:14:02 [INFO:14741:osrf_stack.c:163:15038079312222267] Message processing duration 0.000884
[2017-08-27 14:14:02] open-ils.search [INFO:14468:CStoreEditor.pm:139:15038079312222267] editor[0|1] json_query : returned 1 result(s)
[2017-08-27 14:14:02] open-ils.search [INFO:14468:CStoreEditor.pm:139:15038079312222267] editor[0|1] request en-US open-ils.cstore.json_query.atomic {"from":["config.z3950_source_credentials_lookup","loc","103"]}
open-ils.cstore 2017-08-27 14:14:02 [INFO:14754:osrf_application.c:1059:15038079312222267] CALL: open-ils.cstore open-ils.cstore.json_query.atomic {"from":["config.z3950_source_credentials_lookup","loc","103"]}
open-ils.cstore 2017-08-27 14:14:02 [INFO:14754:osrf_app_session.c:1017:15038079312222267] [open-ils.cstore] sent 439 bytes of data to opensrf@private.localhost/open-ils.search_drone_at_localhost_14468
open-ils.cstore 2017-08-27 14:14:02 [INFO:14754:osrf_stack.c:163:15038079312222267] Message processing duration 0.001504
[2017-08-27 14:14:02] open-ils.search [INFO:14468:CStoreEditor.pm:139:15038079312222267] editor[0|1] json_query : returned 1 result(s)
[2017-08-27 14:14:02] open-ils.search [INFO:14468:Z3950.pm:377:15038079312222267] z3950: connecting to server z3950.loc.gov:7090:Voyager as 
[2017-08-27 14:14:02] open-ils.search [INFO:14468:Z3950.pm:398:15038079312222267] z3950: query => @attr 1=4 @attr 4=6 @attr 5=1 "švejk" 
[2017-08-27 14:14:02] open-ils.search [INFO:14468:Z3950.pm:410:15038079312222267] z3950: search [@attr 1=4 @attr 4=6 @attr 5=1 "švejk" ] took 0 seconds
[2017-08-27 14:14:03] open-ils.search [INFO:14468:Z3950.pm:439:15038079312222267] z3950: using record format 'FI' and transmission format 'usmarc'
[2017-08-27 14:14:03] open-ils.search [INFO:14468:Z3950.pm:445:15038079312222267] z3950: 'loc' search returned 81 hits
[2017-08-27 14:14:03] open-ils.search [INFO:14468:Z3950.pm:459:15038079312222267] z3950: fetching record 0
[2017-08-27 14:14:04] open-ils.search [INFO:14468:Z3950.pm:459:15038079312222267] z3950: fetching record 1
[2017-08-27 14:14:04] open-ils.search [INFO:14468:Z3950.pm:459:15038079312222267] z3950: fetching record 2
[2017-08-27 14:14:04] open-ils.search [INFO:14468:Z3950.pm:459:15038079312222267] z3950: fetching record 3
[2017-08-27 14:14:04] open-ils.search [INFO:14468:Z3950.pm:459:15038079312222267] z3950: fetching record 4
[2017-08-27 14:14:05] open-ils.search [INFO:14468:Z3950.pm:459:15038079312222267] z3950: fetching record 5
[2017-08-27 14:14:05] open-ils.search [INFO:14468:Z3950.pm:459:15038079312222267] z3950: fetching record 6
[2017-08-27 14:14:05] open-ils.search [INFO:14468:Z3950.pm:459:15038079312222267] z3950: fetching record 7
[2017-08-27 14:14:05] open-ils.search [INFO:14468:Z3950.pm:459:15038079312222267] z3950: fetching record 8
[2017-08-27 14:14:05] open-ils.search [INFO:14468:Z3950.pm:459:15038079312222267] z3950: fetching record 9
[2017-08-27 14:14:05] open-ils.search [INFO:14468:Transport.pm:163:15038079312222267] Message processing duration: 3.296