[Archivesspace_Users_Group] More on....Need help troubleshooting an error on CSV import

Thu Jun 11 13:03:32 EDT 2015

More on this...

I tracked down the Import Job log which I hope illuminates the error but
I'm not sure why I am getting it on the third and subsequent attempts to
import, when my first two batches came in just fine, with no permissions
denied.

Here's the whole of what was in the log for the failed attempt.  Below that
I also provided a snippet of a successful attempt for comparison, if that
helps.

-Nicole

==================================================
realdatatest_301ThruLine400.csv
==================================================

!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!  IMPORT ERROR
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Error: #<Errno::EACCES: Permission denied -
C:\UserFiles\archivesspace\data\tmp\import_batch_working_file_143397124790920150610-5076-lv1tbj>
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!

My successful import log presents as:

==================================================
realdatatest_ThruLine100.csv
==================================================
1. STARTED: Reading JSON records
1. DONE: Reading JSON records
2. STARTED: Validating records and checking links
2. DONE: Validating records and checking links
3. STARTED: Evaluating record relationships
3. DONE: Evaluating record relationships
4. STARTED: Saving records: cycle 1
Created:
/repositories/import/collection_management/import_e68ca983-91af-4840-aa69-3d31f9e63c84
Created:
/repositories/import/accessions/import_6aee3a46-a900-4ced-a796-8e33529c502c
Created:
/repositories/import/collection_management/import_7ab3d706-1faa-4cfd-a9be-fb63bf6b99cf
Created:
/repositories/import/accessions/import_68e0185f-0086-4d69-9e77-1609507229b1
Created:
/repositories/import/collection_management/import_da4f01fc-948d-47d0-8aea-c992f0195a2b
Created:
/repositories/import/accessions/import_375d782c-d1d9-4fde-b7af-77cb60d5a5c3
Created:
/repositories/import/collection_management/import_f218fb58-738d-4291-8965-419d5d9d9beb
Created:
/repositories/import/accessions/import_ab33edeb-a96b-4e22-922a-2cf4acba0e84
Created:
/repositories/import/collection_management/import_565c1632-2610-4acf-8288-ea72c35b9d3c
<snip>

******
Nicole Blechynden
Archivist
Heart Mountain Wyoming Foundation
1539 Road 19
Powell, WY 82435
307-754-8000 x103

On Thu, Jun 11, 2015 at 9:56 AM, Nicole Blechynden <
nicoleb at heartmountain.org> wrote:

