Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SystemStackError (stack level too deep) in Hyrax::FileSetsController#destroy #4581

Closed
conorom opened this issue Nov 13, 2020 · 20 comments
Closed

Comments

@conorom
Copy link
Contributor

conorom commented Nov 13, 2020

Using the UI to delete a FileSet from a Work fails when the Work has "many" FileSets

2.8.0, 3.0.0.pre.rc2

Rationale

This seems to be a new issue or regression. Possibly in underlying gems. Apologies but I don't know enough about ActiveFedora/RDF to assign the issue to another gem.

Expected behavior

FileSet should be deleted as expected. I guess something is going wrong with rebuilding the ListSource (total guess). Something recursion-related, perhaps?

Actual behavior

Page spins for a while and then fails with SystemStackError (stack level too deep)

Steps to reproduce the behavior

  1. Add a bunch of FileSets to a new or existing Work. On fulcrum.org we've seen this failure with Works with 93 and 195 FileSets. On Nurax >=122 seems to cause it. Might as well ingest 150 to be sure. The issue is easily replicable in development.

aside: This is an easy way to make a bunch of small < 10KB files to use (causing minimal ingest overhead)

for i in {001..150}; do head -c 10000 </dev/urandom >randfile$i; done
for f in randfile*; do mv $f `printf randfile%03d ${f#randfile}`; done 
  1. Allow ingest to complete.
  2. Delete any FileSet from the Work. Doesn't matter if it's at the start or end of the ListSource (ordered_members). The problem happens whether you use the drop-down delete action on the Work page or the "Delete This File" button on the FileSet page.
  3. Let the page spin and observe the eventual failure.

Stack trace from Nurax:

