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?

Hey Geoff,

Just a NoMethodError for nil.include?

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?

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

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.

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.

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?

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

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?

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

@Nando,

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

http://pastie.org/306051

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!

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] ?)

..try again with that code snippet:

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

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

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

@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?

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.

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

Zip file added here for posterity.

@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, 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.

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

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

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

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.

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

New ticket opened: #1339

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

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.

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.

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

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

http://gist.github.com/251886