【Rails】ActiveRecord::Base#reload（SQLキャッシュ）

Railsアプリケーション開発時に、少しハマったので、備忘録として残しておく。今回を通して、RailsのSQLキャッシュという機能があることを知った。また、その場合に、どのようにして再取得すべきかを学ぶことができた。

実行環境

Ruby : 3.0.1
Ruby on Rails : 6.1.3
Redis : 6.0.11
Sidekiq : 6.2.1

DBからデータが取得できていない？
SQLキャッシュとは
SQLキャッシュを使わず、再取得する
まとめ

DBからデータが取得できていない？

今回、Sidekiqで、DBのerrorsテーブルの任意のレコードを5秒ごとに取得して、finished_atカラムに値が入るまで待機させる処理を実装しようとしていた。

class HogeWorker
  include Sidekiq::Worker

  def perform()
    m_error = Error.create(message: 'test')
    wait_finishded(m_error.id)
    puts "process finished"
    # slackに終了を通知する
  end

  def wait_finishded(error_id)
    num = 1
    while true
      m_error = Error.find(error_id)
      if m_error.finished_at.present?
        break
      end
      sleep 5
      puts "wait, #{num * 5}s"
      num += 1
    end
  end
end

しかしながら、DBの値はすでに変わっているのに、ずっと条件が一致せずに、無限ループに入ってしまっていた。

ログを確認すると、以下のように出力されていた。（SQLの部分のみ抜粋）

DEBUG -- : Error Create (8.6ms)  INSERT INTO `errors` (`message`, `created_at`, `updated_at`) VALUES ('test', '2022-01-29 07:26:30.222125', '2022-01-29 07:26:30.222125')
DEBUG -- : Error Load (1.3ms)  SELECT `errors`.* FROM `errors` WHERE `errors`.`id` = 51 LIMIT 1
DEBUG -- : wait, 5s
DEBUG -- : CACHE Error Load (0.0ms)  SELECT `errors`.* FROM `errors` WHERE `errors`.`id` = 51 LIMIT 1
DEBUG -- : wait, 10s
DEBUG -- : CACHE Error Load (0.2ms)  SELECT `errors`.* FROM `errors` WHERE `errors`.`id` = 51 LIMIT 1

Error.find(error_id)で毎回取得しているつもりでいたが、初回の取得では、Error Loadとなっているが、2回目以降の取得では、CACHE Error Loadとなっており、DBにアクセスできていなかった。

SQLキャッシュとは

Railsがクエリの結果をキャッシュする
以前と同じクエリが発生すると、データベースへのクエリを実行せずに、キャッシュされた結果を返す
SQLキャッシュは、アクションの開始時に作成され、アクションの終了時に破棄されるので、アクションの実行中しか保持されない。
SQLキャッシュが実行されている場合は、ログの頭にCACHEがついている

そして、Sidekiq（5.1.0以降）でも、SQLキャッシュが有効になっていた。

NEW Enable ActiveRecord query cache within jobs by default [#3718, sobrinho] This will prevent duplicate SELECTS; cache is cleared upon any UPDATE/INSERT/DELETE. See the issue for how to bypass the cache or disable it completely.
Sidekiq Changes 5.1.0

SQLキャッシュを使わず、再取得する

ActiveRecord::Base#reloadを使うことで、SQLキャッシュを使わず、再取得することができることがわかった。

# File activerecord/lib/active_record/persistence.rb, line 800
def reload(options = nil)
  self.class.connection.clear_query_cache

  fresh_object =
    if options && options[:lock]
      self.class.unscoped { self.class.lock(options[:lock]).find(id) }
    else
      self.class.unscoped { self.class.find(id) }
    end

  @attributes = fresh_object.instance_variable_get(:@attributes)
  @new_record = false
  @previously_new_record = false
  self
end

https://github.com/rails/rails/blob/v6.1.3/activerecord/lib/active_record/persistence.rb)

self.class.connection.clear_query_cacheでSQLキャッシュを削除した上で、実行していることがわかった。

実際に、コードを一部以下のように変更して、再度実行してみた。

def wait_finishded(error_id)
  num = 1
  m_error = Error.find(error_id) # ActiveRecordインスタンスは初回のみ
  while true
    if m_error.reload.finished_at.present? # ActiveRecord::Base#reloadで再取得
      break
    end
    sleep 5
    puts "wait, #{num * 5}s"
    num += 1
  end
end

DEBUG -- : Error Create (7.6ms)  INSERT INTO `errors` (`message`, `created_at`, `updated_at`) VALUES ('test', '2022-01-29 08:02:39.098792', '2022-01-29 08:02:39.098792')
DEBUG -- : Error Load (1.9ms)  SELECT `errors`.* FROM `errors` WHERE `errors`.`id` = 52 LIMIT 1
DEBUG -- : Error Load (2.0ms)  SELECT `errors`.* FROM `errors` WHERE `errors`.`id` = 52 LIMIT 1
DEBUG -- : wait, 5s
DEBUG -- : Error Load (1.9ms)  SELECT `errors`.* FROM `errors` WHERE `errors`.`id` = 52 LIMIT 1
DEBUG -- : wait, 10s

きちんと毎回DBにアクセスして、データを取得できていることを確認することができた。