Exception in View Freezes Rails #1525
Comments
|
I've experienced this as well... It doesn't seem to happen consistently though. My gems: gem 'rails', '3.1.0.rc1' |
|
I agree. It's unconsistent. The problem is the same with Unicorn or Mongrel. When I look at the activity monitor, I can clearly see the "ruby" process using more and more ram memory, until total freeze when this happen. I still don't know the reason. What I'm sure is that the bug has nothing to do with an infinite loop or somtehing like that. Strange behaviour as well is the fact that, when it doesn't freeze, instead of being redirected to a page with details about the error, I'm redirected to the 500.html page, like in production. |
|
@ndemoreau, are you using the Rails HTTP streaming by any chance? |
|
Correct. I disabled it and now, i'm not redirected to the 500.html page anymore and the freeze doesn't seem to happen anymore (I did very few tests). Thanks! I keep you posted. Nicolas. On 8 juin 2011, at 10:57, utkarshkukreti wrote:
|
|
Just to let you know that it seems to be more stable but it is still not totally fixed yet. It just freezed when I mistyped an input on a simple_form form: <%= input.tel ... %> |
|
+1 on this. I am using the edge Rails and when the error is raised in the view then Rails freezes (eats more and more CPU and memory). When I hit Ctrl-C in console then the error is outputted to the console. I am on Mac OS X Snow Leo and using the latest Ruby 1.9.2. My server is Mongrel. I've also attached some 'dtruss' output here: https://gist.github.com/1016728 |
|
This issue is really annoying, the memory usage grows so fast it becomes quite difficult to even switch to a terminal window to kill the process. I tried to find the source of the problem, but I'm not that familiar with Rails codebase and ruby-prof isn't able to complete the dump file once things blow up (waited a good 15 minutes with my rsize growing to ~4GB). Hoping that this will help a little bit in solving the problem then here's what I tried and figured out. First create a view that uses assets and renders OK (without errors): Then create a view that has an error like the one below: Environment: OS X Snow Leopard, 1.9.2, Thin, Rails 3.1.0 RC4. |
|
Yeah, this does make development (porting to 3.1) tricky. I've found that if I CTRL-C the server sometimes I do get an error message output, which helps me track down that one problem to inch forward. Not fun. I am also seeing this with Passenger. I am using RoR 3.1 RC 4 |
|
Is this still an issue using rails from git 3-1-stable branch? |
|
Yeah, still reproducible, but now better (6-7 secs until I see the error in browser). Workaround is to put this code in development.rb: config.after_initialize do
module SmallInspect
def inspect
"<#{self.class.name} - tooooo long>"
end
end
[ActionDispatch::RemoteIp::RemoteIpGetter, OmniAuth::Strategies::Facebook, ActionController::Base, Warden::Proxy].each do |klazz|
klazz.send(:include, SmallInspect)
end
end |
|
Can you share with us an application where we can try to reproduce the error? |
|
Unfortunately, I can not share it with you because it's proprietary. I simply have HomeController#index action. In index.html.erb I place a call: <% non_existing_method %>It takes 7 secs to render the error in browser and console without the workaround code. And it takes 2 secs to render the error with workaround code. My Gemfile: source 'http://rubygems.org'
gem 'rake', '0.8.7'
gem 'rails', :git => 'https://github.com/rails/rails.git', :branch => '3-1-stable'
gem 'mysql', '2.8.1'
gem 'jquery-rails', '1.0.7'
gem 'devise', :git => 'https://github.com/plataformatec/devise.git'
gem 'mini_magick', :git => 'https://github.com/AndreyChernyh/mini_magick.git' # , :path => '~/projects/gems/mini_magick'
gem 'fog', :git => 'https://github.com/AndreyChernyh/fog.git'
gem 'carrierwave', :git => 'https://github.com/AndreyChernyh/carrierwave.git'
gem 'faraday', '0.6.1'
gem 'oa-oauth', '0.2.6', :require => 'omniauth/oauth'
gem 'oa-openid', '0.2.6', :require => 'omniauth/openid'
gem 'oauth', '~> 0.4.0'
gem 'kaminari', '0.12.4'
gem 'exception_notification_rails3', :require => 'exception_notifier'
# TODO check if the official gem updated
gem 'grouped_validations', :git => 'https://github.com/adzap/grouped_validations.git'
gem 'memcache-client', '1.8.5'
gem 'acts-as-taggable-on', :git => 'https://github.com/denisj/acts-as-taggable-on.git'
gem 'gravtastic', '3.1.0'
gem 'twitter', '1.4.1'
gem 'fbgraph', '1.8.0'
gem 'thinking-sphinx', '2.0.5'
gem 'ts-datetime-delta', '1.0.2', :require => 'thinking_sphinx/deltas/datetime_delta'
gem 'sass-rails'
gem 'whenever', '0.6.7', :require => false
gem 'newrelic_rpm', '3.1.1.beta1'
gem 'configatron', '2.8.0'
gem 'delayed_job', '2.1.4'
gem 'yui-compressor', '0.9.6'
#gem 'mailman', '0.4.0'
# admin
gem 'meta_search', '>= 1.1.0.pre'
gem 'activeadmin', :git => 'https://github.com/gregbell/active_admin.git'
# caching
gem 'hiredis', '~> 0.3.1'
gem 'redis', '~> 2.2.0', :require => ["redis/connection/hiredis", "redis"]
gem 'redis-store', '1.0.0.rc1'
group :development, :test do
gem 'mongrel'
gem 'rspec-rails', '2.6.1.beta1'
gem 'ruby-prof'
end
group :test do
gem 'factory_girl_rails', '1.0.1'
gem 'shoulda-matchers', :git => 'https://github.com/thoughtbot/shoulda-matchers.git'
gem 'autotest-rails', '4.1.0'
gem 'capybara', :git => 'git://github.com/jnicklas/capybara.git'
gem 'timecop', '0.3.5'
gem 'launchy'
end
group :production, :staging do
gem 'unicorn'
end |
|
I'm on master and I've still got this. It happens every time you call a non-existent method as @AndreyChernyh said. Want me to try on the stable branch or should master have fixed it if stable has? This app is also proprietary and it's massive, but I'm happy to provide any traces or info that might be useful. My Gemfile looks like this: |
|
This is the output I get if I kill the server with CTRL-C (the ^C are me holding down CTRL-C as my computer is totally unresponsive by this point). |
|
Digging into this deeper, I'm also sporadically getting the following. It may or may not be related. (Update: now I've applied @AndreyChernyh's hack, I get this ever time a page fails.) |
ghost
assigned 
|
I had this problem on an app I no longer work on, but we worked around with the This issue was potentially made harder to reproduce by 5b88014 that filters out most of the rack stuff from the env dump. It doesn't fix the root problems though, of which there are two:
Happy to provide a patch for either or both of these suggestions @spastorino if you agree. |
|
Are you guys aware of why this is only happening when the error is a missing method? Parse errors and general exceptions are being handled fine. Is a different template rendered for this etc? Could we maybe mimic the other exception behaviours here? Excuse my questions rather than solutions - I don't know this bit of the codebase at all and am too bogged down with deadlines to explore it right now. Sorry. |
|
I experience the issue with unicorn as well as webrick. My trick is to spot it before the memory monster goes past the 1GB.. from years of CounterStrike I tend to have a good reaction time.. ha ha.. Anyway it only happens on method_missing errors for me, typical typo errors. When making a new app it doesnt seem to happen in webrick or unicorn. I only tested this for a few minutes. Maybe important is also the information that it doesnt only happen on the view layer. I also had this happen in a model, 100% reproducible. Unfortunately I deleted that bit of code :/ (I know Im a dummy...) I will post some code if i can reproduce it again. |
|
I've managed to capture a couple stack traces - http://pastie.org/2268985 |
|
When monkey patching rack-mount/lib/rack/mount/route.rb inspect to not call @app.inspect at least the problem goes away, along with some debug info :( |
|
@xaviershay I'm happy with that. Can you put together a patch? |
|
Seems that I managed to fix this (at least I am not able to reproduce this issue anymore). It seems that when a Template:Error is raised from rendering the actual view, the layout rendering fails with calling .html_safe on nil content. This in turn raises another error, which then causes the whole loop to repeat until the host machine runs out of RAM. |
|
Great find @tanelsuurhans. I'm still going to put together a patch for my suggestions as I still think they're worthwhile additions. |
The default includes all instance variables which is many kilobytes long and takes too long to generate, as well as being just plain not useful. The original impetus for this change was the development 500 page taking ages to render, in part because of the potentially massive amount of data that inspect would be generating and displaying. This was mitigated somewhat by 5b88014, though this commit fixes one of the root problems and has the added benefit of being more useful when debugging in console. References rails#1525.
|
Pull request for shorter inspect output for Probably not going to get around to the |
|
I debugged this problem some more, it seems to happen in C code - action_view/template/error.rb#initialize never returns, more accurately the call to NameError.message never returns: super(original_exception.message). I've tried this also with JRuby (1.6.3) and everything works, the following is the result from original_exception.message: undefined local variable or method `foo' for #<#Class:0x174cff77f:0x2e20a282> For some reason 1.9.2-p0 and 1.9.2-p290 are unable to call name_err_mesg_to_str without going into an endless loop and concating to a huge string buffer. I've captured a couple of C level stack traces with GDB also and I think it looks like the string is already over 8 MB. What I suspect is that while name error is looping instance variables there's some sort of circular reference or edge case that causes it to keep looping endlessly (no recursion since stack overflow doesn't happen). I also pastied the C stack traces: http://pastie.org/2274529 and http://pastie.org/2274530 I'll try to go through the C code a bit more when I get the chance, meanwhile hope that this helps a bit in finding the cause of the problem. |
|
@tarmolehtpuu can you consistently reproduce the error? If so, can you push an app to github that I can use to repro? |
|
I got into this loop too since 3.1.0.rc1. On rc4, I had to kill the process and relaunch passenger. Mainly caused by "undefined method" errors, I think when the app crashes for something else, like syntax err, it is OK. (sorry if this is already known.) 3.1.0.rc1+ |
|
@tenderlove, I'm able to reproduce it, but as usual the app is proprietary and I can't share it I think (I'll have to check). I've been trying to reproduce this with a fresh application, no luck so far. I'll try some more over the weekend. |
|
@DriesS: I really have to ask - why on earth are you still using 1.8.7 with Rails 3.2.1? Afaik Rails dropped official support for 1.8.7 from 3.x onwards. I really suggest you upgrade your ruby version, you will get insane performance boots from using 1.9.3 |
|
@tanelsuurhans rails supports 1.8.7 until 4.0 |
|
Okay, I was on that one then. Doesn't really change the fact that 1.8.7 is dog slow compared to 1.9.3, not to mention the memory usage :) As a side note - I've encountered this bug a couple of times on a 3.2.1 project too, although its not as bad as it was with 3.0.x, just eats a up a bit of memory and spits out the TemplateError. |
|
never ending issue :) Would it make sense to write custom inspect methods for rails core classes (at least the huge ones) to make this go away? |
|
@tarmolehtpuu I think that an idiom of "implement inspect for complex classes" is good practice in general; after all, who is inspect for (developers, right)? So the default implementation, which, in our case, returns a 20MB string for the view, is pretty useless! I mean, 20MB is the complete works of shakespeare, the bible, all the sherlock holmes stories, and a bunch of other stuff. Hence my comment about separating symptom from cause above: #1525 (comment) @tanelsuurhans all evidence we have to have to hand is that 1.9.x performance is worse than ree 1.8.7 for our app; it's quite likely GC related; we've not had enough time to investigate |
|
Ping. Seriously. Still no fix for this in Rails 3.2.1? I'm find the RouteSet hack (added via initializer) works for me. |
|
I created a sample app that shows how rails hangs when getting a view error. https://github.com/joevandyk/rails-view-errors-hanging Essentially I created an empty Rails 3.1.3 app with a couple thousand routes and put an undefined method call in the view. I also made a 3.2 branch -- that one seems to hang for much longer. For me, it only hangs for 5-6 seconds, but I'm sure the root cause of the slowness is the same as mentioned above where Rails can hang for minutes for larger apps. As mentioned in the README, I'm positive this problem can show itself without having a thousand+ routes, but the slowness is fixed by the above Routeset fix. |
|
I am using Rails 3.2.1 and the same is happening with me. whenever a method isn't find it takes forever to not throw the error. And memory usage going up and up and it almost use all of my system memory if i dont kill the server manually and sometimes killing the server doesnt work easily. Please we need a fix. |
|
Encountered this problem yesterday in production :( RouteSet hack works for me now. |
|
Out of curiosity, I've had a bit more of a look into this issue. The problem is internal to the Ruby interpreter; Rails isn't scrubbing this exception message as suspected by @tanelsuurhans seven months ago. The root cause is d = rb_protect(rb_inspect, obj, 0);
if (NIL_P(d) || RSTRING_LEN(d) > 65) {
d = rb_any_to_s(obj);
}
desc = RSTRING_PTR(d);
...
if (desc && desc[0] != '#') {
d = d ? rb_str_dup(d) : rb_str_new2(desc);
rb_str_cat2(d, ":");
rb_str_cat2(d, rb_obj_classname(obj));
}
args[0] = mesg;
args[1] = ptr[2];
args[2] = d;
mesg = rb_f_sprintf(NAME_ERR_MESG_COUNT, args);That is:
Now, when a The default implementation of Here's a simple test that replicates the issue in plain Ruby: def test_slow_inspect
require 'benchmark'
SlowInspect.new.raise_name_error
rescue NameError => e
time = Benchmark.realtime { puts e.message }
puts "(done in #{(time*1000).to_i} ms)"
end
class SlowInspect
def initialize(l=0)
@foo = []
10.times { @foo << ( l > 4 ? self : SlowInspect.new(l+1) ) }
end
def raise_name_error
shazbut
end
end
test_slow_inspect
class SlowInspect
alias inspect to_s
end
test_slow_inspectwhich prints the following on my machine: Note that the result of calling In pure Ruby terms, "implement inspect for complex classes" is a good idiom. And, if you're bothering to do that, then "keep the length of the string returned by inspect no more than 65 characters" is a useful corollary, as it will yield more informative error messages for |
|
The fix for this bug has arrived on the 3.2 and 3.1 stable branches. |
|
For those who might stumble upon dirty fixes for this issues in "old" projects, I can confirm that this issue has been fixed in 3.2.3. The changelog doesn't cleary stipulates it (you can't look up #1525). |
|
I always create the changelog on the fly using github : v3.2.2...v3.2.3 |
|
The changelog does say the cause for the bug (routeset inspection) was On Apr 18, 2012, at 3:40 AM, Thomas Gautier
|
The view context is so large that in some cases (eg. when an exception is raised in a template where multiple presenters are referencing the view_context), the ruby process spins out eating more and more memory before either generating an enormous half-gig log or falling over altogether. This suppresses inspect messages on ActionView::Base allowing exceptions to raise without issue. More info on the issue here: rails/rails#1525 (comment)
Calling `inspect` on Active Record collections fires up a sql query that reads the entire table. `NameError` exceptions call inspect on all local controller instance variables, which in turn can cause application to hang. This has been reported in Rails: rails/rails#1525 Closes #127
Calling `inspect` on Active Record collections fires up a sql query that reads the entire table. `NameError` exceptions call inspect on all local controller instance variables, which in turn can cause application to hang. This has been reported in Rails: rails/rails#1525 Closes #127
Calling `inspect` on Active Record collections fires up a sql query that reads the entire table. `NameError` exceptions call inspect on all local controller instance variables, which in turn can cause application to hang. This has been reported in Rails: rails/rails#1525 Closes #127
|
Out of curiosity (since so many others reference this PR when discussing inspect + exception), Ruby 3.3 will fix this issue: https://bugs.ruby-lang.org/issues/18285 |
and others
Hi,
since I installed rails 3.1.0, when some bugs occur, Webrick freezes for a couple of minutes when some bugs occur (not all bugs, apparently the 500 ones).
My gemfile looks like this:
source 'http://rubygems.org'
gem "rails", "3.1.0.rc1"
Asset template engines
gem 'sass'
gem 'coffee-script'
gem 'uglifier'
gem 'jquery-rails'
gem "simple-navigation"
gem 'ranked-model' #, :git => 'git@github.com:harvesthq/ranked-model.git'
gem 'formtastic'
gem 'validation_reflection'
gem "paperclip", "~> 2.3"
gem 'devise'
gem 'heroku'
gem "aws-s3"
gem "scoped_search"
gem "meta_search", :git => 'git://github.com/ernie/meta_search.git'
gem "kaminari"
group :production do
gem "pg", "~> 0.11.0"
gem 'therubyracer-heroku', '0.8.1.pre3'
gem 'exception_notification', :require => 'exception_notifier'
end
group :development, :test do
gem 'mysql2'
end
require 'csv'
Can anyone help me on this? Thanks,
Nicolas
The text was updated successfully, but these errors were encountered: