読者です 読者をやめる 読者になる 読者になる

Rails 2.3.2でロックの挙動が変わっている

 Ruby on Rails 2.3.2がリリースされたので、さっそくインストールしました。自分の作っているアプリケーションでテストを実行してみると、2.3.1のときに出ていなかった"ActiveRecord::StaleObjectError: Attempted to delete a stale object"というエラーが出てきました。この ActiveRecord::StaleObjectError は lock_version を使ったロック機能によるものですが、いつもは更新時に起きるのに、今回はどうもレコードの削除時に起きているようです。また、エラーを出しているのはいずれもこのロックに加えて、関連先のモデルに対して counter_cache と":dependent => :destroy"による連鎖削除を指定しているモデルのようです。

 原因を調べるために、新しく以下のふたつのモデルを作りました。なお、環境は Mac OS X 10.5.6 と Ruby 1.8.7, データベースには SQLite を使っています。

  • app/models/user.rb
class User < ActiveRecord::Base
  has_many :blogs, :dependent => :destroy
end
  • app/models/blog.rb
class Blog < ActiveRecord::Base
  belongs_to :user, :counter_cache => true
end

 migration は以下のような定義です。

class CreateUsers < ActiveRecord::Migration
  def self.up
    create_table :users do |t|
      t.string :name
      t.integer :lock_version, :default => 0
      t.integer :blogs_count, :default => 0

      t.timestamps
    end
  end

  def self.down
    drop_table :users
  end
end

class CreateBlogs < ActiveRecord::Migration
  def self.up
    create_table :blogs do |t|
      t.references :user
      t.string :title

      t.timestamps
    end
  end

  def self.down
    drop_table :blogs
  end
end

 migration を実行した後、console でレコードを操作してみます。2.3.2だとこうなります。

mac:blog nabeta$ script/console
Loading development environment (Rails 2.3.2)
>> u = User.create(:name => 'nabeta') # Userを作成する
=> #<User id: 1, name: "nabeta", lock_version: 0, blogs_count: 0, created_at: "2009-03-16 15:09:40", updated_at: "2009-03-16 15:09:40">
>> u.blogs
=> []
>> u.blogs.create(:title => 'my blog') # Userに関連づけられたBlogを作成する
=> #<Blog id: 1, user_id: 1, title: "my blog", created_at: "2009-03-16 15:10:00", updated_at: "2009-03-16 15:10:00">
>> u
=> #<User id: 1, name: "nabeta", lock_version: 0, blogs_count: 0, created_at: "2009-03-16 15:09:40", updated_at: "2009-03-16 15:09:40">
>> u.reload
=> #<User id: 1, name: "nabeta", lock_version: 1, blogs_count: 1, created_at: "2009-03-16 15:09:40", updated_at: "2009-03-16 15:09:40">
>> u.destroy # Userを削除しようとする。以下のとおり失敗する
ActiveRecord::StaleObjectError: Attempted to delete a stale object
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/locking/optimistic.rb:127:in `destroy_without_callbacks'
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/callbacks.rb:337:in `destroy_without_transactions'
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/transactions.rb:229:in `send'
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/transactions.rb:229:in `with_transaction_returning_status'
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/connection_adapters/abstract/database_statements.rb:136:in `transaction'
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/transactions.rb:182:in `transaction'
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/transactions.rb:228:in `with_transaction_returning_status'
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/transactions.rb:192:in `destroy'
	from (irb):6
>> 

 User を削除しようとすると、問題の ActiveRecord::StaleObjectError が発生します。2.3.1だとこうなります。

mac:blog nabeta$ script/console
Loading development environment (Rails 2.3.1)
>> u = User.create(:name => 'nabeta') # Userを作成する
=> #<User id: 1, name: "nabeta", lock_version: 0, blogs_count: 0, created_at: "2009-03-16 15:21:23", updated_at: "2009-03-16 15:21:23">
>> u.blogs
=> []
>> u.blogs.create(:title => 'my blog') # Userに関連づけられたBlogを作成する
=> #<Blog id: 1, user_id: 1, title: "my blog", created_at: "2009-03-16 15:21:29", updated_at: "2009-03-16 15:21:29">
>> u
=> #<User id: 1, name: "nabeta", lock_version: 0, blogs_count: 0, created_at: "2009-03-16 15:21:23", updated_at: "2009-03-16 15:21:23">
>> u.reload
=> #<User id: 1, name: "nabeta", lock_version: 1, blogs_count: 1, created_at: "2009-03-16 15:21:23", updated_at: "2009-03-16 15:21:23">
>> u.destroy # Userを削除しようとする。以下のとおり成功する
=> #<User id: 1, name: "nabeta", lock_version: 1, blogs_count: 1, created_at: "2009-03-16 15:21:23", updated_at: "2009-03-16 15:21:23">
>> u.blogs
=> [#<Blog id: 1, user_id: 1, title: "my blog", created_at: "2009-03-16 15:21:29", updated_at: "2009-03-16 15:21:29">]
>> u.reload
ActiveRecord::RecordNotFound: Couldn't find User with ID=1
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.1/lib/active_record/base.rb:1595:in `find_one'
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.1/lib/active_record/base.rb:1578:in `find_from_ids'
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.1/lib/active_record/base.rb:616:in `find'
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.1/lib/active_record/base.rb:2695:in `reload_without_dirty'
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.1/lib/active_record/dirty.rb:94:in `reload_without_autosave_associations'
	from /opt/local/lib/ruby/gems/1.8/gems/activerecord-2.3.1/lib/active_record/autosave_association.rb:191:in `reload'
	from (irb):7
>> Blog.find(:all)
=> []
>> 

 User はエラーを起こさずに削除されています。

 もう少し2.3.2の動作やソースコードを調べてみると、最近 ActiveRecord でロックを扱っている部分に変更があったことがわかりました。また、上記の例では counter_cache と ":dependent => :destroy"による連鎖削除の両方を指定しているときに ActiveRecord::StaleObjectError が発生し、どちらか片方だけでは発生しないこともわかりました。