> Hi all,
>
> I have a little over 600 accession records to import using the CSV
> template.  On my first attempt I received a non-specific error appearing on
> the Import Job:Job Status screen within the application so I began
> splitting these into batches of 100 records each.  My first two batches
> imported fine, exactly as expected but when I tried the third batch I again
> received a non-specific error.
>
> I opened the archivesspace.out log to see if that might yield any clues
> but couldn't make heads or tails of it, as far as identify what is failing
> in the process.
>
> I'm a couple versions back, using Version v1.1.2 running against the demo
> database (my current test environment).
>
> Here's a snippet of code from the .out log from one attempt:
>
> D, [2015-06-10T15:20:47.877000 #5076] DEBUG -- : Thread-14292: Import
> running for job 75
> E, [2015-06-10T15:20:47.924000 #5076] ERROR -- : Thread-14296: Job 75
> failed: Permission denied -
> C:\UserFiles\archivesspace\data\tmp\import_batch_working_file_143397124790920150610-5076-lv1tbj
> ["org/jruby/RubyFile.java:1106:in `unlink'",
> "C:/UserFiles/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/converters/converter.rb:22:in
> `remove_files'",
> "C:/UserFiles/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/converters/lib/parse_queue.rb:85:in
> `each_open_file_path'",
> "C:/UserFiles/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/converters/converter.rb:21:in
> `remove_files'",
> "C:/UserFiles/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/batch_import_runner.rb:80:in
> `run'", "org/jruby/RubyArray.java:1613:in `each'",
> "org/jruby/RubyEnumerable.java:977:in `each_with_index'",
> "C:/UserFiles/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/batch_import_runner.rb:63:in
> `run'",
> "C:/UserFiles/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/db.rb:125:in
> `open'", "org/jruby/RubyFixnum.java:280:in `times'",
> "C:/UserFiles/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/db.rb:113:in
> `open'",
> "C:/UserFiles/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/batch_import_runner.rb:59:in
> `run'",
> "C:/UserFiles/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/batch_import_job_queue.rb:96:in
> `run_pending_import'",
> "C:/UserFiles/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/batch_import_job_queue.rb:123:in
> `start_background_thread'"]
> Started GET "/jobs/75/status" for 0:0:0:0:0:0:0:1 at 2015-06-10 15:20:47
> -0600
> Processing by JobsController#status as JSON
>   Parameters: {"id"=>"75"}
> D, [2015-06-10T15:20:48.018000 #5076] DEBUG -- : Thread-13264: GET
> /repositories/4/jobs/75 [session: #<Session:0x91cfe @store={:user=>"admin",
> :login_time=>2015-06-10 15:17:42 -0600, :expirable=>true},
> @id="35a81ae84f5476b18dca98bab372f309ef68464c588359398c4f25e917d14cdf">]
> D, [2015-06-10T15:20:48.018000 #5076] DEBUG -- : Thread-13264:
> Post-processed params: {:id=>75, :repo_id=>4}
> D, [2015-06-10T15:20:48.081000 #5076] DEBUG -- : Thread-13264: Responded
> with [200, {"Content-Type"=>"application/json", "Cache-Control"=>"private,
> must-revalidate, max-age=0", "Content-Length"=>"469"},
> ["{\"import_type\":\"accession_csv\",\"lock_version\":2,\"filenames\":[\"realdatatest_301ThruLine400.csv\"],\"time_submitted\":\"2015-06-10
> 21:20:46 UTC\",\"time_started\":\"2015-06-10 21:20:47
> UTC\",\"status\":\"running\",\"created_by\":\"admin\",\"last_modified_by\":\"admin\",\"create_time\":\"2015-06-10T21:20:46Z\",\"system_mtime\":\"2015-06-10T21:20:47Z\",\"user_mtime\":\"2015-06-1...
> in 94.0ms
> Completed 200 OK in 125.0ms (Views: 0.0ms)
> Started GET "/jobs/75" for 0:0:0:0:0:0:0:1 at 2015-06-10 15:20:48 -0600
> Processing by JobsController#show as HTML
>   Parameters: {"id"=>"75"}
> D, [2015-06-10T15:20:48.221000 #5076] DEBUG -- : Thread-6996: GET
> /repositories/4/jobs/75?resolve%5B%5D=repository [session:
> #<Session:0x1cfa0ee @store={:user=>"admin", :login_time=>2015-06-10
> 15:17:42 -0600, :expirable=>true},
> @id="35a81ae84f5476b18dca98bab372f309ef68464c588359398c4f25e917d14cdf">]
> D, [2015-06-10T15:20:48.221000 #5076] DEBUG -- : Thread-6996:
> Post-processed params: {:id=>75, :resolve=>["repository"], :repo_id=>4}
> D, [2015-06-10T15:20:48.284000 #5076] DEBUG -- : Thread-6996: Responded
> with [200, {"Content-Type"=>"application/json", "Cache-Control"=>"private,
> must-revalidate, max-age=0", "Content-Length"=>"826"},
> ["{\"import_type\":\"accession_csv\",\"lock_version\":2,\"filenames\":[\"realdatatest_301ThruLine400.csv\"],\"time_submitted\":\"2015-06-10
> 21:20:46 UTC\",\"time_started\":\"2015-06-10 21:20:47
> UTC\",\"status\":\"running\",\"created_by\":\"admin\",\"last_modified_by\":\"admin\",\"create_time\":\"2015-06-10T21:20:46Z\",\"system_mtime\":\"2015-06-10T21:20:47Z\",\"user_mtime\":\"2015-06-1...
> in 78.0ms
>   Rendered shared/_breadcrumb.html.erb (16.0ms)
>   Rendered jobs/_show_templates.html.erb (0.0ms)
>   Rendered shared/_sidebar_entry.html.erb (0.0ms)
>   Rendered shared/_sidebar_entry.html.erb (0.0ms)
>   Rendered shared/_sidebar_entry.html.erb (0.0ms)
>   Rendered shared/_sidebar.html.erb (0.0ms)
>   Rendered jobs/_sidebar.html.erb (0.0ms)
>   Rendered jobs/_toolbar.html.erb (0.0ms)
>   Rendered shared/_flash_messages.html.erb (0.0ms)
>   Rendered shared/_flash_messages.html.erb (0.0ms)
>   Rendered jobs/show.html.erb within layouts/application (110.0ms)
>   Rendered shared/_browser_support.html.erb (16.0ms)
>   Rendered shared/_header_user.html.erb (31.0ms)
>   Rendered shared/_header_global.html.erb (31.0ms)
>   Rendered site/_branding.html.erb (0.0ms)
>   Rendered shared/_advanced_search.html.erb (16.0ms)
>   Rendered shared/_header_repository.html.erb (94.0ms)
>   Rendered
> C:/UserFiles/archivesspace/plugins/aspace_feedback/frontend/views/site/_feedback_form.html.erb
> (0.0ms)
>   Rendered
> C:/UserFiles/archivesspace/plugins/aspace_feedback/frontend/views/site/_footer.html.erb
> (16.0ms)
>   Rendered shared/_templates.html.erb (15.0ms)
> Completed 200 OK in 406.0ms (Views: 312.0ms)
> Started GET "/jobs/75/log?offset=0" for 0:0:0:0:0:0:0:1 at 2015-06-10
> 15:20:48 -0600
> Processing by JobsController#log as */*
>   Parameters: {"offset"=>"0", "id"=>"75"}
> Completed 200 OK in 16.0ms
> D, [2015-06-10T15:20:48.987000 #5076] DEBUG -- : Thread-13264: GET
> /repositories/4/jobs/75/log?offset=0 [session: #<Session:0xa7438f
> @store={:user=>"admin", :login_time=>2015-06-10 15:17:42 -0600,
> :expirable=>true},
> @id="35a81ae84f5476b18dca98bab372f309ef68464c588359398c4f25e917d14cdf">]
> D, [2015-06-10T15:20:48.987000 #5076] DEBUG -- : Thread-13264:
> Post-processed params: {:id=>75, :repo_id=>4, :offset=>0}
> D, [2015-06-10T15:20:49.049000 #5076] DEBUG -- : Thread-13264: Responded
> with [200, {"Content-Type"=>"text/plain", "Cache-Control"=>"private,
> must-revalidate, max-age=0", "Content-Length"=>"499"}, #<Enumerator:
> #<JRuby::Generator::Threaded:0x1790ec7 @block=#<Proc:0x410aaa at C:/UserFiles/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/controllers/job.rb:116>,
> @next_element=nil, @index=0,
> @queue_finalizer=#<JRuby::Generator::Threaded::QueueFinalizer:0xc80a7c
> @queue=#<JRuby::Generator::Threaded::ProducerQueue:0x4debc2>>,
> @queue=#<JRuby::Generator::Threaded::... in 93.0ms
>
>
> ******
> Nicole Blechynden
> Archivist
> Heart Mountain Wyoming Foundation
> 1539 Road 19
> Powell, WY 82435
> 307-754-8000 x103
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lyralists.lyrasis.org/pipermail/archivesspace_users_group/attachments/20150611/6661d765/attachment.html>