rdf (3.0.13) lib/rdf/mixin/enumerable.rb:480:in `include?'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:480:in `block in each_object'
rdf (3.0.13) lib/rdf/mixin/queryable.rb:291:in `<<'
rdf (3.0.13) lib/rdf/mixin/queryable.rb:291:in `block (2 levels) in enum_for'
rdf (3.0.13) lib/rdf/repository.rb:408:in `block (4 levels) in query_pattern'
hamster (3.0.0) lib/hamster/trie.rb:40:in `block in each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/hash.rb:331:in `each'
rdf (3.0.13) lib/rdf/repository.rb:406:in `block (3 levels) in query_pattern'
hamster (3.0.0) lib/hamster/trie.rb:40:in `block in each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/hash.rb:331:in `each'
rdf (3.0.13) lib/rdf/repository.rb:405:in `block (2 levels) in query_pattern'
rdf (3.0.13) lib/rdf/repository.rb:397:in `each'
rdf (3.0.13) lib/rdf/repository.rb:397:in `block in query_pattern'
hamster (3.0.0) lib/hamster/trie.rb:40:in `block in each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/hash.rb:331:in `each'
rdf (3.0.13) lib/rdf/repository.rb:385:in `query_pattern'
rdf (3.0.13) lib/rdf/mixin/queryable.rb:291:in `block in enum_for'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:159:in `each'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:159:in `each'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:159:in `each_statement'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:478:in `each_object'
active-triples (1.1.0) lib/active_triples/util/extended_bounded_description.rb:63:in `each_statement'
.
.
.
#############################################################################
### This part repeats 122 times on Nurax (presumably once per FileSet until stack limit is reached) ###

active-triples (1.1.0) lib/active_triples/util/extended_bounded_description.rb:66:in `block in each_statement'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:482:in `block in each_object'
rdf (3.0.13) lib/rdf/mixin/queryable.rb:291:in `<<'
rdf (3.0.13) lib/rdf/mixin/queryable.rb:291:in `block (2 levels) in enum_for'
rdf (3.0.13) lib/rdf/repository.rb:408:in `block (4 levels) in query_pattern'
hamster (3.0.0) lib/hamster/trie.rb:40:in `block in each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/hash.rb:331:in `each'
rdf (3.0.13) lib/rdf/repository.rb:406:in `block (3 levels) in query_pattern'
hamster (3.0.0) lib/hamster/trie.rb:40:in `block in each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/hash.rb:331:in `each'
rdf (3.0.13) lib/rdf/repository.rb:405:in `block (2 levels) in query_pattern'
rdf (3.0.13) lib/rdf/repository.rb:397:in `each'
rdf (3.0.13) lib/rdf/repository.rb:397:in `block in query_pattern'
hamster (3.0.0) lib/hamster/trie.rb:40:in `block in each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/hash.rb:331:in `each'
rdf (3.0.13) lib/rdf/repository.rb:385:in `query_pattern'
rdf (3.0.13) lib/rdf/mixin/queryable.rb:291:in `block in enum_for'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:159:in `each'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:159:in `each'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:159:in `each_statement'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:478:in `each_object'
active-triples (1.1.0) lib/active_triples/util/extended_bounded_description.rb:63:in `each_statement'
#############################################################################
.
.
.
rdf (3.0.13) lib/rdf/transaction.rb:77:in `each'
active-triples (1.1.0) lib/active_triples/rdf_source.rb:90:in `each'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:691:in `to_a'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:691:in `to_a'
active-triples (1.1.0) lib/active_triples/persistence_strategies/parent_strategy.rb:128:in `reload'
active-triples (1.1.0) lib/active_triples/persistable.rb:101:in `reload'
active-triples (1.1.0) lib/active_triples/rdf_source.rb:126:in `initialize'
active-triples (1.1.0) lib/active_triples/rdf_source.rb:703:in `new'
active-triples (1.1.0) lib/active_triples/rdf_source.rb:703:in `from_uri'
active-triples (1.1.0) lib/active_triples/relation.rb:583:in `make_node'
active-triples (1.1.0) lib/active_triples/relation.rb:469:in `convert_object'
active-triples (1.1.0) lib/active_triples/relation.rb:322:in `block in each'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:482:in `block in each_object'
rdf (3.0.13) lib/rdf/mixin/queryable.rb:291:in `<<'
rdf (3.0.13) lib/rdf/mixin/queryable.rb:291:in `block (2 levels) in enum_for'
rdf (3.0.13) lib/rdf/repository.rb:408:in `block (4 levels) in query_pattern'
hamster (3.0.0) lib/hamster/trie.rb:40:in `block in each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/trie.rb:40:in `each'
hamster (3.0.0) lib/hamster/hash.rb:331:in `each'
rdf (3.0.13) lib/rdf/repository.rb:406:in `block (3 levels) in query_pattern'
rdf (3.0.13) lib/rdf/repository.rb:405:in `each'
rdf (3.0.13) lib/rdf/repository.rb:405:in `block (2 levels) in query_pattern'
rdf (3.0.13) lib/rdf/repository.rb:397:in `each'
rdf (3.0.13) lib/rdf/repository.rb:397:in `block in query_pattern'
rdf (3.0.13) lib/rdf/repository.rb:385:in `each'
rdf (3.0.13) lib/rdf/repository.rb:385:in `query_pattern'
rdf (3.0.13) lib/rdf/mixin/queryable.rb:291:in `block in enum_for'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:159:in `each'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:159:in `each'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:159:in `each_statement'
rdf (3.0.13) lib/rdf/mixin/enumerable.rb:478:in `each_object'
active-triples (1.1.0) lib/active_triples/relation.rb:487:in `objects'
active-triples (1.1.0) lib/active_triples/relation.rb:321:in `each'
active-triples (1.1.0) lib/active_triples/relation.rb:37:in `to_a'
active-triples (1.1.0) lib/active_triples/relation.rb:37:in `size'
active-fedora (13.2.0) lib/active_fedora/attributes/property_builder.rb:32:in `tail'
active-fedora (13.2.0) lib/active_fedora/attributes.rb:52:in `[]'
active-fedora (13.2.0) lib/active_fedora/attributes.rb:43:in `block in attributes'
active-fedora (13.2.0) lib/active_fedora/attributes.rb:43:in `each'
active-fedora (13.2.0) lib/active_fedora/attributes.rb:43:in `each_with_object'
active-fedora (13.2.0) lib/active_fedora/attributes.rb:43:in `attributes'
active-fedora (13.2.0) lib/active_fedora/attribute_methods/read.rb:39:in `_read_attribute'
activemodel (5.2.4.4) lib/active_model/dirty.rb:316:in `attribute_will_change!'
activemodel (5.2.4.4) lib/active_model/attribute_methods.rb:439:in `attribute_missing'
activemodel (5.2.4.4) lib/active_model/attribute_methods.rb:430:in `method_missing'
active-fedora (13.2.0) lib/active_fedora/aggregation/list_source.rb:69:in `persist_ordered_self'
active-fedora (13.2.0) lib/active_fedora/aggregation/list_source.rb:11:in `save'
active-fedora (13.2.0) lib/active_fedora/persistence.rb:263:in `block in save_contained_resources'
active-fedora (13.2.0) lib/active_fedora/persistence.rb:262:in `each'
active-fedora (13.2.0) lib/active_fedora/persistence.rb:262:in `save_contained_resources'
active-fedora (13.2.0) lib/active_fedora/persistence.rb:196:in `_update_record'
active-fedora (13.2.0) lib/active_fedora/indexing.rb:79:in `_update_record'
active-fedora (13.2.0) lib/active_fedora/callbacks.rb:249:in `block in _update_record'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:132:in `run_callbacks'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:816:in `_run_update_callbacks'
active-fedora (13.2.0) lib/active_fedora/callbacks.rb:249:in `_update_record'
active-fedora (13.2.0) lib/active_fedora/persistence.rb:179:in `create_or_update'
active-fedora (13.2.0) lib/active_fedora/callbacks.rb:241:in `block in create_or_update'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:132:in `run_callbacks'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:816:in `_run_save_callbacks'
active-fedora (13.2.0) lib/active_fedora/callbacks.rb:241:in `create_or_update'
active-fedora (13.2.0) lib/active_fedora/persistence.rb:44:in `save!'
active-fedora (13.2.0) lib/active_fedora/validations.rb:56:in `save!'
active-fedora (13.2.0) lib/active_fedora/associations/builder/orders.rb:50:in `save!'
hydra-works (1.2.0) lib/hydra/works/models/concerns/file_set_behavior.rb:76:in `block in remove_from_works'
hydra-works (1.2.0) lib/hydra/works/models/concerns/file_set_behavior.rb:73:in `each'
hydra-works (1.2.0) lib/hydra/works/models/concerns/file_set_behavior.rb:73:in `remove_from_works'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:426:in `block in make_lambda'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:198:in `block (2 levels) in halting'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:606:in `block (2 levels) in default_terminator'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:605:in `catch'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:605:in `block in default_terminator'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:199:in `block in halting'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:513:in `block in invoke_before'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:513:in `each'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:513:in `invoke_before'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:131:in `run_callbacks'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:816:in `_run_destroy_callbacks'
active-fedora (13.2.0) lib/active_fedora/callbacks.rb:231:in `destroy'
/opt/nurax/shared/bundle/ruby/2.6.0/bundler/gems/hyrax-940e1003e35b/app/actors/hyrax/actors/file_set_actor.rb:127:in `destroy'
/opt/nurax/shared/bundle/ruby/2.6.0/bundler/gems/hyrax-940e1003e35b/app/controllers/hyrax/file_sets_controller.rb:51:in `destroy'
actionpack (5.2.4.4) lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
actionpack (5.2.4.4) lib/abstract_controller/base.rb:194:in `process_action'
actionpack (5.2.4.4) lib/action_controller/metal/rendering.rb:30:in `process_action'
actionpack (5.2.4.4) lib/abstract_controller/callbacks.rb:42:in `block in process_action'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:132:in `run_callbacks'
actionpack (5.2.4.4) lib/abstract_controller/callbacks.rb:41:in `process_action'
actionpack (5.2.4.4) lib/action_controller/metal/rescue.rb:22:in `process_action'
actionpack (5.2.4.4) lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
activesupport (5.2.4.4) lib/active_support/notifications.rb:168:in `block in instrument'
activesupport (5.2.4.4) lib/active_support/notifications/instrumenter.rb:23:in `instrument'
activesupport (5.2.4.4) lib/active_support/notifications.rb:168:in `instrument'
actionpack (5.2.4.4) lib/action_controller/metal/instrumentation.rb:32:in `process_action'
actionpack (5.2.4.4) lib/action_controller/metal/params_wrapper.rb:256:in `process_action'
activerecord (5.2.4.4) lib/active_record/railties/controller_runtime.rb:24:in `process_action'
actionpack (5.2.4.4) lib/abstract_controller/base.rb:134:in `process'
actionview (5.2.4.4) lib/action_view/rendering.rb:32:in `process'
actionpack (5.2.4.4) lib/action_controller/metal.rb:191:in `dispatch'
actionpack (5.2.4.4) lib/action_controller/metal.rb:252:in `dispatch'
actionpack (5.2.4.4) lib/action_dispatch/routing/route_set.rb:52:in `dispatch'
actionpack (5.2.4.4) lib/action_dispatch/routing/route_set.rb:34:in `serve'
actionpack (5.2.4.4) lib/action_dispatch/journey/router.rb:52:in `block in serve'
actionpack (5.2.4.4) lib/action_dispatch/journey/router.rb:35:in `each'
actionpack (5.2.4.4) lib/action_dispatch/journey/router.rb:35:in `serve'
actionpack (5.2.4.4) lib/action_dispatch/routing/route_set.rb:840:in `call'
warden (1.2.8) lib/warden/manager.rb:36:in `block in call'
warden (1.2.8) lib/warden/manager.rb:34:in `catch'
warden (1.2.8) lib/warden/manager.rb:34:in `call'
rack (2.2.3) lib/rack/tempfile_reaper.rb:15:in `call'
rack (2.2.3) lib/rack/etag.rb:27:in `call'
rack (2.2.3) lib/rack/conditional_get.rb:40:in `call'
rack (2.2.3) lib/rack/head.rb:12:in `call'
actionpack (5.2.4.4) lib/action_dispatch/http/content_security_policy.rb:18:in `call'
rack (2.2.3) lib/rack/session/abstract/id.rb:266:in `context'
rack (2.2.3) lib/rack/session/abstract/id.rb:260:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/cookies.rb:670:in `call'
active-fedora (13.2.0) lib/active_fedora/ldp_cache.rb:26:in `call'
flipflop (2.6.0) lib/flipflop/feature_cache.rb:12:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
activesupport (5.2.4.4) lib/active_support/callbacks.rb:98:in `run_callbacks'
actionpack (5.2.4.4) lib/action_dispatch/middleware/callbacks.rb:26:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
railties (5.2.4.4) lib/rails/rack/logger.rb:38:in `call_app'
railties (5.2.4.4) lib/rails/rack/logger.rb:26:in `block in call'
activesupport (5.2.4.4) lib/active_support/tagged_logging.rb:71:in `block in tagged'
activesupport (5.2.4.4) lib/active_support/tagged_logging.rb:28:in `tagged'
activesupport (5.2.4.4) lib/active_support/tagged_logging.rb:71:in `tagged'
railties (5.2.4.4) lib/rails/rack/logger.rb:26:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
request_store (1.5.0) lib/request_store/middleware.rb:19:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/request_id.rb:27:in `call'
rack (2.2.3) lib/rack/method_override.rb:24:in `call'
rack (2.2.3) lib/rack/runtime.rb:22:in `call'
activesupport (5.2.4.4) lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/executor.rb:14:in `call'
actionpack (5.2.4.4) lib/action_dispatch/middleware/static.rb:127:in `call'
rack (2.2.3) lib/rack/sendfile.rb:110:in `call'
honeybadger (3.3.0) lib/honeybadger/rack/error_notifier.rb:33:in `block in call'
honeybadger (3.3.0) lib/honeybadger/agent.rb:337:in `with_rack_env'
honeybadger (3.3.0) lib/honeybadger/rack/error_notifier.rb:30:in `call'
honeybadger (3.3.0) lib/honeybadger/rack/user_feedback.rb:31:in `call'
honeybadger (3.3.0) lib/honeybadger/rack/user_informer.rb:21:in `call'
railties (5.2.4.4) lib/rails/engine.rb:524:in `call'
passenger (6.0.4) src/ruby_supportlib/phusion_passenger/rack/thread_handler_extension.rb:97:in `process_request'
passenger (6.0.4) src/ruby_supportlib/phusion_passenger/request_handler/thread_handler.rb:157:in `accept_and_process_next_request'
passenger (6.0.4) src/ruby_supportlib/phusion_passenger/request_handler/thread_handler.rb:110:in `main_loop'
passenger (6.0.4) src/ruby_supportlib/phusion_passenger/request_handler.rb:415:in `block (3 levels) in start_threads'
passenger (6.0.4) src/ruby_supportlib/phusion_passenger/utils.rb:113:in `block in create_thread_and_abort_on_exception'
@conorom conorom added the bug label Nov 13, 2020
@cjcolvar
Copy link
Member

