The Buckblog

ActiveRecord is cool and all, and it goes without saying that we all trust its judgment, but sometimes you just want to watch while it does its thing. For instance, just today, I wanted to verify that, in edge Rails, ActiveRecord no longer loads the entire collection when doing a scoped “create”.

In other words, consider the following snippet:

1
2
3
4
5
6

class Account < ActiveRecord::Base
  has_many :people
end

account = Account.find(:first)
person = account.people.create :name => "Jamis Buck"

Before Rails 1.2, that last line would actually load all of the people in that collection, before creating the new person. This was problematic if the collection had thousands of rows, because a simple insert suddenly became a monstrous resource sink.

So, how to verify that the collection is no longer being loaded?

Did you know you can install your own logger instances in Rails? Yah, you can. And yah, it’s pretty cool:

1
2
3
4
5
6
7
8
9
10
11
12
13

$ script/console
>> ActiveRecord::Base.logger = Logger.new(STDOUT)
=> #<Logger:0x2814134 ...>
>> account = Account.find(:first)
  Account Load (0.000346)   SELECT * FROM accounts LIMIT 1
=> #<Account:0x2665478 ...>
>> account.people.create :name => "Jamis Buck"
  Account Columns (0.000271)   SHOW FIELDS FROM accounts
  Person Columns (0.000246)   SHOW FIELDS FROM people
  SQL (0.000093)   BEGIN
  SQL (0.000351)   INSERT INTO people (`account_id`, `name`) VALUES (1, 'Jamis Buck')
  SQL (0.253635)   COMMIT
=> #<Person:0x27cb628 ...>

There you have it. Each call to ActiveRecord now logs all of its activity to STDOUT (e.g., the console), via your custom logger instance. The tale it tells is revealing, and reassuring: scoped creates do not, in fact, load the entire collection anymore.

Yay!

(One caveat: be sure to set up your logger first, before doing anything else, otherwise the default logger will get cached with no simple way to uncache it.)