[Archivesspace_Users_Group] 2.1.2 re-indexing loop

Fri Sep 15 13:44:44 EDT 2017

I notice a repeating error and stacktrace in the log about an unhandled exception.

E, [2017-09-15T09:45:13.168412 #10788] ERROR -- : Thread-5342: Unhandled exception!
E, [2017-09-15T09:45:13.168722 #10788] ERROR -- :
key not found: :
org/jruby/RubyHash.java:1189:in `fetch'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/ancestor_listing.rb:63:in `root_record'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/ancestor_listing.rb:22:in `block in add_ancestors'
org/jruby/RubyArray.java:1734:in `each'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/ancestor_listing.rb:12:in `add_ancestors'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/archival_object.rb:69:in `sequel_to_jsonmodel'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/crud_helpers.rb:105:in `listing_response'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/crud_helpers.rb:68:in `handle_listing'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/controllers/archival_object.rb:95:in `block in ArchivesSpaceService'
org/jruby/RubyBasicObject.java:1687:in `instance_eval'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/rest.rb:280:in `block in returns'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/db.rb:111:in `block in open'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/db.rb:75:in `block in transaction'
/usr/local/archivesspace/gems/gems/sequel-4.20.0/lib/sequel/database/transactions.rb:134:in `_transaction'
/usr/local/archivesspace/gems/gems/sequel-4.20.0/lib/sequel/database/transactions.rb:108:in `block in transaction'
/usr/local/archivesspace/gems/gems/sequel-4.20.0/lib/sequel/connection_pool/threaded.rb:98:in `hold'
/usr/local/archivesspace/gems/gems/sequel-4.20.0/lib/sequel/database/connecting.rb:255:in `synchronize'
/usr/local/archivesspace/gems/gems/sequel-4.20.0/lib/sequel/database/transactions.rb:97:in `transaction'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/db.rb:74:in `transaction'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/db.rb:110:in `block in open'
org/jruby/RubyFixnum.java:305:in `times'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/db.rb:107:in `open'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/db.rb:432:in `block in DB'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/rest.rb:262:in `block in returns'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/request_context.rb:24:in `open'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/rest.rb:230:in `block in returns'
org/jruby/RubyMethod.java:111:in `call'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1611:in `block in compile!'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:975:in `block in route!'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:994:in `route_eval'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:975:in `block in route!'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1015:in `block in process_route'
org/jruby/RubyKernel.java:1120:in `catch'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1013:in `process_route'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:973:in `block in route!'
org/jruby/RubyArray.java:1734:in `each'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:972:in `route!'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1085:in `block in dispatch!'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1067:in `block in invoke'
org/jruby/RubyKernel.java:1120:in `catch'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1067:in `invoke'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1082:in `dispatch!'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:907:in `block in call!'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1067:in `block in invoke'
org/jruby/RubyKernel.java:1120:in `catch'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1067:in `invoke'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:907:in `call!'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:895:in `call'
/usr/local/archivesspace-v2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/main.rb:291:in `call'
/usr/local/archivesspace/gems/gems/rack-protection-1.5.3/lib/rack/protection/xss_header.rb:18:in `call'
/usr/local/archivesspace/gems/gems/rack-protection-1.5.3/lib/rack/protection/path_traversal.rb:16:in `call'
/usr/local/archivesspace/gems/gems/rack-protection-1.5.3/lib/rack/protection/json_csrf.rb:18:in `call'
/usr/local/archivesspace/gems/gems/rack-protection-1.5.3/lib/rack/protection/base.rb:49:in `call'
/usr/local/archivesspace/gems/gems/rack-protection-1.5.3/lib/rack/protection/base.rb:49:in `call'
/usr/local/archivesspace/gems/gems/rack-protection-1.5.3/lib/rack/protection/frame_options.rb:31:in `call'
uri:classloader:/vendor/rack-1.5.5/rack/nulllogger.rb:9:in `call'
uri:classloader:/vendor/rack-1.5.5/rack/head.rb:11:in `call'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:182:in `call'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:2013:in `call'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1487:in `block in call'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1787:in `synchronize'
/usr/local/archivesspace/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1487:in `call'
uri:classloader:/vendor/rack-1.5.5/rack/builder.rb:138:in `call'
uri:classloader:/vendor/rack-1.5.5/rack/urlmap.rb:65:in `block in call'
org/jruby/RubyArray.java:1734:in `each'
uri:classloader:/vendor/rack-1.5.5/rack/urlmap.rb:50:in `call'
uri:classloader:/rack/handler/servlet.rb:22:in `call'
D, [2017-09-15T09:45:13.169154 #10788] DEBUG -- : Thread-5342: Responded with [500, {"Content-Type"=>"application/json", "Cache-Control"=>"private, must-revalidate, max-age=0", "Content-Length"=>"29"}, ["{\"error\":\"key not found: :\"}\n"]]... in 247ms

From: archivesspace_users_group-bounces at lyralists.lyrasis.org [mailto:archivesspace_users_group-bounces at lyralists.lyrasis.org] On Behalf Of Stanonik, Ronald
Sent: Friday, September 15, 2017 9:48 AM
To: archivesspace_users_group at lyralists.lyrasis.org
Subject: [Archivesspace_Users_Group] 2.1.2 re-indexing loop

I recently upgraded to 2.1.2 and it seems to be in an indexing loop.

I restarted the application.

I removed the solr index and restarted the application.

In the log I see it counting up

Staff Indexer [2017-09-15 07:42:21 -0700] ~~~ Indexed 185825 of 212959 archival_object records in repository SC&A
...
Staff Indexer [2017-09-15 03:50:30 -0700] ~~~ Indexed 201525 of 212959 archival_object records in repository SC&A

But then

Staff Indexer [2017-09-15 04:09:49 -0700] ~~~ Indexed 25 of 212959 archival_object records in repository SC&A

Since yesterday it has re-indexed ten times.

The resulting constant re-indexing causes a high load average and slow performance for users.

Any suggestions?

Thanks,

Ron

ps.  I also posted this question to https://groups.google.com/forum/#!forum/archivesspace.  Sorry if that is redundant.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lyralists.lyrasis.org/pipermail/archivesspace_users_group/attachments/20170915/69f68b2e/attachment.html>