[Archivesspace_Users_Group] Need help troubleshooting an error on CSV import

Mon Jun 15 07:42:58 EDT 2015

Hi,

Yes, this is a known problem with Windows file systems. Essentially the file system thinks that the file is still in use, so it won't delete the file. It's been fixed in the release that is upcoming at the end of the month. I can provide a patch to fix this if you'd like it sooner.

b,chris.

Chris Fitzpatrick | Developer, ArchivesSpace
Skype: chrisfitzpat  | Phone: 918.236.6048
http://archivesspace.org/
________________________________
From: archivesspace_users_group-bounces at lyralists.lyrasis.org <archivesspace_users_group-bounces at lyralists.lyrasis.org> on behalf of Nicole Blechynden <nicoleb at heartmountain.org>
Sent: Thursday, June 11, 2015 5:56 PM
To: archivesspace_users_group at lyralists.lyrasis.org
Subject: [Archivesspace_Users_Group] Need help troubleshooting an error on CSV import

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/20150615/3c770ef7/attachment.html>