December 18, 2007 @ 07:21 PM
Adventures in Rails Debugging
After upgrading my app to Rails 2.0, I started getting an error, but only when running a rake task (such as rake db:migrate).
$ rake db:migrate --trace
(in /Users/rick/p/lighthouse/trunk)
** Invoke db:migrate (first_time)
** Invoke environment (first_time)
** Execute environment
rake aborted!
uninitialized constant Technoweenie::ActiveRecordContext
/Users/rick/p/lighthouse/trunk/vendor/rails/activerecord/lib/../../activesupport/lib/active_support/dependencies.rb:266:in `load_missing_constant'
/Users/rick/p/lighthouse/trunk/vendor/rails/activerecord/lib/../../activesupport/lib/active_support/dependencies.rb:453:in `const_missing'
/Users/rick/p/lighthouse/trunk/vendor/plugins/active_record_context/init.rb:1:in `evaluate_init_rb'
So, it’s failing on the first line of my active_record_context’s init.rb file:
ActiveRecord::Base.send :include, Technoweenie::ActiveRecordContext
Where’s the require? I leave it out, relying on ActiveSupport::Dependencies to auto-load the module for me. But, it seems to be failing me in my rake tasks. The fact that it’s working when I run script/server or script/console makes me think it’s some wacky LOAD_PATH issue. So, I try this in the init.rb file:
puts $LOAD_PATH.inspect
puts Dependencies.load_paths.inspect
ActiveRecord::Base.send :include, Technoweenie::ActiveRecordContext
Running both my rake task and script/console don’t show any differences, so that’s a dead end. Next, I turn my attention to Dependencies. The first stack trace showed it failing on line 266 in Dependencies.load_missing_constant. Above the large if statement seems like a good spot for some debugging.
$ rdebug `which rake` db:migrate -n -- --trace
Here are some interesting variables:
- qualified_name – “Technoweenie::ActiveRecordContext”
- path_suffix – “technoweenie::active_record_context”
That doesn’t look like a normal path, String#underscore should be converting :: to /. Next, I run this in script/server (script/console has no switch to enable the debugger).
$ script/server -u
- qualified_name – “Technoweenie::ActiveRecordContext”
- path_suffix – “technoweenie/active_record_context”
So, something is messing with String#underscore, but only when rake runs. Interesting… I then do a grep of my vendor directory, looking for ‘def underscore’ and find 3 locations: ActiveSupport, bj, and AWS::S3. bj managed to copy ActiveSupport’s version of the method exactly, but S3 left out the part that converts :: to /:
# ActiveSupport adds an underscore method to String so let's just use that one if
# we find that the method is already defined
def underscore
gsub(/([A-Z]+)([A-Z][a-z])/,'\1_\2').
gsub(/([a-z\d])([A-Z])/,'\1_\2').
downcase
end unless public_method_defined? :underscore
So, AWS::S3 only adds that method if ActiveSupport isn’t available. Looking at ‘String.included_modules’ while debugging does list ‘ActiveSupport::CoreExtensions::String::Inflections’, so it’s looking like AWS::S3 is loading before ActiveSupport somehow.
Then it hits me, I’m loading it in a rake task! Doh…

by topfunky on 18 Dec 20:12
A gripping story until the very end!
I was worried that you weren’t going to resolve it by the end of the blog post.
by rick on 18 Dec 22:53
Yea, it’s like a lot of hollywood movies. Cool premise with the letdown ending :)
by Dr Nic on 19 Dec 01:14
A wonderful Christmas story!
by Bill on 19 Dec 13:13
I guess I’m not sure what that means.
Why does it load in a rake task first and not in script/server?
by sudara on 19 Dec 17:43
Ahhh, it’s good to see a new post here.
I can’t tell you how much better of a programmer I’ve become from passively observing your work and actively digging into your creations.
Keep up the blog posts – You have a knack for explaining areas of the rails world that people wouldn’t otherwise explore.
by rick on 22 Dec 16:47
Bill: yes, it gets loaded when my rake tasks load (which is before the rails environment loads). Rails does eventually load for migrations, however, but the AWS::S3 version of underscore still gets called. ActiveSupports adds its methods in a module, while AWS::S3 modifies the String class directly, taking precedence.
sudara; thanks. It’s been far too long since I felt the urge to blog. I promised a few folks I’d blog about one of the libs I’m working on, so this shouldn’t be the last one :)