[Archivesspace_Users_Group] 2.1.2 re-indexing loop

Fri Sep 22 11:36:02 EDT 2017

To add another datapoint, when I change the publish status for all items in a node's immediate tree (ie file-> parent box -> parent series) then the child node and its parents will appear in the staff interface. If the AO or *any* of its ancestors are *not* published, they do *not* appear in the staff interface.

I took a quick look at the database and the publish status for *most* of our AOs is "NULL", not the 1 or 0 that large_tree.rb is looking for in published_filter (line 73). I'm currently thinking that our initial custom migration never set that column...

Joshua

________________________________
From: archivesspace_users_group-bounces at lyralists.lyrasis.org <archivesspace_users_group-bounces at lyralists.lyrasis.org> on behalf of Joshua D. Shaw <Joshua.D.Shaw at dartmouth.edu>
Sent: Thursday, September 21, 2017 4:54:04 PM
To: Archivesspace Users Group
Subject: Re: [Archivesspace_Users_Group] 2.1.2 re-indexing loop

This sender failed our fraud detection checks and may not be who they appear to be. Learn about spoofing<http://aka.ms/LearnAboutSpoofing>
        Feedback<http://aka.ms/SafetyTipsFeedback>

I'd love to know the solution as well, since I'm seeing a similar/related(?) error as I'm starting to test 2.1.2 locally. I've migrated from a 1.5.3 instance and see the following error when attempting to view an archival object. The archival object information renders in the record pane, but the tree fails to populate anything except the collection level. I checked the db and the id being referenced (14195) does exist in the archival_object table (I think that's what the id is referencing - assuming I'm reading the code right). This is running with only one plugin (our omniauthCas) plugin enabled, though the database contains some additional tables from some of our other plugins

key not found: :14195
org/jruby/RubyHash.java:1189:in `fetch'
/Applications/archivesspace-2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/large_tree.rb:203:in `block in node_from_root'
org/jruby/RubyArray.java:1734:in `each'
/Applications/archivesspace-2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/large_tree.rb:193:in `block in node_from_root'
/Applications/archivesspace-2.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'
/Applications/archivesspace-2.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'
/Applications/archivesspace-2.1.2/gems/gems/sequel-4.20.0/lib/sequel/database/transactions.rb:105:in `block in transaction'
/Applications/archivesspace-2.1.2/gems/gems/sequel-4.20.0/lib/sequel/connection_pool/threaded.rb:85:in `hold'
/Applications/archivesspace-2.1.2/gems/gems/sequel-4.20.0/lib/sequel/database/connecting.rb:255:in `synchronize'
/Applications/archivesspace-2.1.2/gems/gems/sequel-4.20.0/lib/sequel/database/transactions.rb:97:in `transaction'
/Applications/archivesspace-2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/db.rb:74:in `transaction'
/Applications/archivesspace-2.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'
/Applications/archivesspace-2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/db.rb:107:in `open'
/Applications/archivesspace-2.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'
/Applications/archivesspace-2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/large_tree.rb:145:in `node_from_root'
/Applications/archivesspace-2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/controllers/resource.rb:203:in `block in ArchivesSpaceService'
org/jruby/RubyBasicObject.java:1687:in `instance_eval'
/Applications/archivesspace-2.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'
/Applications/archivesspace-2.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'
/Applications/archivesspace-2.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'
/Applications/archivesspace-2.1.2/gems/gems/sequel-4.20.0/lib/sequel/database/transactions.rb:134:in `_transaction'
/Applications/archivesspace-2.1.2/gems/gems/sequel-4.20.0/lib/sequel/database/transactions.rb:108:in `block in transaction'
/Applications/archivesspace-2.1.2/gems/gems/sequel-4.20.0/lib/sequel/connection_pool/threaded.rb:98:in `hold'
/Applications/archivesspace-2.1.2/gems/gems/sequel-4.20.0/lib/sequel/database/connecting.rb:255:in `synchronize'
/Applications/archivesspace-2.1.2/gems/gems/sequel-4.20.0/lib/sequel/database/transactions.rb:97:in `transaction'
/Applications/archivesspace-2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/db.rb:74:in `transaction'
/Applications/archivesspace-2.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'
/Applications/archivesspace-2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/model/db.rb:107:in `open'
/Applications/archivesspace-2.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'
/Applications/archivesspace-2.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'
/Applications/archivesspace-2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/request_context.rb:24:in `open'
/Applications/archivesspace-2.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'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1611:in `block in compile!'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:975:in `block in route!'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:994:in `route_eval'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:975:in `block in route!'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1015:in `block in process_route'
org/jruby/RubyKernel.java:1120:in `catch'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1013:in `process_route'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:973:in `block in route!'
org/jruby/RubyArray.java:1734:in `each'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:972:in `route!'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1085:in `block in dispatch!'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1067:in `block in invoke'
org/jruby/RubyKernel.java:1120:in `catch'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1067:in `invoke'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1082:in `dispatch!'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:907:in `block in call!'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1067:in `block in invoke'
org/jruby/RubyKernel.java:1120:in `catch'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1067:in `invoke'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:907:in `call!'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:895:in `call'
/Applications/archivesspace-2.1.2/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/main.rb:291:in `call'
/Applications/archivesspace-2.1.2/gems/gems/rack-protection-1.5.3/lib/rack/protection/xss_header.rb:18:in `call'
/Applications/archivesspace-2.1.2/gems/gems/rack-protection-1.5.3/lib/rack/protection/path_traversal.rb:16:in `call'
/Applications/archivesspace-2.1.2/gems/gems/rack-protection-1.5.3/lib/rack/protection/json_csrf.rb:18:in `call'
/Applications/archivesspace-2.1.2/gems/gems/rack-protection-1.5.3/lib/rack/protection/base.rb:49:in `call'
/Applications/archivesspace-2.1.2/gems/gems/rack-protection-1.5.3/lib/rack/protection/base.rb:49:in `call'
/Applications/archivesspace-2.1.2/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'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:182:in `call'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:2013:in `call'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1487:in `block in call'
/Applications/archivesspace-2.1.2/gems/gems/sinatra-1.4.7/lib/sinatra/base.rb:1787:in `synchronize'
/Applications/archivesspace-2.1.2/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'

________________________________
From: archivesspace_users_group-bounces at lyralists.lyrasis.org <archivesspace_users_group-bounces at lyralists.lyrasis.org> on behalf of Stanonik, Ronald <rstanonik at ucsd.edu>
Sent: Friday, September 15, 2017 1:44:44 PM
To: Archivesspace Users Group
Subject: Re: [Archivesspace_Users_Group] 2.1.2 re-indexing loop

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<https://na01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgroups.google.com%2Fforum%2F%23!forum%2Farchivesspace&data=02%7C01%7Cjoshua.d.shaw%40dartmouth.edu%7C028f6cddc8a54f13039908d4fc61778d%7C995b093648d640e5a31ebf689ec9446f%7C0%7C0%7C636410942941690532&sdata=WypeTQ4t6O31ExmAoPwc34i%2B6%2BrkDCVV%2Fg6nYbnizPI%3D&reserved=0>.  Sorry if that is redundant.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lyralists.lyrasis.org/pipermail/archivesspace_users_group/attachments/20170922/0de17c96/attachment.html>