@conorom I dealt with something similar in avalon hitting stack level too deep when it hadn't been a problem before. I ended up creating a monkey patch: https://github.com/avalonmediasystem/avalon/blob/master/config/initializers/active_fedora_general.rb#L11-L19
If you try it out and it works then we can try push it upstream to ActiveFedora.

@bwatson78
Copy link
Contributor

Is it safe to say that all versions in-between 2.8.0 and 3.0.0.pre.rc2 are affected in the same way?

@cjcolvar
Copy link
Member

@bwatson78 That's a good question. I'm not sure what version of Hyrax, ActiveFedora, or other dependency like ActiveTriples or Rails this problem was introduced with and which it still affects.

@conorom
Copy link
Contributor Author

conorom commented Nov 17, 2020

@cjcolvar Thanks v much for sharing the monkey patch. I tested it in Fulcrum/heliotrope a few times and it seems to resolve the problem.

@bwatson78 I would be very surprised if the issue didn't affect all versions between the two I have tested, and probably more besides.

@no-reply no-reply added this to the 2.x series milestone Nov 18, 2020
@no-reply no-reply self-assigned this Nov 18, 2020
@no-reply
Copy link
Contributor

@cjcolvar i'm wondering if you have any breadcrumbs i could follow to lead me to the same conclusions as your AF monkey patch?

