Comments and changes to this ticket

• 

  DHH October 30th, 2008 @ 10:36 AM

  • Tag changed from “activerecord, date, datetime, edge, timezone, utc” to “activerecord, bug, date, datetime, edge, timezone, utc”
  • Assigned user set to “Geoff Buesing”
• 

  Geoff Buesing October 30th, 2008 @ 02:29 PM

  Hi Nando,

  Specifically what error is raised? (this is just the stack trace)

  Also, which version of Ruby are you using, and what are you setting config.time_zone to?

• You flagged this item as spam.
  

  Nando Vieira October 31st, 2008 @ 08:10 PM

  Hey Geoff,

  Just a NoMethodError for nil.include?

• You flagged this item as spam.
  

  Nando Vieira October 31st, 2008 @ 08:14 PM

  Here's the error:

  
  You have a nil object when you didn't expect it!
  You might have expected an instance of Array.
  The error occurred while evaluating nil.include?
  

• You flagged this item as spam.
  

  Nando Vieira October 31st, 2008 @ 08:27 PM

  Don't know where and why but skip_time_zone_conversion_for_attributes is being set no nil.

• You flagged this item as spam.
  

  Justin Leitgeb November 1st, 2008 @ 01:09 PM

  I'm having this issue on edge rails as well. I'm running ruby 1.8.7 (2008-08-11 patchlevel 72), and unfortunately I don't have a 1.8.6 machine to test on at the moment. Nando, what ruby version are you running?

  More info which may help with troubleshooting:

  My config.time_zone is set to 'UTC'.

  In my application, I can do one successful request for a url that has the following code (in the view) before I get this error and have to restart the server:

  
  link_to(image_tag(@refacement.images.first.thumbnails.find_by_thumbnail('medium').url), @refacement.images.first.thumbnails.find_by_thumbnail('large'), :popup => true)
  

  If I remove the link_to, and just include the image_tag part of the code above, I can't reproduce the issue:

  
  image_tag(@refacement.images.first.thumbnails.find_by_thumbnail('medium').url)
  

  The primary resource that I'm testing with is eager-loading its associated resources (including images and thumbnails), but I have the same issue when I take out the eager-loading code. It doesn't change the behavior when I turn on or off caching of the result set that I'm using with memcached.

  So the most minimal set of code changes that I can make involve the link_to in the view above. Let me know if I can do anything else to help troubleshoot this issue.

• You flagged this item as spam.
  

  Nando Vieira November 1st, 2008 @ 02:34 PM

  I'm using the Mac OS X 10.5 Ruby:

  $ ruby -v ruby 1.8.6 (2008-03-03 patchlevel 114) [universal-darwin9.0]

  My time zone is also set to UTC but I overwrite it when user is logged.

