created_at、updated_atの実装コードを追ってalias_method_chainを理解する

RailsにはDBのカラム名に「created_at」「updated_at」を設定しておくだけで、作成日時と更新日時を自動記録してくれるという、お決まりの便利な機能がある。
最初に感動して、その後当り前のように使っていたのだが、その機能がどのように実装されているかを確認しようとして、以前は挫折してしまっていた...。(その当時は、数あるソースコードの中のどこに何があるかも分からなかったので、見当もつかなかった。)
で、前回の日記でその部分を見たときも、最初はやっぱり意味不明。Railsのコードは魔法のようで、理解するには時間がかかる。

active_record/timestamp.rb

  • 作成日時と更新日時を自動記録するメインのコードはここに書いてあるのだけど、これだけでは、いつのタイミングで、何故そうなるのかは理解出来なかった...。
#---------- /Library/Ruby/Gems/1.8/gems/activerecord-2.1.0/lib/active_record/timestamp.rb ----------

module ActiveRecord
  # Active Record automatically timestamps create and update operations if the table has fields
  # named created_at/created_on or updated_at/updated_on.
  #
  # Timestamping can be turned off by setting
  #   <tt>ActiveRecord::Base.record_timestamps = false</tt>
  #
  # Timestamps are in the local timezone by default but you can use UTC by setting
  #   <tt>ActiveRecord::Base.default_timezone = :utc</tt>
  module Timestamp
    def self.included(base) #:nodoc:
      base.alias_method_chain :create, :timestamps #<----------ポイント
      base.alias_method_chain :update, :timestamps #<----------ポイント

      base.class_inheritable_accessor :record_timestamps, :instance_writer => false
      base.record_timestamps = true
    end

    private
      def create_with_timestamps #:nodoc:
        if record_timestamps
          t = self.class.default_timezone == :utc ? Time.now.utc : Time.now #<----------UTCまたはローカル時間を設定
          write_attribute('created_at', t) if respond_to?(:created_at) && created_at.nil?
          write_attribute('created_on', t) if respond_to?(:created_on) && created_on.nil?

          write_attribute('updated_at', t) if respond_to?(:updated_at)
          write_attribute('updated_on', t) if respond_to?(:updated_on)
        end
        create_without_timestamps
      end

      def update_with_timestamps(*args) #:nodoc:
        if record_timestamps && (!partial_updates? || changed?)
          t = self.class.default_timezone == :utc ? Time.now.utc : Time.now #<----------UTCまたはローカル時間を設定
          write_attribute('updated_at', t) if respond_to?(:updated_at)
          write_attribute('updated_on', t) if respond_to?(:updated_on)
        end
        update_without_timestamps(*args)
      end
  end
end

alias_method_chain

理解のポイントはalias_method_chainにあった。

  • Timestampモジュールが ActiveRecord::Baseにincludeされた時に def self.included(base) が実行される。
    • baseにはActiveRecord::Baseが代入されている。
    • base.alias_method_chain :create, :timestampsは以下のコードと同等。
base.alias_method :create_without_timestamps, :create
base.alias_method :create, :create_with_timestamps
    • つまり、create_without_timestampsメソッドが呼び出されると、デフォルト定義のcreateメソッドを実行して、
    • createメソッドが呼び出されると、create_with_timestampsメソッドを実行しなさい、というエイリアス定義になる。
    • よって、レコードの新規作成でcreateが呼び出され、create_with_timestampsの定義内容が実行され、
    • その最後でcreate_without_timestampsが呼び出され、デフォルトのcreateが処理されることになったのだ。

このようにして、元のcreateメソッドには手を加えずに、作成日時の自動記録という機能を追加していたのだった。

  • どうりで、create_without_timestampsメソッド定義を一生懸命探したのだが、見つからないはずだ...。
  • Railsソースコードをちゃんと読むのは難しい...。

参考ページ

以下のページがたいへん参考になりました。感謝です!

残った疑問

  • before_createやbefore_updateを利用して実装しないのは、常にオーバーライドされる運命にあるメソッドだから?
    • オーバーライド先でsuperを書き忘れると、自動記録の機能が失われてしまうから?
before_save、before_create、before_updateとの関係
  • なぜか以下の順番で実行された。before_saveが先に実行されるのは何故だろう?
    1. before_save
    2. created_at、updated_atの更新
    3. before_create、before_update
    4. create、update
class Todo < ActiveRecord::Base
  before_create :test_before_create
  before_save :test_before_save
  before_update :test_before_update
  
  def test_before_create
    p '*'*40+"test_before_create"
    p created_at
    p updated_at
  end
  
  def test_before_save
    p '*'*40+"test_before_save"
    p created_at
    p updated_at
  end
  
  def test_before_update
    p '*'*40+"test_before_update"
    p created_at
    p updated_at
  end
end
Processing TodosController#new (for 127.0.0.1 at 2008-12-24 15:57:03) [GET]
  Parameters: {"action"=>"new", "controller"=>"todos"}
  User Load (0.000489)   SELECT * FROM "users" WHERE ("users"."id" = 1) LIMIT 1
Rendering template within layouts/application
Rendering todos/new
  Role Load (0.000360)   SELECT "roles".* FROM "roles" INNER JOIN permissions ON roles.id = permissions.role_id WHERE ("roles"."name" = 'administrator') AND (("permissions".user_id = 1)) LIMIT 1