my initial reaction was that this likely originates as an issue with the result of the ingest, rather than the #destroy itself. i tried to reproduce this more minimally with:

w = FactoryBot.create(:work_with_files)
250.times do
  f = FactoryBot.create(:file_set, :image)
  w.members << f
end
w.save
w.reload
w.members.to_a.count # => 252

w.members.each(&:destroy)

i was hoping that this would raise the issue, but no luck. i might try again in the morning with threads---i half suspect a race condition.

it could also just be a bug in ActiveTriples::ExtendedBoundedDescription, which is supposed to be "bounded" in a way that excludes recursive references causing graph cycles. if we had an executable example, i could pretty easily shim in some debugging and get a sense for why it gets caught. if AT::EBD is at fault, it would seem pretty important to figure out what kinds of graphs it trips up on.

@no-reply
Copy link
Contributor

i created 300 ordered_members for a single work, as above, in 3 threads, and couldn't reproduce.

i guess the next step is to try to do the creation through the controller. if anyone has any insight about working up a reproducible example, it would be a huge help; else, i'll keep chugging along.

w = FactoryBot.create(:work_with_files)
threads = []
3.times do
  threads << Thread.new do
    100.times do
      w.ordered_members << FactoryBot.create(:file_set, :image)
      w.save
    end
  end