• 

  Geoff Buesing November 1st, 2008 @ 07:57 PM

  Jsl and Nano, thanks for your help with this.

  @Jsl, just to confirm, you're getting exactly the same error that Nano is getting, i.e., a NoMethodError when "create_time_zone_conversion_attribute?" is called by ActiveRecord?

  I tried creating a new app on edge and replicating this issue (I'm on ruby 1.8.6 (2007-09-24 patchlevel 111)), but I wasn't able to.

  Can you both confirm that there's no code in your app or plugins that would be setting skip_time_zone_conversion_for_attributes to nil? Rails itself initializes this to an empty array, and otherwise never changes it; it only reads from it.

  Does this error occur when running in both development and production modes? I'm wondering if this might be an issue with reloading.

  Does this issue occur with different resources in your apps, or is it just with a particular resource/association?

• You flagged this item as spam.
  

  Justin Leitgeb November 1st, 2008 @ 08:31 PM

  Hi Geoff,

  Yes, the error is the same as the one that Nano reported. Attached is the application trace, in case it provides any useful information. I did a grep through everything in my project and plugins for the string "skip_time_zone_conversion_for_attributes", but it didn't appear anywhere outside of vendor/rails.

  I can only produce this error with the one association that I mentioned in my initial ticket (a polymorphic association), but I haven't tested extensively with other association types.

  I think that you may be on to something with the suspicion about reloading. I initialized my development environment with most of the settings from production.rb, and couldn't reproduce the error. I started modifying them one at a time, and finally figured out that the error only occurs when config.cache_classes is set to false.

  @Nando - does changing config.cache_classes to true stop this error for you as well?

  Justin

  • trace.txt 4.3 KB
• 

  Michael Koziarski November 2nd, 2008 @ 09:22 AM

  • Milestone cleared.
• 

  Geoff Buesing November 2nd, 2008 @ 05:10 PM

  As best as I can tell, this is an issue with certain AR models not reloading correctly in development, as opposed to an issue with just the time zone features.

  In 2.2, skip_time_zone_conversion_for_attributes was changed from a cattr_accessor, which stores the value in a @@skip_time_zone_conversion_for_attributes class variable, to a class_inheritable_accessor, which stores the value in a hash stored in the @inheritable_attributes instance variable.

  In development mode, ActiveRecord::Base.reset_subclasses is called at the end of each request. This method removes all instance variables from each subclass, which would blow away @inheritable_attributes.

  If the class reloads correctly, @inheritable_attributes will be reset to their default values (for skip_time_zone_conversion_for_attributes, this defaulted to an empty Array.)

  However, if a model class somehow does not reload correctly, we could be left with a model with all instance variables removed, but not re-initialized. Hence the blow up when #include? is called on nil instead of the array that skip_ was supposed to be initialized to.

  I came up with this pastie -- http://pastie.org/305903 -- which, when added as an initializer, shows debug info each time attributes are inherited by a subclass of AR::Base. In development mode, each time I request a page that requires an AR model class, I'll see output that shows that the model inherited @inheritable_attributes correctly.

  @Justin and @Nando,

  1. could you pull in this pastie, and see if it shows that your models are inheriting these attributes correctly?

  2. with the models that are causing problems, are you doing STI, or using observers, or including code from specific plugins? Or something else out of the ordinary?

  3. are you doing anything custom with dispatching, or dependencies, or including libraries that would do this?

• You flagged this item as spam.
  

  Nando Vieira November 2nd, 2008 @ 09:28 PM

  Geoff,

  Setting config.cache_classes = truestopped raising this error.

  About the logging method you created, I'm receiving this error:

  
  /Users/fnando/Sites/wiiluv/app/config/initializers/dependencies.rb:29:in `inherited': undefined method `inherited_without_logging' for Object:Class (NoMethodError)
  	from /Users/fnando/Sites/wiiluv/app/vendor/rails/actionpack/lib/action_controller/dispatcher.rb:4
  	from /Library/Ruby/Site/1.8/rubygems/custom_require.rb:27:in `gem_original_require'
  	from /Library/Ruby/Site/1.8/rubygems/custom_require.rb:27:in `require'
  	from /Users/fnando/Sites/wiiluv/app/vendor/rails/activesupport/lib/active_support/dependencies.rb:148:in `require'
  	from /Users/fnando/Sites/wiiluv/app/vendor/rails/activesupport/lib/active_support/dependencies.rb:507:in `new_constants_in'
  	from /Users/fnando/Sites/wiiluv/app/vendor/rails/activesupport/lib/active_support/dependencies.rb:148:in `require'
  	from /Users/fnando/Sites/wiiluv/app/vendor/rails/railties/lib/dispatcher.rb:23
  	from /Library/Ruby/Site/1.8/rubygems/custom_require.rb:27:in `gem_original_require'
  	 ... 35 levels...
  	from /Users/fnando/Sites/wiiluv/app/vendor/rails/railties/lib/commands/server.rb:49
  	from /Library/Ruby/Site/1.8/rubygems/custom_require.rb:27:in `gem_original_require'
  	from /Library/Ruby/Site/1.8/rubygems/custom_require.rb:27:in `require'
  	from script/server:3
  
  

• 

  Geoff Buesing November 2nd, 2008 @ 10:21 PM

  @Nando,

  Apologies, there was a typo in that last pastie -- try this one:

  http://pastie.org/306051

• You flagged this item as spam.
  

  Nando Vieira November 2nd, 2008 @ 10:48 PM

  Geoff,

  All classes are being loaded correctly.

  
  SUCCESS REQUEST
  ===========
  
  === User is inheriting attributes from ActiveRecord::Base. @inheritable_attributes={:scopes=>{:scoped=>#<Proc:0x0219e090@/Users/fnando/Sites/wiiluv/app/vendor/rails/activerecord/lib/active_record/named_scope.rb:86>, :sort_by=>#<Proc:0x0219e090@/Users/fnando/Sites/wiiluv/app/vendor/rails/activerecord/lib/active_record/named_scope.rb:86>, :paginate=>#<Proc:0x0219e090@/Users/fnando/Sites/wiiluv/app/vendor/rails/activerecord/lib/active_record/named_scope.rb:86>}, :record_timestamps=>true, :skip_time_zone_conversion_for_attributes=>[]} ===
  
  === Game is inheriting attributes from ActiveRecord::Base. @inheritable_attributes={:scopes=>{:scoped=>#<Proc:0x0219e090@/Users/fnando/Sites/wiiluv/app/vendor/rails/activerecord/lib/active_record/named_scope.rb:86>, :sort_by=>#<Proc:0x0219e090@/Users/fnando/Sites/wiiluv/app/vendor/rails/activerecord/lib/active_record/named_scope.rb:86>, :paginate=>#<Proc:0x0219e090@/Users/fnando/Sites/wiiluv/app/vendor/rails/activerecord/lib/active_record/named_scope.rb:86>}, :record_timestamps=>true, :skip_time_zone_conversion_for_attributes=>[]} ===
  
  
  RAISED REQUEST
  ==============
  
  === User is inheriting attributes from ActiveRecord::Base. @inheritable_attributes={:scopes=>{:scoped=>#<Proc:0x0219e090@/Users/fnando/Sites/wiiluv/app/vendor/rails/activerecord/lib/active_record/named_scope.rb:86>, :sort_by=>#<Proc:0x0219e090@/Users/fnando/Sites/wiiluv/app/vendor/rails/activerecord/lib/active_record/named_scope.rb:86>, :paginate=>#<Proc:0x0219e090@/Users/fnando/Sites/wiiluv/app/vendor/rails/activerecord/lib/active_record/named_scope.rb:86>}, :record_timestamps=>true, :skip_time_zone_conversion_for_attributes=>[]} ===
  
  === Game is inheriting attributes from ActiveRecord::Base. @inheritable_attributes={:scopes=>{:scoped=>#<Proc:0x0219e090@/Users/fnando/Sites/wiiluv/app/vendor/rails/activerecord/lib/active_record/named_scope.rb:86>, :sort_by=>#<Proc:0x0219e090@/Users/fnando/Sites/wiiluv/app/vendor/rails/activerecord/lib/active_record/named_scope.rb:86>, :paginate=>#<Proc:0x0219e090@/Users/fnando/Sites/wiiluv/app/vendor/rails/activerecord/lib/active_record/named_scope.rb:86>}, :record_timestamps=>true, :skip_time_zone_conversion_for_attributes=>[]} ===
  

  Double checked all plugins I'm using: they're not using skip_time_zone_conversion_for_attributes at all!

• 

  Geoff Buesing November 3rd, 2008 @ 12:08 AM

  Thanks, Nando. Ok, so it appears inheritable attributes are inheriting correctly for AR::Base.

  Something else to try -- if you set explicitly set skip_time_zone_conversion_for_attributes to an empty array in your models, like so:

  class Game < ActiveRecord::Base # ... self.skip_time_zone_conversion_for_attributes = [] # ... end

  ...does the problem still occur?

  (if it does, what if you then set it to a non-empty array, like [:created_at] ?)

• 

  Geoff Buesing November 3rd, 2008 @ 12:09 AM

  ..try again with that code snippet:

  
  class Game < ActiveRecord::Base
    # ...
    self.skip_time_zone_conversion_for_attributes = []
    # ...
  end
  

• You flagged this item as spam.
  

  Nando Vieira November 3rd, 2008 @ 01:55 AM

  Setting self.skip_time_zone_conversion_for_attributes to an empty array or [:created_at] doesn't solve the problem. Anything else?

• You flagged this item as spam.
  

  David Rice November 4th, 2008 @ 05:42 PM

  I'm getting this too, exactly the same scenario.

  • Production environment is fine, it only affects development.
  • The first page load works, all subsequent requests fail with this error.
  • Manually setting skip_time_zone_conversion_for_attributes doesn't solve it.
  • Ruby 1.8.6 (Patchlevel 22) on Leopard
  • Default tz is set
  • Rails 2.2 release candidate && edge

  Let me know if there's anything that I can help with.

  Best, Dave

• 

  Geoff Buesing November 4th, 2008 @ 06:15 PM

  @David, thanks for the report. As Justin and Nando have reported, does the problem only happen with a specific page?

  I think a next step here would be, if someone who's experiencing the issue could try to replicate this issue in a fresh app. That, or try building up the problem page from scratch, to isolate the code that's causing the problem.

  @David, @Nando or @Justin, would one of you be willing to help us out with this?

• You flagged this item as spam.
  

  David Rice November 4th, 2008 @ 06:48 PM

  Geoff, it happens on every request (logic is referenced in application.html.erb)

  So, I'm trying to get example code together to replicate this but (would you believe) it's being a little bit pesky... will post if I uncover anything.

• You flagged this item as spam.
  

  David Rice November 4th, 2008 @ 11:40 PM

  Result. Here's a rails app that replicates this issue. The cause as far as I can see is assigning an ActiveRecord::Base subclass to a constant (on initialize of Rails)

  http://github.com/davidjrice/bug...

  Now, it's probably an anti-pattern we've uncovered (I'm on a refactoring mission after all)... The data is more perhaps better suited to be represented with a struct (or even just a hash).

  I'll be refactoring that part of the client's app for sure so I'm not too bothered if it's a wontfix :)

  Best, Dave

• You flagged this item as spam.
  

  David Rice November 4th, 2008 @ 11:41 PM

  Zip file added here for posterity.

  • lighthouse-ticket-1290.zip 104.2 KB
• 

  Geoff Buesing November 5th, 2008 @ 03:29 PM

  @David, thanks for isolating this problem, and the demo app example -- very helpful.

  A few things:

  1. with this example app, I get the error "undefined method >' for #<Monkey:0x208faa0>" on edge, and 2.1.0-2 gems (as expected)

  2. if I alter the failing code in this example from

  
  MONKEY_ONE > @monkey_two
  

  to

  
  MONKEY_ONE.created_at
  

  ...on edge, I get the nil.include? error reported by Justin and Nando above, but on 2.1.x gems, it works fine (concurrent with the behavior that Nando reported in his app when upgrading to edge.)

  I guess this makes sense -- AR::Base#method_missing re-generates attribute methods, but not #>. I would assume that if Nando were calling a non-attribute method in his failing example, it would have failed on 2.1.x as well.

  1. I found this Lighthouse ticket: http://rails.lighthouseapp.com/p... which seems to be addressing the same issue. Looks like some folks are getting this problem from storing an AR object in the Rails.cache.

  Given all the evidence from this ticket and the related ticket referenced above, I think we can assume that the issues reported in this ticket are because of an issue with AR instances persisting between requests (from Rails.cache, constant caching, or whatever other situations this could occur) when config.cache_classes = false.

  @Nando and @Justin, in your failing cases, are you doing any sort of caching of AR objects?

• 

  Geoff Buesing November 5th, 2008 @ 03:39 PM

  • Tag changed from “activerecord, bug, date, datetime, edge, timezone, utc” to “activerecord, bug, cache”
  • Assigned user changed from “Geoff Buesing” to “josh”

  Josh, I think this ticket relates to the caching issue identified in http://rails.lighthouseapp.com/p...

• You flagged this item as spam.
  

  chrispanda November 5th, 2008 @ 03:43 PM

  • Assigned user changed from “josh” to “Geoff Buesing”
  • Tag changed from “activerecord, bug, cache” to “activerecord, bug, date, datetime, edge, timezone, utc”

  I think I just hit the same bug - or at least similar Loading data into a model in the console I get:

  
  NoMethodError: You have a nil object when you didn't expect it!
  You might have expected an instance of Array.
  The error occurred while evaluating nil.include?
  	from /usr/lib/ruby/gems/1.8/gems/activerecord-2.2.0/lib/active_record/attribute_methods.rb:142:in `create_time_zone_conversion_attribute?'
  

  Adding the line:

  
  self.skip_time_zone_conversion_for_attributes=[]
  

  to the model removes the problem

  and so does commenting out the line:

  
  config.time_zone = 'UTC'
  

  in environment.rb

  This with Rails RC2.2 and ruby 1.8.7

• You flagged this item as spam.
  

  Tom Lea November 5th, 2008 @ 04:50 PM

  @Geoff, I assume the following fixes the issue: http://rails.lighthouseapp.com/a...

  #785 went very stale because we ended up with a catch-22, either existing instances lose their methods and go mental, or existing instances remain as they were before the reload!. After a while I just gave up hope, there was no panacea that would monkey patch all existing subclasses with updated instance methods and variables, to keep their instances sane.

  There is no good reason for stripping down all subclasses of AR::Base before a reload, apart from the alleged memory leak issue, which I can't replicate.

  IMHO (and for that matter IIRC) the lines should be stripped out, they are irrelevant in production, and were intended to do a job in development, that: A) isn't needed (who cares about a little wasted memory in dev mode?) B) shows no signs of doing the job it was intended to. c) has no test coverage.

• You flagged this item as spam.
  

  chrispanda November 5th, 2008 @ 05:39 PM

  sorry - my problem was unrelated though it threw a similar error - fixed by replacing

  
  config.time_zone = 'UTC'
  

  with

  
  config.active_record.default_timezone = :utc
  

  as required for 2.2

• 

  Geoff Buesing November 5th, 2008 @ 07:51 PM

  • Tag changed from “activerecord, bug, date, datetime, edge, timezone, utc” to “activerecord, bug, cache”
  • Assigned user changed from “Geoff Buesing” to “josh”

  @Tom Lea -- thanks for the info. Indeed, that seems like the best fix here. But we should definitely confirm that the memory leak is no longer an issue, or at least, is not enough of an issue to merit this confusing/broken behavior in development mode.

  If you were able to write up a description of the problem and solution and post it to the core list, so that we could get feedback, that would be helpful here -- the outstanding tickets about this issue are quite long and hard to follow.

  @chrispanda -- actually, I there's a good chance your problem is related to what we've discovered here. By removing config.time_zone and adding config.active_record.default_timezone (which, btw, is not required for 2.2) you may have worked around the issue, but you've removed time zone support from your app in the process.

  @Lighthouse -- if someone submits a comment with a stale version of the page, it says they changed tags etc. Consider splitting these functions into two separate forms.

• You flagged this item as spam.
  

  Nando Vieira November 5th, 2008 @ 10:53 PM

  Yay!!!! Will this patch be applied on edge?

• You flagged this item as spam.
  

  Tom Lea November 6th, 2008 @ 08:43 PM

  Was posted to core list, here for reference.

  I diagnosed the following issue as part of [1], but it has since come up again as part of [2].

  == The issue: ==

  Whenever an AR::Base instance is persisted between requests with cache_classes disabled, Dispatcher#reset_application! will go through all its subclasses and remove all its instance methods and instance variables (those on the instance of Class not on instances of AR::Base, it's all very confusing!).

  This was intended to fix a memory leak [3], and had a test associated with it. The test is now long gone, and my efforts at re-adding it failed because I never got it to pass, with or without the class stripping.

  == The effect: ==

  The example app by David Rice [4] will explode with error [5] after 2 page loads.

  This app saves an AR model to a constant at startup... then expects it to work after a reload!.

  After a reload the model gets very confused, as its class has all its class_inheritable_attributes stripped.

  It expects an array to be dangling off the end of #skip_time_zone_conversion_for_attributes, but instead it finds nil.

  This sucks.

  == What should happen (IMHO): ==

  Removing the references to classes in @@subclasses should be enough to allow garbage collection to do the good stuff when the relevant constants (that refer to the classes) are removed.

  This way, any objects that are still referencing those classes (you know, like when they are an instance of them), can still operate without unnecessary loss of organs.

  == The patch: ==

  The attached patch, rebased especially for the occasion, stops AR from behaving in this odd way, and seems to pass the existing test pack.

  == The questions: ==

  Does anyone have a good reason why these lines should stay?

  Can anyone create a failing test case? (preferably one that passes before the patch is applied ;)

  Does anyone remember why the code is there?

  Thanks in advance for any thoughts / input / other. - Tom

  p.s. I had to revert my local rails back to 55707da1a1481, as 8adb79b9b598 onwards clashed with my MySQL. Tests passed at that point though.

  [1] http://rails.lighthouseapp.com/p... [2] http://rails.lighthouseapp.com/p... [3] http://github.com/rails/rails/co... [4] http://rails.lighthouseapp.com/a... [5] http://pastie.org/308884

  • prevent_class_method_and_variable_nukeing_on_AR_reset_subclasses.diff 1.1 KB
• 

  josh November 6th, 2008 @ 09:17 PM

  Woah, really long story.

  @Tom Maybe we should start a new ticket that wraps up all the issues across the multiple tickets. I don't really feel comfortable committing this because the dependency loading is not my area of expertise. Though it sounds like this should fix the issue.

• You flagged this item as spam.
  

  Tom Lea November 6th, 2008 @ 09:41 PM

  Yeah, it is a little epic, and all that for a 2 line patch!

  New ticket opened: #1339

• 

  Michael Koziarski November 7th, 2008 @ 07:42 AM

  So should we close this one in favour of #1339?

• 

  josh November 10th, 2008 @ 06:39 PM

  • State changed from “new” to “duplicate”

  Yeah, please refer to #1339

• You flagged this item as spam.
  

  Rob Anderton November 24th, 2008 @ 12:19 PM

  Just wanted to add a note that this error may not be directly related to #1339 - I was getting it in a class when it was first used in a Rails console, without any reloading taking place. I'll spare you the exciting details but I eventually tracked it down to ActsAsStateMachine.

  So if you're using an STI model with the Rubyist-aasm gem v2.0.2 and get the error described at the start of this ticket you need to freeze the 'edge' version of the aasm gem in vendor/gems.

  The relevant commit that fixes this problem is here if you're interested: http://github.com/rubyist/aasm/c...

  Hopefully this will save others spending too much time trying to track down the problem.

• You flagged this item as spam.
  

  pjammer September 13th, 2009 @ 05:29 PM

  I'm using rails 2.3.4 and i recieved the same error and stack trace as the original poster. issue #1339 may help fix it, how knows, as that ticket is a mess. but the simple fix for me was the comment by chrispanda regarding switching to the old style of config line.

  i added

  config.active_record.default_timezone = 'Eastern Time (US & Canada)'
  

  and it seems to work fine and more importantly I don't have to switch config.cache_classes = false to true, now and my rails app acts like normal. Setting to true is not the real answer, and i'm unsure what is, as i don't even know where to begin to help out on this one.

  I am just reporting that this issue happened to me also in 2.3.4. I also don't know what is going to happen to my timezones now that i am using the old style of setting. time will tell.

• You flagged this item as spam.
  

  Peter Zlatnar September 18th, 2009 @ 08:45 AM

  @pjammer this solution also works for me on rails 2.3.2 so I cancel previous solution confi.cache_classes = true

• You flagged this item as spam.
  

  igul222 November 26th, 2009 @ 06:16 PM

  • Assigned user cleared.

  I got this error under Rails 2.3.4, and renaming one of my AR models from "Sync" to "SyncObject" seemed to fix the issue.

• You flagged this item as spam.
  

  igul222 November 26th, 2009 @ 06:17 PM

  • Assigned user set to “josh”

  (oops, didn't mean to clear the assigned user)

• You flagged this item as spam.
  

  rubymaverick December 8th, 2009 @ 06:53 PM

  If you are getting this bug because of storing an AR object in cache, here is a fix:

  http://gist.github.com/251886

• You flagged this item as spam.
  

  macario July 28th, 2010 @ 02:41 AM

  • Importance changed from “” to “”

  I was having the very same issue with 2.5.8 but then suddenly I stated having a can't dup NilClass in /Users/sistemasinteractivos/.rvm/gems/ruby-1.8.7-p174/gems/activerecord-2.3.8/lib/active_record/base.rb:2219:in dup':

  Spoooky!!!

  http://gist.github.com/493164

  I turned cache_classes to true so I wouldn't go nuts.

  I think I can live with that since I spend most of my time in textmate with rspec.