This project is archived and is in readonly mode.

#4427 ✓resolved
Karl Alexandre

Strange behaviour in exception display

Reported by Karl Alexandre | April 17th, 2010 @ 09:47 AM | in 3.0.2

I spent a bunch of time tracking a strange baheviour in Rails 3 exception display. The problem doesn't show up in 2.3.5.
Here it is:

Step 1: Context

app/controllers/subitems_controller.rb

class SubitemsController < ApplicationController
  def index
    @subitems = Item.first.subitems
  end
end

app/views/subitems/index.html.erb

<%= @subitems %>
<%= Boum.new %>

result

As expected, this renders Action Controller: Exception caught in the browser with the following message uninitialized constant ActionView::CompiledTemplates::Boum, fine.

Step 2: Not displaying subitems

app/controllers/subitems_controller.rb

class SubitemsController < ApplicationController
  def index
    @subitems = Item.first.subitems
  end
end

app/views/subitems/index.html.erb

<%= Boum.new %>

result

This renders 500 Internal Server Error, weird.

Step 3: Getting sibitems directly, instead of going through the item has_many subitems association

app/controllers/subitems_controller.rb

class SubitemsController < ApplicationController
  def index
    @subitems = Subitem.all
  end
end

app/views/subitems/index.html.erb

<%= Boum.new %>

h4. result
Things back to normal: the exception is rendered correctly in the browser.

h3. Test configuration

OS X 10.5.8
Rails 3.0.0.beta3
Both 1.8.7 p249 & 1.9.1 p378

Am I wrong, or is it an unexpected behaviour?

PS
Sample app attached (in step1 state, rake db:migrate / rake db:seed).

