はじめに
突然ですが、こんな奇妙な体験をしたことはありませんか？
ローカルでのテスト実行は全て通るけど、CIではテストが通らない。
CI環境とローカルでのテスト実施方法に違いがあると思いきや、そんなこともない(並列実行になっているなど)
ローカルで通っていると思えば、ローカルでうまくいかない人もいる。
実施する人全員が毎回同じテストで失敗するわけでなく、いろんなテストのうちいずれか一つだけが失敗する。
いかがでしょうか、これだけみるとただの怖い話です。
しかし、こういった事象にもきちんと理由があり解決する方法があります。
今回は、上記問題に直面して解決したよ！という話を記事にしてみました。
問題の詳細
テスト実行条件
- テストフレームワーク: XCTest
- テスト実行方法: 並列テスト
- 実行順: アルファベット順
問題の内容
テストスイートの中に、非同期処理を確認するテストケースをいくつか追加したPRにて、CIのテスト実行で失敗するようになりました。
しかし、CIで失敗したテストケースは、PRで追加したコードとは全く関係ないコードを検証するテストケースでした。
ローカルで再現確認をしようにも、ローカルでは問題なくテストが通ります。
ただ、ローカルでテスト実行してもCIと同じようにテストが失敗する開発者もいました。
さらに、ローカルで失敗する場合でも、CIとは別のテストケースが失敗することもありました。
この事象を再現するためのサンプルのテストスイートが以下のような感じです。
テスト実行時はSuccessTest.test_skelton_successのテストケースが失敗しています。
テスト失敗時のログには以下のように表示されていました。
"/Users/satoutaichi/work/swiftui/SwiftTestingSample/SwiftTestingSample/SwiftTestingSampleTests/FailTest.swift:15 - failed"
失敗しているテストはSuccessTestのテストケースなのに、なぜかFailTestが失敗原因のようなログが出ています。
変なことが起きていますね、、
原因
早速、今回の事象の原因をバラそうと思います。
ログの内容の通り、今回のケースでは実はFailTestが悪さをしていました。
このテストの中身を見てみましょう。
final class FailTest: XCTestCase {
func test_skelton_fail() {
DispatchQueue.main.async {
sleep(10)
XCTFail()
}
}
}
自分で書いておいてあれですが、かなりおかしなテストコードです。
ここで注目して欲しいのは、このテストは成功していることです。
なぜ成功していたのかというと、DispatchQueue.main.asyncのブロックは非同期処理であり、同期的テストケースを実行するとXCTFail()が呼ばれる前にFailTest.test_skelton_failがエラーが起きないまま終了しテスト成功とみなされるのです。
では、DispatchQueue.main.asyncの中の処理は呼ばれないのかというと、実はそういうわけでもなく非同期でしっかり動いています。
しかしXCTFail()が呼ばれる頃にはFailTest.test_skelton_failはとうに終了してしまっています。
今回SuccessTest.test_skelton_successが失敗してしまったのは、このテストケース実行中にちょうどFailTest.test_skelton_failのXCTFail()が呼ばれたためでした。
そのため、SuccessTest.test_skelton_successが失敗したにもかかわらず、エラーログにはFailTestの言及がされたのです。
ちなみに、この事象を再現するために、SuccessTest.test_skelton_successは以下のように作っています。
sleepを入れてテスト実行時間を長めにとるようにして、FailTest.test_skelton_failのXCTFail()が呼ばれることを待つようにしています。
final class SuccessTest: XCTestCase {
func test_skelton_success() async throws {
try await Task.sleep(nanoseconds: 10000)
XCTAssertTrue(true)
}
}
上記共有した、原因のサンプルコードはかなりヘンテコなので、実際のテストコードでこんなことが起こるのかと思われるかもですが、起こります、、
結局今回の原因は、非同期処理の結果が返ってくるのを待たずに同期的にテストコードを実行し、あたかもテストが成功しているように見えていたが、実は失敗するテストコードだったというところです。
例えば、以下のようなコードも潜在的に今回の問題を起こし得ます。
func test_sample() {
HogeRepository.fetch { result in
switch result {
case .success(let success):
XCTAssertEqual(success, "hoge")
case .failure(let failure):
XCTFail()
}
}
}
HogeRepository.fetchが非同期処理だったとして、テストは同期的に実行しており、resultが帰ってくるまで待つようにテストコードが作られていないため、resultの検証をする前にテストは完了してしまいます。
もしこのテストが実は.failureに入ってしまいXCTFail()が呼ばれて失敗するようになっていれば、今回の問題と同様の事象が発生する可能性が高いです。
さらに、こういったテストは問題が顕在化するまでは成功してしまうので、問題が顕在化するかちゃんとテストコードを見ないと検知できないため、実は業務のテストコードでもこんなテストケースがある可能性は、割とあるんじゃないかなと思います。
解決方法
上記でも少し触れましたが、原因は非同期処理が完了することを待たずにテストが終了することなので、XCTestExpectationなどを使用して、非同期処理が完了するまで待つ処理を追加してやると解決します。
func test_sample() {
+ let expectation = XCTestExpectation()
+
HogeRepository.fetch { result in
switch result {
case .success(let success):
XCTAssertEqual(success, "hoge")
case .failure(let failure):
XCTFail()
}
+
+ expectation.fulfill()
}
+
+ wait(for: [expectation], timeout: 5)
}
なんで実行環境によって、テストが失敗したりしなかったりしたのか
これは実行するマシンのスペックが関係していると思われます。
今回の問題は、FailTest.test_skelton_failのようなテストが非同期で他のテスト実行中にXCTFail()を呼び出すことで起こります。
ですので、XCTFail()が呼び出される前に全てのテストを完了してしまえば、テストは成功します。
マシンのスペックが良ければ、テストを完了する時間も短くなるので、XCTFail()が呼ばれる前にテストが完了し、テスト成功扱いになるというわけです。
ただこれは、事象から考えた推測に過ぎません。(別でこんな理由があるんじゃ？と思われた方がいればぜひコメントしていただけると嬉しいです！)
おわりに
今回はいわゆるFlakyテストにまつわる問題の一例を解決する話でした。
皆さんの開発現場でも、似たような事象が起きていたりする場合は、今回の問題がもしかしたら絡んでいるかもなので、非同期処理がきちんと結果が出るまで待っているかなど確認してみてください。
どなたかの参考になれば幸いです！