rails console 上で実行時間を計測する

Rails Tutorial 5日目。
現在第8章を勉強中。

知りたいこと

find_by と find_by_x ってどっちが速いの？

6.1.4 ユーザーオブジェクトを検索する 演習1

nameを使ってユーザーオブジェクトを検索してみてください。また、 find_by_nameメソッドが使えることも確認してみてください (古いRailsアプリケーションでは、古いタイプのfind_byをよく見かけることでしょう)。

find_by が古いタイプと言いながら、このあとの演習でも find_by がたくさん出てくるから、やっぱり古くないのではないか？？？(互換性があるから update されてないだけ？)

追記：@scivola さんがコメントで勘違いを指摘してくださいました。ありがとうございます！
古いタイプの find_by == find_by_x ということだったのか～！

やりたいこと

find_by と find_by_x ってどっちが速いのか実行時間を計測してみたい。

ほかに知らないこと

• 実行時間のはかり方 参考
• rails console 上の SQL 出力の消し方(じゃま…) 参考

関数定義

rails_console

def calc_find_by(count:, id:)
  # SQL の出力を抑える
  old_logger = ActiveRecord::Base.logger
  ActiveRecord::Base.logger = nil
  # Benchmark モジュールを使う
  Benchmark.bm 10 do |r|
    # find_by(id: id) を計測
    # 結果出力時のタイトル設定
    r.report "find_by" do
      count.times do
        User.find_by(id: id)
      end
    end

    # find_by_id(id) を計測
    r.report "find_by_id" do
      count.times do
        User.find_by_id(id)
      end
    end
  end
  # SQL 出力抑制を元に戻す
  ActiveRecord::Base.logger = old_logger
end

実行結果

id : 3 は nil。

10000回

>> calc_find_by count:10000, id: 3
                 user     system      total        real
find_by      0.956429   0.092523   1.048952 (  1.050382)
find_by_id   0.957591   0.100028   1.057619 (  1.059075)

100000回

>> calc_find_by count:100000, id: 3
                 user     system      total        real
find_by      9.854176   0.629422  10.483598 ( 10.498670)
find_by_id   9.824362   0.667503  10.491865 ( 10.506455)

id : 2 は nil ではない。

10000回

>> calc_find_by count:10000, id: 2
                 user     system      total        real
find_by      1.278680   0.063538   1.342218 (  1.344218)
find_by_id   1.267526   0.059938   1.327464 (  1.328699)

100000回

>> calc_find_by count:100000, id: 2
                 user     system      total        real
find_by     12.492160   0.747277  13.239437 ( 13.251859)
find_by_id  12.435650   0.863175  13.298825 ( 13.311519)

そこまで大きく差が出るほど早さに影響しているわけではなさそう。
↓の通り、SQL 文は一緒だもんね。

>> User.find_by(id: 3)
  User Load (0.2ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?  [["id", 3], ["LIMIT", 1]]
=> nil
>> User.find_by_id(3)
  User Load (0.1ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?  [["id", 3], ["LIMIT", 1]]
=> nil