失敗事例の共有。テストが実行できていないのにCI/CDが通ってリリースしてしまった話

はじめまして
アクトインディでWebエンジニア職として採用されて4ヶ月目。
つい最近試用期間が終了して、正式に正社員になったばかりの s4na です。

今回は私の失敗事例を共有させていただきます。

はじまりはリリース後のふとした違和感でした。

最初にその違和感に気づいたのは、チームのメンバーでした。
（本当に感謝しております 🙏 ）

f:id:s4na:20200910133907p:plain

f:id:s4na:20200910134118p:plain

たしかに、テストのカバレッジが50%以上も落ちてしまっていました。

・・・私のリリースから。

何かやってしまったみたいです 😢

リリース時のCIのログを見てみると、テストでActive Modelのロードに失敗していました。

An error occurred while loading ./spec/controllers/xxx/xxx/xxx_controller_spec.rb.
Failure/Error: ActiveRecord::Migration.maintain_test_schema!

ActiveRecord::PendingMigrationError:


  Migrations are pending. To resolve this issue, run:

マイグレーションに失敗しているみたいです。

でも、なぜか、本番データベースでのマイグレーションは成功している

本番のデータベースを見てもマイグレーションに成功している。
データの中身を見てみても、カラムは追加されている

どういうことだ？？？ 🤔

原因判明！！

トラブルなことを聞きつけて、チームメンバーと一緒に通話しながらPRを調査していると、スキーマ定義の日時がおかしいことが判明しました。
（一緒に調べてくださったメンバーに感謝 🙏 ）

今回私がリリースする前に、コンフリクトが発生したのですが、その際に古い日時（自分が作成した日時）を優先してしまっていました。そして、そのあとステージングで検証していませんでした。
ステージングで検証していたと思っていたのですが、やったと思っていたのはコンフリクト解消する前だったみたいです・・・

なぜ古い日時（自分が作成した日時）を設定するとテストが実行されなかったのか

マイグレーションファイルとスキーマ定義の日時がずれていると、テストが失敗するためです。

RailsのActiveRecordではDBの状態を管理するために、マイグレーションという仕組みを導入しています。
マイグレーションでは3つの日時を管理しています。

それぞれのマイグレーションファイルの作成日時
スキーマの日時 👈 ここが今回おかしかったところです。
データベース内に取り込んだマイグレーションファイルの作成日時

マイグレーションファイルではどこまでの変更を取り込めば良いかというのを「2.スキーマの日時」で管理しています。
今回そこが一番新しい日時になっていなかったので、不整合となり一部のテストが実行されていませんでした。

詳しくは 👉 Railsガイド Active Record マイグレーション

ではなぜCI/CDが落ちて止まらなかったのか？

まだ再現できていないので未確定なのですが、テストがエラーで落ちなかった原因は、テストを実行する処理内でマイグレーション時のエラーの考慮が漏れていたからだと思われます。

アクトインディではテストの実行を分散処理のライブラリをカスタムして使っていて、その中で「1. テストに向けて準備、2. テストの分散実行、3. サマリーの表示」を行っています。

通常、「1. テストに向けての準備」で失敗するとエラー終了します。
しかしマイグレーションのズレを検知するのは「2. テストの分散実行」内で spec_helper.rb の ActiveRecord::Migration.maintain_test_schema! をロードしたタイミングになっていました。
ここで失敗すると、そのまま「3. サマリー表示」がされてしまい、正常終了していたようです。