Comments and changes to this ticket

  • Karl Alexandre

    Karl Alexandre April 17th, 2010 @ 09:49 AM

    • no changes were found...
  • Karl Alexandre

    Karl Alexandre April 17th, 2010 @ 09:52 AM

    • no changes were found...
  • Santiago Pastorino

    Santiago Pastorino April 22nd, 2010 @ 08:05 PM

    • Assigned user set to “Santiago Pastorino”

    Karl Alexandre, i have tried your application with the latest rails code from github and works as expected.
    Please get a fresh copy from github, generate the application copy your models, views, controllers, routes and try it again.
    Then we can close this issue.
    Thanks.

  • Karl Alexandre

    Karl Alexandre April 22nd, 2010 @ 09:14 PM

    Santiago,

    I bundled edge rails and still have the problem somehow.
    The first request (step2) renders the exception, all the following render a 500.
    The log file for two requests is attached.

    Karl.

  • Karl Alexandre

    Karl Alexandre April 22nd, 2010 @ 09:20 PM

    • no changes were found...
  • Santiago Pastorino

    Santiago Pastorino April 22nd, 2010 @ 10:51 PM

    Karl, works for me tell me how you did your app.

    You need to have the lastest rails from github and run ruby DIR_WHERE_YOU_HAVE_RAILS_REPO/bin/rails myapp --dev

    And then start doing the routes, models, and all again.

    Let me know.

  • Karl Alexandre

    Karl Alexandre April 23rd, 2010 @ 08:01 AM

    Santigo,

    Run this script and tell me the result on your side.

    Karl.

  • Santiago Pastorino

    Santiago Pastorino April 23rd, 2010 @ 02:24 PM

    Ok i'm trying right now, try this one you.

  • Santiago Pastorino

    Santiago Pastorino April 23rd, 2010 @ 02:27 PM

    Your patch doesn't apply cleanly on a fresh Rails edge generated app.
    But try my app.

  • Karl Alexandre

    Karl Alexandre April 27th, 2010 @ 09:32 AM

    • Tag changed from “actiondispatch, activerecord, exception” to “activerecord rails3, actiondispatch, activerecord, exception”

    Santiago,

    Sorry for late reply,

    In your app you have Subitems.all in the controller, it works ok with it.
    Now try Item.first.subitems , it fails on the second request for me.
    Strange thing is that Item.first.subitems.all works fine, but Item.first.subitems fails.

    yours,
    Karl.

  • Steven Ringo

    Steven Ringo April 27th, 2010 @ 10:18 AM

    • Assigned user changed from “Santiago Pastorino” to “Ryan Bigg”

    Just tried this with the following configuration:

    ruby 1.9.1p378 (2010-01-10 revision 26273) [i386-darwin10.2.0]
    Rails 3.0.0.beta3

    Works as expected and yields:
    undefined method subitems' for nil:NilClass

  • Karl Alexandre

    Karl Alexandre April 27th, 2010 @ 11:12 AM

    Steven,
    It seems you don't have the database populated with at least one item. Did you run rake db:seed ?

  • Ryan Bigg

    Ryan Bigg April 27th, 2010 @ 11:21 AM

    I did this and I get:
    uninitialized constant ActionView::CompiledTemplates::Boum. No 500 page, just a standard white-and-grey error page.

  • Karl Alexandre

    Karl Alexandre April 27th, 2010 @ 12:06 PM

    Ryan,
    The first request is always OK. Try two requests in a row, and tell me the result of the second one.

    I'm digging deeper and what I see now is that ActionDispatch::ShowExceptions::render_exception goes FAILSAFE while rendering this exception for the second time.

  • Ryan Bigg

    Ryan Bigg April 27th, 2010 @ 12:13 PM

    Multiple requests works for me, I'm interested as to how you can replicate this issue.

  • Anil Wadghule

    Anil Wadghule April 27th, 2010 @ 01:06 PM

    yeah it is an issue. See here http://pastie.org/937107. When you start server you get proper error page with exception. On second request you get "500 Internal Server Error"

  • Karl Alexandre

    Karl Alexandre April 27th, 2010 @ 01:45 PM

    Anil,

    I don't get this exact trace, but that's the point.

    Two interresing points :
    - First, the association gets loaded even if not used (in my example), - Second, the exception fire two times as expected, but the middleware goes fail safe with can't dup nil class on the second rendering (may be something to do with template compiler ?)

  • Karl Alexandre

    Karl Alexandre April 27th, 2010 @ 03:20 PM

    All,

    The cause of the problem is that _request_and_response.erb template inspects the current controller throught request.env["action_controller.instance"]

    In my example app this reference the @subitems instance variable.

    If I prevent this to happen by adding <%@request.env.delete("action_controller.instance")%> to _request_and_response.erb , everything goes fine.

    Why all this lead to a can't dup nil class in ActiveRecord::Base.scoped_methods (Cause of the 500) ? To be continued...

  • Jeremy Kemper

    Jeremy Kemper April 27th, 2010 @ 06:44 PM

    • Milestone cleared.
    • State changed from “new” to “open”
  • Dan Pickett

    Dan Pickett May 15th, 2010 @ 01:51 AM

    • Tag changed from “activerecord rails3, actiondispatch, activerecord, exception” to “activerecord rails3, actiondispatch, activerecord, bugmash, exception”

    Can a bugmasher reproduce this behavior?

  • Rohit Arondekar

    Rohit Arondekar May 15th, 2010 @ 04:10 AM

    I too got a 500 Internal Server Error by following the steps provided by Karl.

    I created a gist of the rails server output => http://gist.github.com/401967 -- Note that I have demarcated the logs of the two requests. Before the " Started GET "/subitems/index" " of the second request a error is shown as follows:

    Error during failsafe response:
    ActionView::Template::Error (can't dup NilClass) in /home/rohit/.rvm/gems/ruby-1.9.2-head/gems/actionpack-3.0.0.beta3/lib/action_dispatch/middleware/templates/rescues/_request_and_response.erb:

    Also by switching to Subitem.all the 500 error doesn't appear.

  • Rohit Arondekar

    Rohit Arondekar May 15th, 2010 @ 05:19 AM

    Forgot to mention my environment:
    Ubuntu 10.04
    ruby 1.9.2dev (2010-05-08 trunk 27665) [x86_64-linux]
    Rails 3.0.0.beta3

  • Anil Wadghule

    Anil Wadghule May 15th, 2010 @ 07:14 AM

    verified

    See pasties for info about the logs

    https://gist.github.com/2cc2371975ade98b85e5
    http://pastie.org/937107

    Environment:
    Macbook Pro Snow Leopard
    ruby-1.8.7-p249 [ x86_64 ]
    Rails 3 master branch "a0621c1086165e4b3cff71b54f08a190851b6314"

    Attached is rails app with which this bug is reproducible.

  • Gavin Stark

    Gavin Stark May 15th, 2010 @ 10:20 PM

    This is happening, I believe, because in ActiveRecord::Base

        def scoped_methods #:nodoc:
      key = :"#{self}_scoped_methods"
      Thread.current[key] = Thread.current[key].presence || self.default_scoping.dup
    end

    On the second request self.default_scoping is nil as opposed to []. This causes an exception trying to dup nil. However, I cannot see what is setting the default_scoping to nil

  • Jonas Huckestein

    Jonas Huckestein May 28th, 2010 @ 10:35 PM

    I had the same problem when using Tyler Kovac's HyperBase with is a subclass of ActiveRecord::Base.

    default_scoping is defined as a class_inheritable_accessor in base.rb. It gets initialized in ActiveRecord::Base and HyperBase wasn't able to see the default value. Adding "self.default_scoping = self.superclass.default_scoping" to HyperBase resolved the situation. I'm not sure if that is a smart fix, though. It is my understanding that this is the intende behavior of class_inheritable_accessor.

    What I don't understand is why most ActiveRecord::Base subclasses to see the default value for default_Scoping (which is []). Can somebody from the team explain how that works?

    This problem was killing me, hope I could help a little bit.

  • Rohit Arondekar

    Rohit Arondekar August 3rd, 2010 @ 08:27 AM

    • Importance changed from “” to “High”

    I can't reproduce this on Rails 3 RC, can somebody else give a try?

  • Jeremy Kemper

    Jeremy Kemper August 30th, 2010 @ 04:10 AM

    • Milestone cleared.
  • Len Smith

    Len Smith September 14th, 2010 @ 12:16 AM

    Can't reproduce on Safari, Chrome or Firefox on OSX, Rails 3.0.0 and ruby 1.9.2p0.

  • Rohit Arondekar

    Rohit Arondekar September 14th, 2010 @ 04:23 AM

    • State changed from “open” to “resolved”

    I think this issue got resolved along the way. I'm going to go ahead and close. If anybody still faces this issue just leave a comment and I'll reopen it.

  • Andrea Campi

    Andrea Campi October 8th, 2010 @ 03:57 PM

    • Assigned user changed from “Ryan Bigg” to “Rohit Arondekar”

    Just a reminder you said you would close this :)

  • Rohit Arondekar

    Rohit Arondekar October 9th, 2010 @ 01:37 AM

    Andrea, the ticket is already closed as 'resolved'. :)

  • Jeremy Kemper

    Jeremy Kemper October 15th, 2010 @ 11:01 PM

    • Milestone set to “3.0.2”
  • Jeff Kreeftmeijer

    Jeff Kreeftmeijer November 8th, 2010 @ 08:51 AM

    • Tag cleared.

    Automatic cleanup of spam.

  • yoyogo

    yoyogo March 31st, 2011 @ 05:59 AM

    oh my!! i love you so much!!

    Thank you so much.
    Hermes Bags
    http://www.louisvuittonparty.com/
    Hermes Bags

  • af001

    af001 May 5th, 2011 @ 02:55 AM

    私の中で、総合評価のとっても低いアバアバクロホリスタークロ銀座店。アバクロは大好きなんですけどね。一昨日の東京駅付近での打ち合わせの後、散歩がてら久々に行ってきました。そしたらビックリ！相変わらアバクロず、踊っているだけの店員さんとかもいましたが、

  • ssupreme11

    ssupreme11 May 10th, 2011 @ 10:29 PM

    Its my first time to visit this site and as I was exploring I cant believe that this site was made up of a very informative articles that you should try to have compliment with so as what I am doing now I really love to look forward with more interesting information on this site..

    Regards,
    Dissertation Proposal

  • csnk

    csnk May 18th, 2011 @ 08:14 AM

    cleanup of spam.Automatic cleanup of spam.clothing factory

Create your profile

Help contribute to this project by taking a few moments to create your personal profile. Create your profile »

<h2 style="font-size: 14px">Tickets have moved to Github</h2>

The new ticket tracker is available at <a href="https://github.com/rails/rails/issues">https://github.com/rails/rails/issues</a>

People watching this ticket

Attachments

Referenced by

Pages