migration時にreset_column_informationを実行するとdb:seedしたときにNoMethodErrorが発生する

TL;DR:

RAILS_ENV=test rails db:migrate:reset db:seed実行したときにreset_column_informationがあると意図しないDBスキーマがRailsによってキャッシュがされてしまい、NoMethodErrorが発生した。

現象:

RAILS_ENV=test rails db:migrate:reset自体は成功しており、DBには期待したテーブル構成が構築されていることを確認できた。
ところがそのあとに実行されるdb:seedが期待した挙動にならずエラーが発生する。

RAILS_ENV=test rails db:migrate:resetとRAILS_ENV=test rails db:seedを別々に実行すると成功するという謎挙動に遭遇した。

原因:

まだ具体的にどこのコードが影響してそうなったのか？がわかっていないのだが少なくとも原因の主な理由は reset_column_information にあることが判明した。

発生する条件としては↓のような状態となる。

• rails db:migrate:reset db:seedをワンライナーで実行する
• マイグレーションファイル内でreset_column_informationを実行している
• RAILS_ENVがtest
  • developmentだと発生しない、理由は後述する

再現:

↓な感じのマイグレーションファイルを用意する。

class RenameCancelledToStatus < ActiveRecord::Migration[5.1]
  def up
    rename_column :model, :cancelled, :ok

    Model.reset_column_information
    Model.find_each do |model|
      model.ok = !model.ok
      model.save!
    end
  end
  
  def down
    rename_column :model, :ok, :cancelled

    Model.reset_column_information
    Model.find_each do |model|
      model.cancelled = !model.cancelled
      model.save!
    end
  end
end

内容としてはイケてないカラムcancelledさんをokさんにリネームするというもの。
(カラム名に対して突っ込んではいけない、わかりやすくするためにあえて名付けているのだ。)

Modelのカラムをリネームしているのでそのままだとリネーム前のカラムを参照してしまうのでreset_column_informationでモデルデータを読み込み直している。

一見？問題なさそうに見える。
実際RAILS_ENV=development rails db:migrate:reset db:seedしたところ、正常に完了する。
DBに入っている値もきちんと反転した状態で入っていたので意図した値が登録されているため、問題ないと思っていた、このときまでは。

CIサーバーからFailの通知が来た

一応手元の環境で確認が出来たのでgit pushをしてCIを回したところテストがFailしたという通知が届いた。
CIをチェックするとDBの初期化、つまりRAILS_ENV=test rails db:migrate:reset db:seedでNoMethodErrorが発生して失敗をしている。

何故 db:seed でエラーになる？とこの時点でかなり頭を抱えそうだなと感じていたがだいたいこの手の嫌な予感は外れない法則が的中した。

エラーメッセージをみると NoMethodError: undefined method 'ok=' が発生しており、現象としてはdb:seedを実行してmodel.okというカラムにデータを突っ込もうとしたらエラーという状況になっているということまではわかった。
はて？migration時にはエラーにならないのに何故 db:seed でエラーになるのか？がよくわからなくて途方に暮れた。

ちなみに当初 'ok=' というメソッドでエラーになってしまっているので何かしらのタイポをしたのだと思っていた。

とりあえずいろいろ調査する

ちょっと原因の想定がつかないな…と思いながらもまずは手元の環境でログを出して調べようとrails db:migrate:reset db:seedを実行する→何故か完了するという現象に遭遇してしまう。
(このとき手元の環境はRAILS_ENV=developmentだった)

この時点で完全に謎の迷宮に放り込まれたが、StackOverflowやGithubのissueなどをみたり、いろいろ手元で試した結果「これはそもそもRailsがModelを起動時にキャッシュしているのでは？」という仮説が浮かび上がった。

その後同僚が協力して調べてくれた内容を共有してくれて恐らくキャッシュのせいだろうと結論づけた。

解決方法:

Railsのキャッシュ周りがどうなっているのか？を調べる時間的余裕がこのときあまりなかった。
そのうえでどう解決するかを考えたところ、そもそも RAILS_ENV=test rails db:migrate:reset db:seed を行うときにだけ発生するのでとりあえずCIでワンライナーで実行しているところを分割するという対策にしようということになった。

本来はきちんと解決すべき問題なのかもしれないがそもそもの影響範囲がテストのときだけ(開発環境はRAILS_ENV=developmentなので影響がない)ということで少なくともいまのところ問題にはなっていない。

まとめ:

今回の想定外だった箇所としては2つあると考えている。

• rails db:migrate:reset db:seedがrails db:migrate:reset && rails db:seed と等価だと思っていたこと。
  • 実際にはキャッシュの生成タイミングなどに微妙な差異があった。
• db:seed実行時に最新のモデルが読み込まれていると思い込んでいたこと
  • ワンライナーで実行したときにもdb:migrate:reset後にリロードされると思っていたが実際にはそうでなかった
    • 今にして思えばリロードしてしまうのはコストが高い気がするので仕方ないように思う。

ということで根本的な解決ではないが対処方法としてはまあまあ妥当でかつ簡単に対応出来た点は良かったかもしれない。

恐らくもっと正しい対処方法があると思うので知ってる方がいたら教えてください。