Rendered layouts/_menu (0.01835)
Rendered layouts/_footer (0.00004)
Completed in 0.05413 (18 reqs/sec) | Rendering: 0.03315 (61%) | DB: 0.00085 (1%) | 200 OK [http://localhost/todos/new]
"****************************************test_before_save"
nil
nil
"****************************************test_before_create"
Wed, 24 Dec 2008 15:57:07 JST +09:00
Wed, 24 Dec 2008 15:57:07 JST +09:00


Processing TodosController#create (for 127.0.0.1 at 2008-12-24 15:57:07) [POST]
  Parameters: {"commit"=>"Create", "authenticity_token"=>"b0ef6117989828869fa27f36e6cee5c4993bb42e", "action"=>"create", "todo"=>{"due(1i)"=>"2008", "due(2i)"=>"12", "body"=>"", "due(3i)"=>"24", "done"=>"0"}, "controller"=>"todos"}
  User Load (0.000401)   SELECT * FROM "users" WHERE ("users"."id" = 1) LIMIT 1
  Todo Create (0.000435)   INSERT INTO "todos" ("updated_at", "body", "done", "due", "created_at") VALUES('2008-12-24 06:57:07', '', 'f', '2008-12-23 15:00:00', '2008-12-24 06:57:07')
Redirected to http://localhost:3000/todos/6
Completed in 0.03218 (31 reqs/sec) | DB: 0.00084 (2%) | 302 Found [http://localhost/todos]


Processing TodosController#show (for 127.0.0.1 at 2008-12-24 15:57:07) [GET]  Parameters: {"action"=>"show", "id"=>"6", "controller"=>"todos"}
  User Load (0.000407)   SELECT * FROM "users" WHERE ("users"."id" = 1) LIMIT 1
  Todo Load (0.000310)   SELECT * FROM "todos" WHERE ("todos"."id" = 6) 
Rendering template within layouts/application
Rendering todos/show
  Role Load (0.000346)   SELECT "roles".* FROM "roles" INNER JOIN permissions ON roles.id = permissions.role_id WHERE ("roles"."name" = 'administrator') AND (("permissions".user_id = 1)) LIMIT 1
Rendered layouts/_menu (0.01536)
Rendered layouts/_footer (0.00002)
Completed in 0.11861 (8 reqs/sec) | Rendering: 0.01873 (15%) | DB: 0.00106 (0%) | 200 OK [http://localhost/todos/6]


Processing TodosController#edit (for 127.0.0.1 at 2008-12-24 15:57:38) [GET]
  Parameters: {"action"=>"edit", "id"=>"6", "controller"=>"todos"}
  User Load (0.000597)   SELECT * FROM "users" WHERE ("users"."id" = 1) LIMIT 1
  Todo Load (0.000324)   SELECT * FROM "todos" WHERE ("todos"."id" = 6) 
Rendering template within layouts/application
Rendering todos/edit
  Role Load (0.000387)   SELECT "roles".* FROM "roles" INNER JOIN permissions ON roles.id = permissions.role_id WHERE ("roles"."name" = 'administrator') AND (("permissions".user_id = 1)) LIMIT 1
Rendered layouts/_menu (0.01613)
Rendered layouts/_footer (0.00002)
Completed in 0.04025 (24 reqs/sec) | Rendering: 0.02570 (63%) | DB: 0.00131 (3%) | 200 OK [http://localhost/todos/6/edit]
"****************************************test_before_save"
Wed, 24 Dec 2008 15:57:07 JST +09:00
Wed, 24 Dec 2008 15:57:07 JST +09:00
"****************************************test_before_update"
Wed, 24 Dec 2008 15:57:07 JST +09:00
Wed, 24 Dec 2008 15:57:44 JST +09:00


Processing TodosController#update (for 127.0.0.1 at 2008-12-24 15:57:44) [PUT]
  Parameters: {"commit"=>"Update", "authenticity_token"=>"b0ef6117989828869fa27f36e6cee5c4993bb42e", "_method"=>"put", "action"=>"update", "id"=>"6", "todo"=>{"due(1i)"=>"2008", "due(2i)"=>"12", "body"=>"edit", "due(3i)"=>"24", "done"=>"0", "due(4i)"=>"00", "due(5i)"=>"00"}, "controller"=>"todos"}
  User Load (0.000498)   SELECT * FROM "users" WHERE ("users"."id" = 1) LIMIT 1
  Todo Load (0.000290)   SELECT * FROM "todos" WHERE ("todos"."id" = 6) 
  Todo Update (0.000401)   UPDATE "todos" SET "body" = 'edit', "updated_at" = '2008-12-24 06:57:44' WHERE "id" = 6
Redirected to http://localhost:3000/todos/6
Completed in 0.03469 (28 reqs/sec) | DB: 0.00119 (3%) | 302 Found [http://localhost/todos/6]


Processing TodosController#show (for 127.0.0.1 at 2008-12-24 15:57:44) [GET]
  Parameters: {"action"=>"show", "id"=>"6", "controller"=>"todos"}
  User Load (0.003034)   SELECT * FROM "users" WHERE ("users"."id" = 1) LIMIT 1
  Todo Load (0.003362)   SELECT * FROM "todos" WHERE ("todos"."id" = 6) 
Rendering template within layouts/application
Rendering todos/show
  Role Load (0.000350)   SELECT "roles".* FROM "roles" INNER JOIN permissions ON roles.id = permissions.role_id WHERE ("roles"."name" = 'administrator') AND (("permissions".user_id = 1)) LIMIT 1
Rendered layouts/_menu (0.01850)
Rendered layouts/_footer (0.00002)
Completed in 0.06435 (15 reqs/sec) | Rendering: 0.03826 (59%) | DB: 0.00675 (10%) | 200 OK [http://localhost/todos/6]

やはり自分にとっては難解で、長くなりそうなのでここで力尽きる...。

  • before_saveだけは、created_at、updated_atの更新よりも前に実行されるという事実は分かったので、注意することにする。