flaky test の調査のためにテスト中で使う変数でもログに出すようにする

というのを最近試みている。

これまで遭遇してきた flaky test の多くは比較的単純な原因だった。コードを少し眺めたり、乱数が原因で落ちたテストのシード値を指定するだけで再現できることが多かったため、あまり困っていなかった。

しかし、最近遭遇したテストは、並行で実行されるテストで作られるデータと競合していたため、調査が難航していた。 周辺コードや既存のログを読んでも原因が全く分からなかったため、テストの前後で変数をダンプするログを追加して、しばらく CI の様子を観察していた。 すると、調査が一気に進み、flaky test の修正も可能になりました。

この件から、普通のアプリケーションの不具合調査の際と同じように、情報を増やすためにログを仕込むテクニックが flaly test の修正でも有効であることを認識してきた。 特に、テスト実行中だとデバッガもないので、変数の中身が出るくらいで情報は大幅に増えることがわかった。

違う話題だと、世の中には flaky test の実際の修正方法についてはあまり言及されていなさそうと思って調べてみたら、以下のブログを見つけた。 Railsプロジェクト以外でも共通するパターンがまとめられており、参考になりそう。

note.com

エスパー力を発揮したり怪しいところにログを仕込むなどして見つけるしかないこともあります。

やっていきましょう。