I'm developing a plugin for a management framework and when I start the webrick server in the development mode, a strange error raises(stack level too deep). It happens when an action (e.g. the show action) starts to render a template. Unfortunately i have no idea why this is happen.
SystemStackError in Stories#show
Showing vendor/plugins/stories/app/views/stories/show.rhtml where line #5 raised:
stack level too deep
Extracted source (around line #5):
5: link_to_if_authorized 'aa', {:controller => "stories", :action => "index", :id => @story.id, :project_id => @story.project.id}, :title => l(:view_story), :class => 'icon icon-zoom-out'
6: link_to_if_authorized 'bb', {:controller => "stories", :action => "edit", :id => @story.id, :project_id => @story.project.id}, :title => l(:button_edit), :class => 'icon icon-edit'
7: link_to 'bb', {:id => @story.id, :project_id => @story.project.id}, :confirm => 'Really delete?', :method => :delete, :class => 'icon icon-del' if User.current.allowed_to? (:delete_stories, @project)
RAILS_ROOT: /home/haendwic/Documents/Aptana Studio 3 Workspace/1.4-stable-SVN
Application Trace | Framework Trace | Full Trace
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/attribute_methods.rb:248:in method_missing'
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/attribute_methods.rb:249:in method_missing'
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/associations /association_proxy.rb:215:in send'
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/associations/association_proxy.rb:215:in method_missing'
/home/haendwic/Documents/Aptana Studio 3 Workspace/1.4-stable-SVN/vendor/plugins/stories/app/views/stories/show.rhtml:5:in _run_rhtml_vendor47plugins47stories47app47views47stories47show46rhtml'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_view/renderable.rb:34:in send'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_view/renderable.rb:34:in render'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_view/base.rb:306:in with_template'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_view/renderable.rb:30:in render'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_view/template.rb:205:in render_template'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_view/base.rb:265:in render'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_view/base.rb:348:in _render_with_layout'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_view/base.rb:262:in render'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/base.rb:1252:in render_for_file'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/base.rb:936:in render_without_benchmark'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/benchmarking.rb:51:in render'
/var/lib/gems/1.8/gems/activesupport-2.3.14/lib/active_support/core_ext/benchmark.rb:17:in ms'
/usr/lib/ruby/1.8/benchmark.rb:308:in realtime'
/var/lib/gems/1.8/gems/activesupport-2.3.14/lib/active_support/core_ext/benchmark.rb:17:in ms'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/benchmarking.rb:51:in render'
/home/haendwic/Documents/Aptana Studio 3 Workspace/1.4-stable-SVN/vendor/plugins/stories/app/controllers/stories_controller.rb:104:in show'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/mime_responds.rb:135:in call'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/mime_responds.rb:135:in custom'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/mime_responds.rb:179:in call'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/mime_responds.rb:179:in respond'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/mime_responds.rb:173:in each'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/mime_responds.rb:173:in respond'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/mime_responds.rb:107:in respond_to'
/home/haendwic/Documents/Aptana Studio 3 Workspace/1.4-stable-SVN/vendor/plugins/stories/app/controllers/stories_controller.rb:102:in show'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/base.rb:1333:in send'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/base.rb:1333:in perform_action_without_filters'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/filters.rb:617:in call_filters'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/filters.rb:610:in perform_action_without_benchmark'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/benchmarking.rb:68:in perform_action_without_rescue'
/var/lib/gems/1.8/gems/activesupport-2.3.14/lib/active_support/core_ext/benchmark.rb:17:in ms'
/usr/lib/ruby/1.8/benchmark.rb:308:in realtime'
/var/lib/gems/1.8/gems/activesupport-2.3.14/lib/active_support/core_ext/benchmark.rb:17:in ms'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/benchmarking.rb:68:in perform_action_without_rescue'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/rescue.rb:160:in perform_action_without_flash'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/flash.rb:151:in perform_action'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/base.rb:532:in send'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/base.rb:532:in process_without_filters'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/filters.rb:606:in process'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/base.rb:391:in process'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/base.rb:386:in call'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/routing/route_set.rb:438:in call'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/dispatcher.rb:87:in dispatch'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/dispatcher.rb:121:in _call'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/dispatcher.rb:130:in build_middleware_stack'
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/query_cache.rb:29:in call'
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/query_cache.rb:29:in call'
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/connection_adapters/abstract/query_cache.rb:34:in cache'
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/query_cache.rb:9:in cache'
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/query_cache.rb:28:in call'
/var/lib/gems/1.8/gems/activerecord-2.3.14/lib/active_record/connection_adapters/abstract/connection_pool.rb:361:in call'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/string_coercion.rb:25:in call'
/var/lib/gems/1.8/gems/rack-1.1.3/lib/rack/head.rb:9:in call'
/var/lib/gems/1.8/gems/rack-1.1.3/lib/rack/methodoverride.rb:24:in call'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/params_parser.rb:15:in call'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/session /cookie_store.rb:99:in call'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/failsafe.rb:26:in call'
/var/lib/gems/1.8/gems/rack-1.1.3/lib/rack/lock.rb:11:in call'
/var/lib/gems/1.8/gems/rack-1.1.3/lib/rack/lock.rb:11:in synchronize'
/var/lib/gems/1.8/gems/rack-1.1.3/lib/rack/lock.rb:11:in call'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/dispatcher.rb:114:in call'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/reloader.rb:34:in run'
/var/lib/gems/1.8/gems/actionpack-2.3.14/lib/action_controller/dispatcher.rb:108:in call'
/var/lib/gems/1.8/gems/rails-2.3.14/lib/rails/rack/static.rb:31:in call'
/var/lib/gems/1.8/gems/rack-1.1.3/lib/rack/urlmap.rb:47:in call'
/var/lib/gems/1.8/gems/rack-1.1.3/lib/rack/urlmap.rb:41:in each'
/var/lib/gems/1.8/gems/rack-1.1.3/lib/rack/urlmap.rb:41:in call'
/var/lib/gems/1.8/gems/rails-2.3.14/lib/rails/rack/log_tailer.rb:17:in call'
/var/lib/gems/1.8/gems/rack-1.1.3/lib/rack/content_length.rb:13:in call'
/var/lib/gems/1.8/gems/rack-1.1.3/lib/rack/handler/webrick.rb:48:in service'
/usr/lib/ruby/1.8/webrick/httpserver.rb:104:in service'
/usr/lib/ruby/1.8/webrick/httpserver.rb:65:in run'
/usr/lib/ruby/1.8/webrick/server.rb:173:in start_thread'
/usr/lib/ruby/1.8/webrick/server.rb:162:in start'
/usr/lib/ruby/1.8/webrick/server.rb:162:in start_thread'
/usr/lib/ruby/1.8/webrick/server.rb:95:in start'
/usr/lib/ruby/1.8/webrick/server.rb:92:in each'
/usr/lib/ruby/1.8/webrick/server.rb:92:in start'
/usr/lib/ruby/1.8/webrick/server.rb:23:in start'
/usr/lib/ruby/1.8/webrick/server.rb:82:in start'
/var/lib/gems/1.8/gems/rack-1.1.3/lib/rack/handler/webrick.rb:14:in run'
/var/lib/gems/1.8/gems/rails-2.3.14/lib/commands/server.rb:111
script/server:3:in require'
script/server:3
Request
Parameters:
{"project_id"=>"1",
"id"=>"2"}
Show session dump
Response
Headers:
{"Cache-Control"=>"no-cache",
"Content-Type"=>"text/html"}
and here is the action from the controller
def show
@edit_allowed = User.current.allowed_to?(:edit_stories, @project)
respond_to do |format|
format.html {
render :template => 'stories/show'
}
format.api
format.pdf { send_data(story_to_pdf(@story), :type => 'application/pdf', :filename => "#{@project.identifier}-#{@story.id}.pdf") }
end
end
and at last a part of the view
link_to_if_authorized 'aa', {:controller => "stories", :action => "index", :id => @story.id, :project_id => @story.project.id}, :title => l(:view_story), :class => 'icon icon-zoom-out'
link_to_if_authorized 'bb', {:controller => "stories", :action => "edit", :id => @story.id, :project_id => @story.project.id}, :title => l(:button_edit), :class => 'icon icon-edit'
link_to 'bb', {:id => @story.id, :project_id => @story.project.id}, :confirm => 'Really delete?', :method => :delete, :class => 'icon icon-del' if User.current.allowed_to?(:delete_stories, @project)
Maybe it's important to say, that in the production mode the plugin is stable and routes the actions (incl. show) correctly
This is typically caused by you (or others) patching core models (probably the Project model) from a plugin without taking the rails reloader into account.
If you override methods (e.g. using alias_method_chain) and your patch is loaded twice, you can easily create an infinite loop when calling the old method.
# This is our initial class
class MyClass
def foo
puts "original foo"
end
end
module Patch
def self.included(base)
base.alias_method_chain :foo, :feature
end
def foo_with_feature
foo_without_feature # call the "original" method
puts "foo with feature"
end
end
# patch the class
MyClass.send(:include, Patch)
# Now call the patched method
MyClass.new.foo
# prints:
# original foo
# foo with feature
foo now refers to the method foo_with_feature while the original foo method now is accessible from foo_without_feature
All right, until now everything looked good. Now let's see what happens, if we load our patch again
# patch again
MyClass.send(:include, Patch)
# And call the method again
MyClass.new.foo
# SystemStackError: stack level too deep
# from (irb):7:in `foo_without_feature'
# from (irb):7:in `foo'
# from (irb):27
You see a SystemStackError caused by an infinite loop. This is because after the second loading of the patch, foo_without_feature now refers to the foo_with_feature method from the first patch. When calling it, it will over and over again call foo_without_feature until the stack is full.
You said that it only crashes on the second request. This is exactly the typical behavior when something is odd on the class reloader. By default, Rails will reload all classes on every request in development mode but only once in production mode.
Taming the rails reloader is a bit tricky sometimes. As some general guidelines, you should
require_dependency instead of require when loading patchesDispatcher.to_prepareunloadableThe most critical part is using Dispatcher.to_prepare. It is a callback which is called once in production mode and before each request in development mode and is thus the ideal place for loading patches.
As a side note though: When using Redmine 2 (or the upcoming ChiliProject 4), i.e. Rails 3, the class patching will be rather different from this approach - most probably easier.