end

threads.each(&:join)
w.ordered_members.to_a.each(&:destroy)

@conorom
Copy link
Contributor Author

conorom commented Nov 18, 2020

@no-reply In case it's helpful I just poked around in Slack where the content editor first reported this. I can see in the Rails console that the two Works in question were created using our CSV importer (which uses the actor stack) and not the UI/controller. In my tests I uploaded the files through the UI each time. Seems like how the FileSets were added to the Work isn't relevant. Maybe.

I can also conform that the editor ended up deleting the offending FileSets successfully in the Rails console after several UI attempts had failed. This is why I emphasized the UI in the description. UI deletion is the problem, I think.

@no-reply
Copy link
Contributor

@no-reply In case it's helpful I just poked around in Slack where the content editor first reported this. I can see in the Rails console that the two Works in question were created using our CSV importer (which uses the actor stack) and not the UI/controller. In my tests I uploaded the files through the UI each time. Seems like how the FileSets were added to the Work isn't relevant. Maybe.

I can also conform that the editor ended up deleting the offending FileSets successfully in the Rails console after several UI attempts had failed. This is why I emphasized the UI in the description. UI deletion is the problem, I think.

oh, this does help! it sounds like i should start at the actor stack, both on the create and delete sides. thanks for the info!

@JulieWinchester
Copy link

