better_errors: Slows down the browser and the server too

Using it with rails 3.2.1 so far so great! But sometimes it just eats up the memory or some kinda thing goes behind, it takes too long to show up the page. Don’t know if its me only or not, sometimes I have to end the server and fire up again. I Dev mode, I’m using the Thin server as well.

The trace:

16:35:59 Completed 500 Internal Server Error in 13711ms

16:35:59 NameError - undefined local variable or method `college_label' for #<#<Class:0x00000100b67cd0>:0x000001020992c0>:
  app/views/passions/_passion_concept.html.slim:2:in `_app_views_passions__passion_concept_html_slim___2702832306001475878_2174199320'
  (gem) actionpack-3.2.1/lib/action_view/template.rb:143:in `block in render'
  (gem) activesupport-3.2.1/lib/active_support/notifications.rb:125:in `instrument'
  (gem) actionpack-3.2.1/lib/action_view/template.rb:141:in `render'
  (gem) actionpack-3.2.1/lib/action_view/renderer/partial_renderer.rb:343:in `block in collection_with_template'
  (gem) actionpack-3.2.1/lib/action_view/renderer/partial_renderer.rb:340:in `each'
  (gem) actionpack-3.2.1/lib/action_view/renderer/partial_renderer.rb:340:in `collection_with_template'
  (gem) actionpack-3.2.1/lib/action_view/renderer/partial_renderer.rb:242:in `render_collection'
  (gem) actionpack-3.2.1/lib/action_view/renderer/partial_renderer.rb:226:in `block in render'
  (gem) actionpack-3.2.1/lib/action_view/renderer/abstract_renderer.rb:38:in `block in instrument'
  (gem) activesupport-3.2.1/lib/active_support/notifications.rb:123:in `block in instrument'
  (gem) activesupport-3.2.1/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
  (gem) activesupport-3.2.1/lib/active_support/notifications.rb:123:in `instrument'
  (gem) actionpack-3.2.1/lib/action_view/renderer/abstract_renderer.rb:38:in `instrument'
  (gem) actionpack-3.2.1/lib/action_view/renderer/partial_renderer.rb:225:in `render'
  (gem) actionpack-3.2.1/lib/action_view/renderer/renderer.rb:41:in `render_partial'
  (gem) actionpack-3.2.1/lib/action_view/renderer/renderer.rb:15:in `render'
  (gem) actionpack-3.2.1/lib/action_view/helpers/rendering_helper.rb:24:in `render'
  app/views/passions/show.html.slim:15:in `_app_views_passions_show_html_slim__3250032618956879478_2164571660'
  (gem) actionpack-3.2.1/lib/action_view/template.rb:143:in `block in render'
  (gem) activesupport-3.2.1/lib/active_support/notifications.rb:125:in `instrument'
  (gem) actionpack-3.2.1/lib/action_view/template.rb:141:in `render'
  (gem) actionpack-3.2.1/lib/action_view/renderer/template_renderer.rb:41:in `block (2 levels) in render_template'
  (gem) actionpack-3.2.1/lib/action_view/renderer/abstract_renderer.rb:38:in `block in instrument'
  (gem) activesupport-3.2.1/lib/active_support/notifications.rb:123:in `block in instrument'
  (gem) activesupport-3.2.1/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
  (gem) activesupport-3.2.1/lib/active_support/notifications.rb:123:in `instrument'
  (gem) actionpack-3.2.1/lib/action_view/renderer/abstract_renderer.rb:38:in `instrument'
  (gem) actionpack-3.2.1/lib/action_view/renderer/template_renderer.rb:40:in `block in render_template'
  (gem) actionpack-3.2.1/lib/action_view/renderer/template_renderer.rb:48:in `render_with_layout'
  (gem) actionpack-3.2.1/lib/action_view/renderer/template_renderer.rb:39:in `render_template'
  (gem) actionpack-3.2.1/lib/action_view/renderer/template_renderer.rb:12:in `render'
  (gem) actionpack-3.2.1/lib/action_view/renderer/renderer.rb:36:in `render_template'
  (gem) actionpack-3.2.1/lib/action_view/renderer/renderer.rb:17:in `render'
  (gem) actionpack-3.2.1/lib/abstract_controller/rendering.rb:109:in `_render_template'
  (gem) actionpack-3.2.1/lib/action_controller/metal/streaming.rb:225:in `_render_template'
  (gem) actionpack-3.2.1/lib/abstract_controller/rendering.rb:103:in `render_to_body'
  (gem) actionpack-3.2.1/lib/action_controller/metal/renderers.rb:28:in `render_to_body'
  (gem) actionpack-3.2.1/lib/action_controller/metal/compatibility.rb:50:in `render_to_body'
  (gem) actionpack-3.2.1/lib/abstract_controller/rendering.rb:88:in `render'
  (gem) actionpack-3.2.1/lib/action_controller/metal/rendering.rb:16:in `render'
  (gem) actionpack-3.2.1/lib/action_controller/metal/instrumentation.rb:40:in `block (2 levels) in render'
  (gem) activesupport-3.2.1/lib/active_support/core_ext/benchmark.rb:5:in `block in ms'
  /Users/millisami/.rbenv/versions/1.9.3-p194/lib/ruby/1.9.1/benchmark.rb:295:in `realtime'
  (gem) activesupport-3.2.1/lib/active_support/core_ext/benchmark.rb:5:in `ms'
  (gem) actionpack-3.2.1/lib/action_controller/metal/instrumentation.rb:40:in `block in render'
  (gem) actionpack-3.2.1/lib/action_controller/metal/instrumentation.rb:83:in `cleanup_view_runtime'
  (gem) activerecord-3.2.1/lib/active_record/railties/controller_runtime.rb:24:in `cleanup_view_runtime'
  (gem) actionpack-3.2.1/lib/action_controller/metal/instrumentation.rb:39:in `render'
  (gem) actionpack-3.2.1/lib/action_controller/metal/implicit_render.rb:10:in `default_render'
  (gem) actionpack-3.2.1/lib/action_controller/metal/implicit_render.rb:5:in `send_action'
  (gem) actionpack-3.2.1/lib/abstract_controller/base.rb:167:in `process_action'
  (gem) actionpack-3.2.1/lib/action_controller/metal/rendering.rb:10:in `process_action'
  (gem) actionpack-3.2.1/lib/abstract_controller/callbacks.rb:18:in `block in process_action'
  (gem) activesupport-3.2.1/lib/active_support/callbacks.rb:535:in `_run__3422095058009860042__process_action__3721854489021212916__callbacks'
  (gem) activesupport-3.2.1/lib/active_support/callbacks.rb:405:in `__run_callback'
  (gem) activesupport-3.2.1/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'
  (gem) activesupport-3.2.1/lib/active_support/callbacks.rb:81:in `run_callbacks'
  (gem) actionpack-3.2.1/lib/abstract_controller/callbacks.rb:17:in `process_action'
  (gem) actionpack-3.2.1/lib/action_controller/metal/rescue.rb:29:in `process_action'
  (gem) actionpack-3.2.1/lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'
  (gem) activesupport-3.2.1/lib/active_support/notifications.rb:123:in `block in instrument'
  (gem) activesupport-3.2.1/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
  (gem) activesupport-3.2.1/lib/active_support/notifications.rb:123:in `instrument'
  (gem) actionpack-3.2.1/lib/action_controller/metal/instrumentation.rb:29:in `process_action'
  (gem) actionpack-3.2.1/lib/action_controller/metal/params_wrapper.rb:205:in `process_action'
  (gem) activerecord-3.2.1/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
  (gem) actionpack-3.2.1/lib/abstract_controller/base.rb:121:in `process'
  (gem) actionpack-3.2.1/lib/abstract_controller/rendering.rb:45:in `process'
  (gem) actionpack-3.2.1/lib/action_controller/metal.rb:203:in `dispatch'
  (gem) actionpack-3.2.1/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
  (gem) actionpack-3.2.1/lib/action_controller/metal.rb:246:in `block in action'
  (gem) actionpack-3.2.1/lib/action_dispatch/routing/route_set.rb:66:in `call'
  (gem) actionpack-3.2.1/lib/action_dispatch/routing/route_set.rb:66:in `dispatch'
  (gem) actionpack-3.2.1/lib/action_dispatch/routing/route_set.rb:30:in `call'
  (gem) journey-1.0.4/lib/journey/router.rb:68:in `block in call'
  (gem) journey-1.0.4/lib/journey/router.rb:56:in `each'
  (gem) journey-1.0.4/lib/journey/router.rb:56:in `call'
  (gem) actionpack-3.2.1/lib/action_dispatch/routing/route_set.rb:589:in `call'
  (gem) omniauth-1.1.0/lib/omniauth/strategy.rb:177:in `call!'
  (gem) omniauth-1.1.0/lib/omniauth/strategy.rb:157:in `call'
  (gem) omniauth-1.1.0/lib/omniauth/strategy.rb:177:in `call!'
  (gem) omniauth-1.1.0/lib/omniauth/strategy.rb:157:in `call'
  (gem) omniauth-1.1.0/lib/omniauth/strategy.rb:177:in `call!'
  (gem) omniauth-1.1.0/lib/omniauth/strategy.rb:157:in `call'
  (gem) better_errors-0.3.2/lib/better_errors/middleware.rb:51:in `app_call'
  (gem) better_errors-0.3.2/lib/better_errors/middleware.rb:45:in `call'
  (gem) client_side_validations-3.1.4/lib/client_side_validations/middleware.rb:18:in `call'
  (gem) warden-1.2.1/lib/warden/manager.rb:35:in `block in call'
  (gem) warden-1.2.1/lib/warden/manager.rb:34:in `catch'
  (gem) warden-1.2.1/lib/warden/manager.rb:34:in `call'
  (gem) actionpack-3.2.1/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
  (gem) rack-1.4.1/lib/rack/etag.rb:23:in `call'
  (gem) rack-1.4.1/lib/rack/conditionalget.rb:25:in `call'
  (gem) actionpack-3.2.1/lib/action_dispatch/middleware/head.rb:14:in `call'
  (gem) actionpack-3.2.1/lib/action_dispatch/middleware/params_parser.rb:21:in `call'
  (gem) actionpack-3.2.1/lib/action_dispatch/middleware/flash.rb:242:in `call'
  (gem) rack-1.4.1/lib/rack/session/abstract/id.rb:205:in `context'
  (gem) rack-1.4.1/lib/rack/session/abstract/id.rb:200:in `call'
  (gem) actionpack-3.2.1/lib/action_dispatch/middleware/cookies.rb:338:in `call'
  (gem) activerecord-3.2.1/lib/active_record/query_cache.rb:64:in `call'
  (gem) activerecord-3.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:443:in `call'
  (gem) actionpack-3.2.1/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
  (gem) activesupport-3.2.1/lib/active_support/callbacks.rb:405:in `_run__3707603801134175657__call__207174176202627819__callbacks'
  (gem) activesupport-3.2.1/lib/active_support/callbacks.rb:405:in `__run_callback'
  (gem) activesupport-3.2.1/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
  (gem) activesupport-3.2.1/lib/active_support/callbacks.rb:81:in `run_callbacks'
  (gem) actionpack-3.2.1/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
  (gem) actionpack-3.2.1/lib/action_dispatch/middleware/reloader.rb:65:in `call'
  (gem) actionpack-3.2.1/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
  (gem) actionpack-3.2.1/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'
  (gem) actionpack-3.2.1/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
  (gem) railties-3.2.1/lib/rails/rack/logger.rb:26:in `call_app'
  (gem) railties-3.2.1/lib/rails/rack/logger.rb:16:in `call'
  (gem) quiet_assets-1.0.1/lib/quiet_assets.rb:20:in `call_with_quiet_assets'
  (gem) actionpack-3.2.1/lib/action_dispatch/middleware/request_id.rb:22:in `call'
  (gem) rack-1.4.1/lib/rack/methodoverride.rb:21:in `call'
  (gem) rack-1.4.1/lib/rack/runtime.rb:17:in `call'
  (gem) activesupport-3.2.1/lib/active_support/cache/strategy/local_cache.rb:72:in `call'
  (gem) rack-1.4.1/lib/rack/lock.rb:15:in `call'
  (gem) actionpack-3.2.1/lib/action_dispatch/middleware/static.rb:53:in `call'
  (gem) airbrake-3.1.3/lib/airbrake/rack.rb:41:in `call'
  (gem) airbrake-3.1.3/lib/airbrake/user_informer.rb:12:in `call'
  (gem) railties-3.2.1/lib/rails/engine.rb:479:in `call'
  (gem) railties-3.2.1/lib/rails/application.rb:220:in `call'
  (gem) rack-1.4.1/lib/rack/content_length.rb:14:in `call'
  (gem) railties-3.2.1/lib/rails/rack/log_tailer.rb:14:in `call'
  (gem) thin-1.4.1/lib/thin/connection.rb:80:in `block in pre_process'
  (gem) thin-1.4.1/lib/thin/connection.rb:78:in `catch'
  (gem) thin-1.4.1/lib/thin/connection.rb:78:in `pre_process'
  (gem) thin-1.4.1/lib/thin/connection.rb:53:in `process'
  (gem) thin-1.4.1/lib/thin/connection.rb:38:in `receive_data'
  (gem) eventmachine-0.12.10/lib/eventmachine.rb:256:in `run_machine'
  (gem) eventmachine-0.12.10/lib/eventmachine.rb:256:in `run'
  (gem) thin-1.4.1/lib/thin/backends/base.rb:63:in `start'
  (gem) thin-1.4.1/lib/thin/server.rb:159:in `start'
  (gem) rack-1.4.1/lib/rack/handler/thin.rb:13:in `run'
  (gem) rack-1.4.1/lib/rack/server.rb:265:in `start'
  (gem) railties-3.2.1/lib/rails/commands/server.rb:70:in `start'
  (gem) railties-3.2.1/lib/rails/commands.rb:55:in `block in <top (required)>'
  (gem) railties-3.2.1/lib/rails/commands.rb:50:in `tap'
  (gem) railties-3.2.1/lib/rails/commands.rb:50:in `<top (required)>'
  script/rails:6:in `require'
  script/rails:6:in `<main>'

16:36:00 Started POST "/__better_errors/2151900780/variables" for 127.0.0.1 at 2012-12-20 16:36:00 +0545
...

Specifically, that last Started POST "/...... request too long.

About this issue

  • Original URL
  • State: closed
  • Created 12 years ago
  • Comments: 20

Most upvoted comments

Same here. OS X 16GB RAM. Solved issue by removing better_errors from Gemfile

@rstacruz I’m seeing the same issue in my application. For me the problem depends on the request path and is perfectly repeatable. Here is some more info to help track down what’s going on:

  • Errors in requests with a large amount of data in the instance variables, such as index requests, are slow.
  • Errors in requests with small amount of data in the instance variables, such as show requests, are fast.
  • When processing an error request, I first see my ruby worker spike to 100% CPU for ~9 seconds while the server is processing the request. Then the error page appears, but the code panel is blank. Then I see my browser spike to 100% CPU for ~24 seconds. Then the code panel appears.
  • When binding_of_caller is not installed, the ruby worker still spikes the CPU for ~9 seconds, but after that the code panel appears immediately and the browser CPU does not spike.
  • Tested with Rails 3.2.16 / better_errors 1.1.0 / binding_of_caller 0.7.2
  • Reproduced same problem with Rails 3.2.13 / better_errors 0.5.0 / binding_of_caller 0.7.2
  • Ruby 2.0.0p247
  • I have 8GB ram on my laptop. I don’t see evidence of excessive swap usage.