何が起きたか
rspecのテストケースが増えてきたある日、下記のようなdbコネクションに失敗する事象が発生するようになった。
毎回発生するわけではなく、エラーになるテストも毎回異なるという謎挙動。。。
ActiveRecord::StatementInvalid
(Mysql2::Error::ConnectionError: Lost connection to MySQL server during query: BEGIN):
railsなどのバージョンは下記
# rails -v
Rails 5.2.2.1
# ruby -v
ruby 2.5.3
最初に結論
active storageを使った機能のテストがエラーの原因だった。
active storageでファイルを追加するとファイルを分析する処理が非同期で動いており、DBコネクションを取り合ったりロックしたりしてエラーが発生していた。
調査
エラー箇所特定
エラーになるテストケースと直近で触った機能を洗い出したところ、active storageを使った箇所が怪しいことが判明。
active storageを使っている箇所を中心に調査開始。
active storageを使った処理のログを眺めているとファイルをアップロードしたときに非同期で処理が動いている痕跡があった。
そこでソースをみたところ、アップロードしたファイルを解析する処理が非同期で動いていることが判明。
該当箇所は下記。
https://github.com/rails/rails/blob/b2eb1d1c55a59fee1e6c4cba7030d8ceb524267c/activestorage/app/models/active_storage/blob/analyzable.rb#L37
非同期を解消するには
非同期を解消するにはactive_job.queue_adapterを:inlineに変更すればOK。
こうするとactive jobも同期処理として実行される。
config.active_job.queue_adapter = :inline
同期処理になったが、、、
DBコネクションエラーは発生しなくなったが、次は下記のエラーが発生するようになった。
MiniMagick::Error:
You must have ImageMagick or GraphicsMagick installed
これはテスト環境だけImageMagickが入っていなかったために発生していた。
今まで非同期だったのでrspecはエラーにならず気づけていなかった・・・
最終的にどうしたか
ImageMagickをテスト環境に入れるだけでエラーは解決できるが、最終的にはactive jobの実行メソッド(perform_later)を一律スタブにすることにした。
RSpec.configure do |config|
・・・
config.before(:each) do
allow(ActiveJob::Base).to receive(:perform_later).and_return(true)
end
end
このように対応した理由は、今回問題となった非同期処理は実行されなくてもテストに影響がないためスタブでも問題ないと判断したため。スタブにすることでテスト時間の短縮にもつながる。
また、自前のジョブを呼び出す機能をテストするときはジョブを呼び出すところまでをテストして、ジョブは別途テストを書くことで対応する。