I believe we've hit a similar error to this in our somewhat-modified Hyrax application (currently running on 2.9.0) using many different work types with many different parent-child relationships between works. Namely, if we have a work with over 120 or so child works, and we try to create a new child work nested inside the parent work (using the AddToWorkActor to accomplish the nesting), we hit a stack level too deep error on saving the parent work. @cjcolvar 's monkey-patch seems to have fixed this error for us (thanks!), but I'm not yet finished testing things after adding it.

cjcolvar added a commit to samvera/active_fedora that referenced this issue Mar 3, 2021
…ered list when calling nodes_will_change!

which leads to a stack level too deep exception in some cases
See samvera/hyrax#4581
This approach was also taken in ActiveFedora::File:
See 7c8bbbe#diff-28356c4daa0d55cbaf97e4269869f510R100-R103
cjcolvar added a commit to samvera/active_fedora that referenced this issue Mar 3, 2021
…ered list when calling nodes_will_change!

which leads to a stack level too deep exception in some cases
See samvera/hyrax#4581
This approach was also taken in ActiveFedora::File:
See 7c8bbbe#diff-28356c4daa0d55cbaf97e4269869f510R100-R103
no-reply pushed a commit to samvera/active_fedora that referenced this issue Mar 3, 2021
…ered list when calling nodes_will_change! (#1442)

which leads to a stack level too deep exception in some cases
See samvera/hyrax#4581
This approach was also taken in ActiveFedora::File:
See 7c8bbbe#diff-28356c4daa0d55cbaf97e4269869f510R100-R103
@no-reply
Copy link
Contributor

no-reply commented Mar 3, 2021

can anyone confirm that this issue still exists in 3.0.0.pre.rc2? according to samvera/active_fedora@2b49516, this is already fixed in most recent ActiveFedora, but the original ticket claims it's an issue in Hyrax 3.0.0-rc2

@conorom
Copy link
Contributor Author

conorom commented Mar 5, 2021

@no-reply well I popped onto Nurax, now on 3.0.0.pre.rc3 and can confirm the issue still exists there with a freshly-created Work and FileSet deletion test.

Full disclosure, I dunno what any of this does or why the monkey patch works, but I think I see your confusion. Maybe.

Looks like the commit you reference was only merged yesterday, though the comment states the workaround is based on one added here.

It doesn't help that that line range link doesn't work (i.e. jump and highlight lines 100-103 of lib/active_fedora/file.rb) within the diff commit view, nor does the fact that the referenced method is changed in master anyway, but it was this line that was changed in said commit and was mimicked for yesterday's monkey patch.

@no-reply
Copy link
Contributor

Looks like the commit you reference was only merged yesterday, though the comment states the workaround is based on one added here

that's right nurax-dev is using ActiveFedora 13.1.1 which does have the ActiveModel::Dirty API changes @cjcolvar contributed here: samvera/active_fedora@7c8bbbe#diff-28356c4daa0d55cbaf97e4269869f510R100-R103

on the other hand, it's also using Rails 5.1 (but ActiveModel 5.2), so maybe that's implicated?

@cjcolvar
Copy link
Member

Can this be closed with the release of ActiveFedora 12.2.3? Or is investigation still needed to determine if it is still present in ActiveFedora 13+?

@no-reply
Copy link
Contributor

no-reply commented Mar 26, 2021 via email

@joelakes
Copy link

joelakes commented May 18, 2021

I am seeing a very similar looking error when running large imports.

The background is that I had some github/dependabot alerts relating to actionpack, actionview and activesupport.

I moved rails from 5.1.6.2 to 5.2.6 to pick up the equivalent verions of actionpack, actionview and activesupport, and to test I submitted several imports (via a custom version of bulkrax) where works getting > 50 images attached.

AttachFilesToWorkJob fails in Sidekiq with 'SystemStackError: stack level too deep', log file attached.

My log looks pretty similar to the description in issue 4581, although mine is not a delete of images.

We are using Hyrax 2.9.5, and active-fedora is at 12.1.1 in gemfile.lock.

Apologies if this is unrelated to this issue, but posting here in case bumping to 5.2.* is somehow involved
trace.txt

@dlpierce
Copy link
Contributor

dlpierce commented Oct 6, 2021

I am able to reproduce this in dassie by creating a large work via the UI as described, no deletion step required. This is while using active fedora 13 and the suggested attribute_will_change! patch that was put in to active fedora 12 (but not 13 it appears).

I'll note that the number of files that can be attached by upload is limited (to 100?), so the error is not seen at initial creation, but later when adding an additional set of 100 files.

It seems possible to me this is not a case of circular method calls, but recursive calls for each FileSet.

@dlpierce
Copy link
Contributor

dlpierce commented Nov 2, 2021

I dug into the debugger looking at what ActiveTriples::ExtendedBoundedDescription#each_statement is doing. In at least one application where I've seen this error it is not getting into an infinite loop, simply a very deep loop. Since each trip around the loop involves adding 27 layers to the stack, it's not surprising we're hitting the stack memory limit.

My suggestion, and what worked for my application, is to simply raise the limit. This would need to be added to deployment and/or troubleshooting documentation. See IU-Libraries-Joint-Development/essi#355 where I added RUBY_THREAD_MACHINE_STACK_SIZE=8388608 as an environment variable.

@dlpierce
Copy link
Contributor

dlpierce commented Feb 1, 2022

@fritzfreiheit
Copy link
Contributor

I was able to get further before a stack overflow error with the following two changes that shift resource use from the stack to the heap:
First is in: lib/active_fedora/persistence.rb

      def save_contained_resources
        # Split into two steps due to stack overflow issue while saving works with large numbers of ordered members
        changed = contained_resources.changed
        keys = []
        keys = changed.keys if changed.size > 0
        i = 0
        n = keys.size
        while i < n do
          resource = changed[keys[i]]
          resource.save
          i += 1
        end
      end

The second change, which I am less sure about being correct, is in: lib/active_triples/util/extended_bounded_description.rb

    def each_statement
      ancestors = @ancestors.dup

      if block_given?
        statements = source_graph.query(subject: starting_node).each
        statements.each_statement { |st| yield st }

        ancestors << starting_node

        ebd_to_process = []
        statements.each_object do |object|
          next if object.literal?  || ancestors.include?(object)
          ebd_to_process << ExtendedBoundedDescription.new(source_graph, object, ancestors)
        end
        statements = []
        ebd_to_process.each do |ebd|
          ebd.each { |statement| statements << statement }
        end
        statements.each { |statement| yield statement }
      end
      enum_statement
    end

@rjkati
Copy link

rjkati commented Feb 20, 2023

Closing since the solution to raise the memory limit has been documented. see: #4581 (comment)

@rjkati rjkati closed this as completed Feb 20, 2023
masaball added a commit to avalonmediasystem/avalon that referenced this issue Feb 21, 2023
Based on recommendation for resolving "Stack level too deep" errors, found here: samvera/hyrax#4581 (comment)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment