[2011-11-08 11:08:24] open-ils.vandelay [INFO:17338:Application.pm:130:13205801212671077] CALL: open-ils.vandelay open-ils.vandelay.bib_queue.create 9f93de9e89dfc5950448fc734516f506, 2011.11.03.02_SE, , bib, 1
open-ils.auth 2011-11-08 11:08:24 [INFO:1310:oils_auth.c:883:13205801212671077] CALL:	open-ils.auth open-ils.auth.session.retrieve - ["9f93de9e89dfc5950448fc734516f506",1]
open-ils.auth 2011-11-08 11:08:24 [INFO:1310:oils_event.c:46:13205801212671077] Creating new event: SUCCESS
open-ils.auth 2011-11-08 11:08:24 [INFO:1310:osrf_app_session.c:991:13205801212671077] [open-ils.auth] sent 723 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.auth 2011-11-08 11:08:24 [INFO:1310:osrf_stack.c:159:13205801212671077] Message processing duration 0.001958
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671077] editor[1|1] checking perms user=1, org=4, perm=CREATE_BIB_IMPORT_QUEUE
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_app_session.c:991:13205801212671077] [open-ils.cstore] sent 180 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_stack.c:159:13205801212671077] Message processing duration 0.000468
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671077] editor[1|1] request en-US open-ils.cstore.transaction.begin []
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_app_session.c:991:13205801212671077] [open-ils.cstore] sent 373 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_stack.c:159:13205801212671077] Message processing duration 0.001134
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671077] editor[1|1] request en-US open-ils.cstore.json_query.atomic {"from":"au","select":{"au":[{"params":["CREATE_BIB_IMPORT_QUEUE","4"],"transform":"permission.usr_has_perm","alias":"has_perm","column":"id"}]},"where":{"id":"1"}}
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_application.c:1040:13205801212671077] CALL: open-ils.cstore open-ils.cstore.json_query.atomic {"from":"au","select":{"au":[{"params":["CREATE_BIB_IMPORT_QUEUE","4"],"transform":"permission.usr_has_perm","alias":"has_perm","column":"id"}]},"where":{"id":"1"}}
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_app_session.c:991:13205801212671077] [open-ils.cstore] sent 357 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_stack.c:159:13205801212671077] Message processing duration 0.002750
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671077] editor[1|1] json_query : returned 1 result(s)
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671077] editor[1|1] request en-US open-ils.cstore.direct.vandelay.bib_queue.search.atomic {"owner":1,"queue_type":"bib","name":"2011.11.03.02_SE"}
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_application.c:1040:13205801212671077] CALL: open-ils.cstore open-ils.cstore.direct.vandelay.bib_queue.search.atomic {"owner":1,"queue_type":"bib","name":"2011.11.03.02_SE"}
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_app_session.c:991:13205801212671077] [open-ils.cstore] sent 341 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_stack.c:159:13205801212671077] Message processing duration 0.002238
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671077] editor[1|1] vandelay.bib_queue.search : returned 0 result(s)
[2011-11-08 11:08:24] open-ils.vandelay [ACT:17338:CStoreEditor.pm:109:13205801212671077] editor[1|1] vandelay.bib_queue.create queue_type=bib owner=1 item_attr_def=1 ischanged= name=2011.11.03.02_SE isnew= id= isdeleted= complete=
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671077] editor[1|1] request en-US open-ils.cstore.direct.vandelay.bib_queue.create <new object>
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_application.c:1040:13205801212671077] CALL: open-ils.cstore open-ils.cstore.direct.vandelay.bib_queue.create {"__c":"vbq","__p":[null,1,"2011.11.03.02_SE",null,"bib","1"]}
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_app_session.c:991:13205801212671077] [open-ils.cstore] sent 396 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_stack.c:159:13205801212671077] Message processing duration 0.007342
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671077] editor[1|1] created a new vandelay.bib_queue object with Identity 14
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671077] editor[1|1] request en-US open-ils.cstore.transaction.commit []
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_app_session.c:991:13205801212671077] [open-ils.cstore] sent 373 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_stack.c:159:13205801212671077] Message processing duration 0.012951
open-ils.cstore 2011-11-08 11:08:24 [INFO:3711:osrf_stack.c:159:13205801212671077] Message processing duration 0.000002
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17338:Transport.pm:161:13205801212671077] Message processing duration: 0.103
open-ils.auth 2011-11-08 11:08:24 [INFO:17282:oils_auth.c:883:] CALL:	open-ils.auth open-ils.auth.session.retrieve - ["9f93de9e89dfc5950448fc734516f506"]
open-ils.auth 2011-11-08 11:08:24 [INFO:17282:oils_event.c:46:] Creating new event: SUCCESS
open-ils.auth 2011-11-08 11:08:24 [INFO:17282:osrf_app_session.c:991:] [open-ils.auth] sent 695 bytes of data to opensrf@private.localhost/client_at_library.CPS.EDU_26710
open-ils.auth 2011-11-08 11:08:24 [INFO:17282:osrf_stack.c:159:] Message processing duration 0.001921
[2011-11-08 11:08:24] /usr/sbin/apache2 [INFO:26710:Vandelay.pm:125:] uploaded MARC batch with key 476a713fc2f177ffe94679e90ae399c1
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17316:Application.pm:130:13205801212671078] CALL: open-ils.vandelay open-ils.vandelay.bib.process_spool 9f93de9e89dfc5950448fc734516f506, 476a713fc2f177ffe94679e90ae399c1, 14
open-ils.auth 2011-11-08 11:08:24 [INFO:1310:oils_auth.c:883:13205801212671078] CALL:	open-ils.auth open-ils.auth.session.retrieve - ["9f93de9e89dfc5950448fc734516f506",1]
open-ils.auth 2011-11-08 11:08:24 [INFO:1310:oils_event.c:46:13205801212671078] Creating new event: SUCCESS
open-ils.auth 2011-11-08 11:08:24 [INFO:1310:osrf_app_session.c:991:13205801212671078] [open-ils.auth] sent 723 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.auth 2011-11-08 11:08:24 [INFO:1310:osrf_stack.c:159:13205801212671078] Message processing duration 0.002005
open-ils.cstore 2011-11-08 11:08:24 [INFO:4385:osrf_app_session.c:991:13205801212671078] [open-ils.cstore] sent 180 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.cstore 2011-11-08 11:08:24 [INFO:4385:osrf_stack.c:159:13205801212671078] Message processing duration 0.000442
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671078] editor[1|1] request en-US open-ils.cstore.transaction.begin []
open-ils.cstore 2011-11-08 11:08:24 [INFO:4385:osrf_app_session.c:991:13205801212671078] [open-ils.cstore] sent 373 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.cstore 2011-11-08 11:08:24 [INFO:4385:osrf_stack.c:159:13205801212671078] Message processing duration 0.001145
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671078] editor[1|1] request en-US open-ils.cstore.direct.vandelay.bib_queue.retrieve 14
open-ils.cstore 2011-11-08 11:08:24 [INFO:4385:osrf_application.c:1040:13205801212671078] CALL: open-ils.cstore open-ils.cstore.direct.vandelay.bib_queue.retrieve 14
open-ils.cstore 2011-11-08 11:08:24 [INFO:4385:osrf_app_session.c:991:13205801212671078] [open-ils.cstore] sent 396 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.cstore 2011-11-08 11:08:24 [INFO:4385:osrf_stack.c:159:13205801212671078] Message processing duration 0.005575
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671078] editor[1|1] checking perms user=1, org=4, perm=CREATE_BIB_IMPORT_QUEUE
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671078] editor[1|1] request en-US open-ils.cstore.json_query.atomic {"from":"au","select":{"au":[{"params":["CREATE_BIB_IMPORT_QUEUE","vbq",14,"4"],"transform":"permission.usr_has_object_perm","alias":"has_perm","column":"id"}]},"where":{"id":"1"}}
open-ils.cstore 2011-11-08 11:08:24 [INFO:4385:osrf_application.c:1040:13205801212671078] CALL: open-ils.cstore open-ils.cstore.json_query.atomic {"from":"au","select":{"au":[{"params":["CREATE_BIB_IMPORT_QUEUE","vbq",14,"4"],"transform":"permission.usr_has_object_perm","alias":"has_perm","column":"id"}]},"where":{"id":"1"}}
open-ils.cstore 2011-11-08 11:08:24 [INFO:4385:osrf_app_session.c:991:13205801212671078] [open-ils.cstore] sent 357 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.cstore 2011-11-08 11:08:24 [INFO:4385:osrf_stack.c:159:13205801212671078] Message processing duration 0.013242
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671078] editor[1|1] json_query : returned 1 result(s)
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17316:Vandelay.pm:263:13205801212671078] vandelay spooling 476a713fc2f177ffe94679e90ae399c1 purpose= file=/tmp/476a713fc2f177ffe94679e90ae399c1.mrc
[2011-11-08 11:08:24] open-ils.vandelay [INFO:17316:Vandelay.pm:283:13205801212671078] processing record 0
[2011-11-08 11:08:25] open-ils.vandelay [ACT:17316:CStoreEditor.pm:109:13205801212671078] editor[1|1] vandelay.queued_bib_record.create bib_source=2 matches= import_time= purpose= create_time= isnew= imported_as= ischanged= marc=<record    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"    xsi:schemaLocation="http://www.loc.gov/MARC21/slim http://ww... id= queue=14 isdeleted= attributes=
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671078] editor[1|1] request en-US open-ils.cstore.direct.vandelay.queued_bib_record.create <new object>
open-ils.cstore 2011-11-08 11:08:25 [INFO:4385:osrf_application.c:1040:13205801212671078] CALL: open-ils.cstore open-ils.cstore.direct.vandelay.queued_bib_record.create {"__c":"vqbr","__p":[null,null,null,"<record    xmlns:xsi=\"http://www.w3.org/2001/XMLSchema-instance\"    xsi:schemaLocation=\"http://www.loc.gov/MARC21/slim http://www.loc.gov/standards/marcxml/schema/MARC21slim.xsd\"    xmlns=\"http://www.loc.gov/MARC21/slim\"><leader>00969cam a22002891  4500</leader><controlfield tag=\"001\">   26016523 /AC/r873</controlfield><controlfield tag=\"005\">20110512113308.0</controlfield><controlfield tag=\"008\">110512s1926    nyua   j      00011 eng  </controlfield><datafield tag=\"010\" ind1=\" \" ind2=\" \"><subfield code=\"a\">   26016523 /AC/r873</subfield></datafield><datafield tag=\"040\" ind1=\" \" ind2=\" \"><subfield code=\"c\">Wa</subfield><subfield code=\"d\">DLC</subfield></datafield><datafield tag=\"043\" ind1=\" \" ind2=\" \"><subfield code=\"a\">n-usp--</subfield></datafield><datafield tag=\"050\" ind1=\"0\" ind2=\" \"><subfield code=\"a\">QL795.H7</subfield><subfield code=\"b\">J3 1926</subfield></datafield><datafield tag=\"100\" ind1=\"1\" ind2=\"0\"><subfield code=\"a\">James, Will,</subfield><subfield code=\"d\">1892-1942.</subfield></datafield><datafield tag=\"245\" ind1=\"1\" ind2=\"0\"><subfield code=\"a\">Smoky, the cowhorse,</subfield><subfield code=\"c\">by Will James.</subfield></datafield><datafield tag=\"260\" ind1=\"0\" ind2=\" \"><subfield code=\"a\">[New York]</subfield><subfield code=\"b\">Scribner</subfield><subfield code=\"c\">[c1926]</subfield></datafield><datafield tag=\"300\" ind1=\" \" ind2=\" \"><subfield code=\"a\">xi, 310 p.</subfield><subfield code=\"b\">illus.</subfield><subfield code=\"c\">21 cm.</subfield></datafield><datafield tag=\"520\" ind1=\" \" ind2=\" \"><subfield code=\"a\">Describes the experiences of Smoky, the mouse-colored horse, from his birth on the range, his capture by humans, through his work in the rodeo and on the ranch, and his eventual old age.</subfield></datafield><datafield tag=\"650\" ind1=\" \" ind2=\"0\"><subfield code=\"a\">Horses</subfield><subfield code=\"x\">Juvenile fiction.</subfield></datafield><datafield tag=\"650\" ind1=\" \" ind2=\"1\"><subfield code=\"a\">Horses</subfield><subfield code=\"x\">Fiction.</subfield></datafield><datafield tag=\"651\" ind1=\" \" ind2=\"1\"><subfield code=\"a\">West (U.S.)</subfield><subfield code=\"x\">Fiction.</subfield></datafield><datafield tag=\"852\" ind1=\" \" ind2=\" \"><subfield code=\"c\"></subfield><subfield code=\"h\">PB FIC Jam</subfield><subfield code=\"p\">103250</subfield><subfield code=\"a\">SE</subfield></datafield><datafield tag=\"852\" ind1=\" \" ind2=\" \"><subfield code=\"c\"></subfield><subfield code=\"h\">PB FIC Jam</subfield><subfield code=\"p\">103251</subfield><subfield code=\"a\">SE</subfield></datafield><datafield tag=\"852\" ind1=\" \" ind2=\" \"><subfield code=\"c\"></subfield><subfield code=\"h\">PB FIC Jam</subfield><subfield code=\"p\">103252</subfield><subfield code=\"a\">SE</subfield></datafield><datafield tag=\"961\" ind1=\"w\" ind2=\"l\"><subfield code=\"t\">1</subfield></datafield><datafield tag=\"961\" ind1=\"w\" ind2=\"l\"><subfield code=\"t\">1</subfield></datafield><datafield tag=\"961\" ind1=\"w\" ind2=\"l\"><subfield code=\"t\">1</subfield></datafield><datafield tag=\"999\" ind1=\" \" ind2=\" \"><subfield code=\"c\">3</subfield><subfield code=\"d\">c</subfield></datafield></record>",14,"2"]}
open-ils.cstore 2011-11-08 11:08:25 [ERR :4385:oils_sql.c:2222:13205801212671078] open-ils.cstore ERROR inserting vandelay::queued_bib_record object using query [INSERT INTO vandelay.queued_bib_record (id,create_time,import_time,marc,queue,bib_source,imported_as,purpose) VALUES (DEFAULT,DEFAULT,DEFAULT,'<record    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"    xsi:schemaLocation="http://www.loc.gov/MARC21/slim http://www.loc.gov/standards/marcxml/schema/MARC21slim.xsd"    xmlns="http://www.loc.gov/MARC21/slim"><leader>00969cam a22002891  4500</leader><controlfield tag="001">   26016523 /AC/r873</controlfield><controlfield tag="005">20110512113308.0</controlfield><controlfield tag="008">110512s1926    nyua   j      00011 eng  </controlfield><datafield tag="010" ind1=" " ind2=" "><subfield code="a">   26016523 /AC/r873</subfield></datafield><datafield tag="040" ind1=" " ind2=" "><subfield code="c">Wa</subfield><subfield code="d">DLC</subfield></datafield><datafield tag="043" ind1=" " ind2=" "><subfield code="a">n-usp--</subfield></datafield><datafield tag="050" ind1="0" ind2=" "><subfield code="a">QL795.H7</subfield><subfield code="b">J3 1926</subfield></datafield><datafield tag="100" ind1="1" ind2="0"><subfield code="a">James, Will,</subfield><subfield code="d">1892-1942.</subfield></datafield><datafield tag="245" ind1="1" ind2="0"><subfield code="a">Smoky, the cowhorse,</subfield><subfield code="c">by Will James.</subfield></datafield><datafield tag="260" ind1="0" ind2=" "><subfield code="a">[New York]</subfield><subfield code="b">Scribner</subfield><subfield code="c">[c1926]</subfield></datafield><datafield tag="300" ind1=" " ind2=" "><subfield code="a">xi, 310 p.</subfield><subfield code="b">illus.</subfield><subfield code="c">21 cm.</subfield></datafield><datafield tag="520" ind1=" " ind2=" "><subfield code="a">Describes the experiences of Smoky, the mouse-colored horse, from his birth on the range, his capture by humans, through his work in the rodeo and on the ranch, and his eventual old age.</subfield></datafield><datafield tag="650" ind1=" " ind2="0"><subfield code="a">Horses</subfield><subfield code="x">Juvenile fiction.</subfield></datafield><datafield tag="650" ind1=" " ind2="1"><subfield code="a">Horses</subfield><subfield code="x">Fiction.</subfield></datafield><datafield tag="651" ind1=" " ind2="1"><subfield code="a">West (U.S.)</subfield><subfield code="x">Fiction.</subfield></datafield><datafield tag="852" ind1=" " ind2=" "><subfield code="c"></subfield><subfield code="h">PB FIC Jam</subfield><subfield code="p">103250</subfield><subfield code="a">SE</subfield></datafield><datafield tag="852" ind1=" " ind2=" "><subfield code="c"></subfield><subfield code="h">PB FIC Jam</subfield><subfield code="p">103251</subfield><subfield code="a">SE</subfield></datafield><datafield tag="852" ind1=" " ind2=" "><subfield code="c"></subfield><subfield code="h">PB FIC Jam</subfield><subfield code="p">103252</subfield><subfield code="a">SE</subfield></datafield><datafield tag="961" ind1="w" ind2="l"><subfield code="t">1</subfield></datafield><datafield tag="961" ind1="w" ind2="l"><subfield code="t">1</subfield></datafield><datafield tag="961" ind1="w" ind2="l"><subfield code="t">1</subfield></datafield><datafield tag="999" ind1=" " ind2=" "><subfield code="c">3</subfield><subfield code="d">c</subfield></datafield></record>',14,2,DEFAULT,DEFAULT);]: 0 ERROR:  invalid XPath expression
DETAIL:  Invalid expression
CONTEXT:  SQL function "oils_xpath" statement 1
PL/pgSQL function "oils_xpath_table" line 53 at FOR over EXECUTE statement
PL/pgSQL function "ingest_items" line 195 at FOR over SELECT rows
PL/pgSQL function "ingest_bib_items" line 8 at FOR over SELECT rows

open-ils.cstore 2011-11-08 11:08:25 [INFO:4385:osrf_app_session.c:991:13205801212671078] [open-ils.cstore] sent 218 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
[2011-11-08 11:08:25] open-ils.vandelay [ERR :17316:CStoreEditor.pm:109:13205801212671078] editor[1|1] request error open-ils.cstore.direct.vandelay.queued_bib_record.create : <new object> : Exception: OpenSRF::DomainObject::oilsMethodException 2011-11-08T11:08:25 OpenILS::Utils::CStoreEditor /usr/local/share/perl/5.10.1/OpenILS/Utils/CStoreEditor.pm:412 <500>  INSERT error -- please see the error log for more details

[2011-11-08 11:08:25] open-ils.vandelay [ERR :17316:EX.pm:66:13205801212671078] Exception: OpenSRF::DomainObject::oilsMethodException 2011-11-08T11:08:25 OpenILS::Utils::CStoreEditor /usr/local/share/perl/5.10.1/OpenILS/Utils/CStoreEditor.pm:425 <500>  INSERT error -- please see the error log for more details

[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671078] editor[1|1] request returned no data : open-ils.cstore.direct.vandelay.queued_bib_record.create
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671078] editor[1|1] rolling back db session
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671078] editor[1|1] request en-US open-ils.cstore.transaction.rollback []
open-ils.cstore 2011-11-08 11:08:25 [INFO:4385:osrf_app_session.c:991:13205801212671078] [open-ils.cstore] sent 343 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.cstore 2011-11-08 11:08:25 [WARN:4385:osrf_application.c:839:13205801212671078] Returning method exception with message: An unknown server error occurred
open-ils.cstore 2011-11-08 11:08:25 [INFO:4385:osrf_app_session.c:991:13205801212671078] [open-ils.cstore] sent 193 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.cstore 2011-11-08 11:08:25 [INFO:4385:osrf_stack.c:159:13205801212671078] Message processing duration 0.118413
open-ils.cstore 2011-11-08 11:08:25 [INFO:4385:osrf_app_session.c:991:13205801212671078] [open-ils.cstore] sent 373 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.cstore 2011-11-08 11:08:25 [INFO:4385:osrf_stack.c:159:13205801212671078] Message processing duration 0.001442
open-ils.cstore 2011-11-08 11:08:25 [INFO:4385:osrf_stack.c:159:13205801212671078] Message processing duration 0.000002
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:Transport.pm:161:13205801212671078] Message processing duration: 0.351
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17338:Application.pm:130:13205801212671079] CALL: open-ils.vandelay open-ils.vandelay.bib_queue.records.retrieve.atomic 9f93de9e89dfc5950448fc734516f506, 14, HASH(0xb64fb08)
open-ils.auth 2011-11-08 11:08:25 [INFO:17282:oils_auth.c:883:13205801212671079] CALL:	open-ils.auth open-ils.auth.session.retrieve - ["9f93de9e89dfc5950448fc734516f506",1]
open-ils.auth 2011-11-08 11:08:25 [INFO:17282:oils_event.c:46:13205801212671079] Creating new event: SUCCESS
open-ils.auth 2011-11-08 11:08:25 [INFO:17282:osrf_app_session.c:991:13205801212671079] [open-ils.auth] sent 723 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.auth 2011-11-08 11:08:25 [INFO:17282:osrf_stack.c:159:13205801212671079] Message processing duration 0.001881
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_app_session.c:991:13205801212671079] [open-ils.cstore] sent 180 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_stack.c:159:13205801212671079] Message processing duration 0.000428
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671079] editor[1|1] request en-US open-ils.cstore.transaction.begin []
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_app_session.c:991:13205801212671079] [open-ils.cstore] sent 373 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_stack.c:159:13205801212671079] Message processing duration 0.001171
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671079] editor[1|1] request en-US open-ils.cstore.direct.vandelay.bib_queue.retrieve 14
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_application.c:1040:13205801212671079] CALL: open-ils.cstore open-ils.cstore.direct.vandelay.bib_queue.retrieve 14
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_app_session.c:991:13205801212671079] [open-ils.cstore] sent 396 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_stack.c:159:13205801212671079] Message processing duration 0.003033
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671079] editor[1|1] checking perms user=1, org=4, perm=CREATE_BIB_IMPORT_QUEUE
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671079] editor[1|1] request en-US open-ils.cstore.json_query.atomic {"from":"au","select":{"au":[{"params":["CREATE_BIB_IMPORT_QUEUE","vbq",14,"4"],"transform":"permission.usr_has_object_perm","alias":"has_perm","column":"id"}]},"where":{"id":"1"}}
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_application.c:1040:13205801212671079] CALL: open-ils.cstore open-ils.cstore.json_query.atomic {"from":"au","select":{"au":[{"params":["CREATE_BIB_IMPORT_QUEUE","vbq",14,"4"],"transform":"permission.usr_has_object_perm","alias":"has_perm","column":"id"}]},"where":{"id":"1"}}
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_app_session.c:991:13205801212671079] [open-ils.cstore] sent 357 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_stack.c:159:13205801212671079] Message processing duration 0.002547
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671079] editor[1|1] json_query : returned 1 result(s)
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671079] editor[1|1] request en-US open-ils.cstore.direct.vandelay.queued_bib_record.id_list.atomic [{"import_time":null,"queue":14},{"order_by":{"vqbr":"id"},"limit":10,"offset":0}]
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_application.c:1040:13205801212671079] CALL: open-ils.cstore open-ils.cstore.direct.vandelay.queued_bib_record.id_list.atomic {"import_time":null,"queue":14},{"order_by":{"vqbr":"id"},"limit":10,"offset":0}
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_app_session.c:991:13205801212671079] [open-ils.cstore] sent 341 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_stack.c:159:13205801212671079] Message processing duration 0.002323
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671079] editor[1|1] vandelay.queued_bib_record.search : returned 0 result(s)
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671079] editor[1|1] rolling back db session
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17338:CStoreEditor.pm:109:13205801212671079] editor[1|1] request en-US open-ils.cstore.transaction.rollback []
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_app_session.c:991:13205801212671079] [open-ils.cstore] sent 373 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17338
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_stack.c:159:13205801212671079] Message processing duration 0.001350
open-ils.cstore 2011-11-08 11:08:25 [INFO:3717:osrf_stack.c:159:13205801212671079] Message processing duration 0.000002
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17338:Transport.pm:161:13205801212671079] Message processing duration: 0.088
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:Application.pm:130:13205801212671080] CALL: open-ils.vandelay open-ils.vandelay.bib_queue.summary.retrieve 9f93de9e89dfc5950448fc734516f506, 14
open-ils.auth 2011-11-08 11:08:25 [INFO:1310:oils_auth.c:883:13205801212671080] CALL:	open-ils.auth open-ils.auth.session.retrieve - ["9f93de9e89dfc5950448fc734516f506",1]
open-ils.auth 2011-11-08 11:08:25 [INFO:1310:oils_event.c:46:13205801212671080] Creating new event: SUCCESS
open-ils.auth 2011-11-08 11:08:25 [INFO:1310:osrf_app_session.c:991:13205801212671080] [open-ils.auth] sent 723 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.auth 2011-11-08 11:08:25 [INFO:1310:osrf_stack.c:159:13205801212671080] Message processing duration 0.001926
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_app_session.c:991:13205801212671080] [open-ils.cstore] sent 180 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_stack.c:159:13205801212671080] Message processing duration 0.000435
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671080] editor[1|1] request en-US open-ils.cstore.transaction.begin []
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_app_session.c:991:13205801212671080] [open-ils.cstore] sent 373 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_stack.c:159:13205801212671080] Message processing duration 0.001145
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671080] editor[1|1] request en-US open-ils.cstore.direct.vandelay.bib_queue.retrieve 14
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_application.c:1040:13205801212671080] CALL: open-ils.cstore open-ils.cstore.direct.vandelay.bib_queue.retrieve 14
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_app_session.c:991:13205801212671080] [open-ils.cstore] sent 396 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_stack.c:159:13205801212671080] Message processing duration 0.003104
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671080] editor[1|1] checking perms user=1, org=4, perm=CREATE_BIB_IMPORT_QUEUE
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671080] editor[1|1] request en-US open-ils.cstore.json_query.atomic {"from":"au","select":{"au":[{"params":["CREATE_BIB_IMPORT_QUEUE","vbq",14,"4"],"transform":"permission.usr_has_object_perm","alias":"has_perm","column":"id"}]},"where":{"id":"1"}}
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_application.c:1040:13205801212671080] CALL: open-ils.cstore open-ils.cstore.json_query.atomic {"from":"au","select":{"au":[{"params":["CREATE_BIB_IMPORT_QUEUE","vbq",14,"4"],"transform":"permission.usr_has_object_perm","alias":"has_perm","column":"id"}]},"where":{"id":"1"}}
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_app_session.c:991:13205801212671080] [open-ils.cstore] sent 357 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_stack.c:159:13205801212671080] Message processing duration 0.002522
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671080] editor[1|1] json_query : returned 1 result(s)
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671080] editor[1|1] request en-US open-ils.cstore.direct.vandelay.queued_bib_record.id_list.atomic {"queue":14}
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_application.c:1040:13205801212671080] CALL: open-ils.cstore open-ils.cstore.direct.vandelay.queued_bib_record.id_list.atomic {"queue":14}
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_app_session.c:991:13205801212671080] [open-ils.cstore] sent 341 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_stack.c:159:13205801212671080] Message processing duration 0.001915
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671080] editor[1|1] vandelay.queued_bib_record.search : returned 0 result(s)
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671080] editor[1|1] request en-US open-ils.cstore.direct.vandelay.queued_bib_record.id_list.atomic {"import_time":{"!=":null},"queue":14}
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_application.c:1040:13205801212671080] CALL: open-ils.cstore open-ils.cstore.direct.vandelay.queued_bib_record.id_list.atomic {"import_time":{"!=":null},"queue":14}
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_app_session.c:991:13205801212671080] [open-ils.cstore] sent 341 bytes of data to opensrf@private.localhost/open-ils.vandelay_drone_at_localhost_17316
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_stack.c:159:13205801212671080] Message processing duration 0.001977
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:CStoreEditor.pm:109:13205801212671080] editor[1|1] vandelay.queued_bib_record.search : returned 0 result(s)
open-ils.cstore 2011-11-08 11:08:25 [INFO:4384:osrf_stack.c:159:13205801212671080] Message processing duration 0.000002
[2011-11-08 11:08:25] open-ils.vandelay [INFO:17316:Transport.pm:161:13205801212671080] Message processing duration: 0.088