Exit Code 134 による自動テストの失敗を調査する
こんにちは。「家族アルバム みてね(以下、みてね)」でエンジニアをやっている sou といいます。
前回の記事では膝を壊した話をしましたが、その後に十日ほど走らない期間を作ったところ今ではだいぶ良くなり、走っても違和感程度でほとんど痛くなることはなくなりました。走るの楽しい。
さて、この記事ではみてねの Android アプリ開発において CI による自動テストで発生していた問題とその対策について紹介します。
みてねの Android アプリにおける自動テストの構成とその特徴
どういった問題が起きたのかを説明するためまずはみてねの Android アプリにおける CI について簡単に紹介をしたいと思います。
みてねの Android アプリでは CI に GitHub Actions を使っています。また、マルチモジュール構成を取っていますが、まだ理想形にはなっておらず過渡期であるため、本体に相当する app に多くのソースコードが残っており、その関係で CI では自動テストを app とその他のマルチモジュール全てを分けたうえで、それぞれを並列なジョブとして実行しています。
app とそれ以外だと app の方が実行時間が長いです。つまり、 app の実行時間 = テスト全体の実行時間という状況でした。
そして、今回の問題が起きていたのはこのうちの app 側でした。
自動テストが適切に行われずに失敗してしまっているため本来検証したかったロジックが問題ないかが分からずリトライするしかありません。
AI によって開発サイクルが加速した今、本来は落ちるべきではないところで自動テストが落ちてしまいリトライを要求される状況は早期に解決すべき問題となっていました。
テスト失敗時に起きていたこと
発生していた事象は Gradle によって並列実行している Test Executer プロセスのうちいずれかが 134 を返し失敗してしまうというものでした。
実は 134 で特定のプロセスが落ちてしまうことは今回が初めてではなく、以前にも何度か修正をしたことがあります。
私がみてねで初めて目にした当時は CircleCI 環境であり、 CircleCI ではメトリクスが表示されるため、ヒープが枯渇し OOM が起きていることが自明でした。そのため JVM の設定を調整することで問題を解決しました[1]。
ですが、今回はヒープサイズについては十分な調整が行われており OOM が起きているとは考えづらい状況です。
もちろん前回の対応における調整が不十分だった可能性は考えられますが、前回 134 が出てからあまり時間が経っていないこともあり、前回の対応が適切だったのか検証も兼ねて詳しく調べてみることにしました。
調査にあたっての準備
さて、調査するためには何が起きたのかを正確に知る必要があります。
gradlew コマンドに stacktrace オプションを付けていたため GitHub のジョブから CI で落ちたステップを開けば 134 が出ていることは分かっていたのですが、それ以上の情報は出力されたクラッシュログを読まなければ分かりません。
ところが、後続ステップで設定されていた actions/upload-artifact で指定するパスに漏れがあり、今回のようなクラッシュが起きた場合のログがアップロードされない状態となっていました。
そこで早速 actions/upload-artifact のパスを修正し 134 が発生した場合に何が起きているのかを分かるようにしました。
- name: Upload artifacts
if: ${{ always() }}
uses: actions/upload-artifact@v6
with:
name: test-app-reports
path: |
app/build/reports
+ build/reports/problems
+ **/hs_err_pid*.log
retention-days: 7
クラッシュログの確認
hs_err_pid*.log にはクラッシュログが出力されています。
これは JVM に関する致命的なエラーが発生した際の情報をまとめたログファイルとなっています。
ログファイルでは以下のような様々な情報が記載されています。
- エラー内容
- JDK / JRE / JVM などの情報
- 起動コマンド
- マシンスペック
- 発生時刻
- 実行スレッドや実行タスク
- スタックトレース
実際に出力されたクラッシュログはこのような内容です。
#
# A fatal error has been detected by the Java Runtime Environment:
#
# SIGSEGV (0xb) at pc=0x00007f922c9f5000, pid=4930, tid=27777
#
# JRE version: OpenJDK Runtime Environment Temurin-17.0.18+8 (17.0.18+8) (build 17.0.18+8)
# Java VM: OpenJDK 64-Bit Server VM Temurin-17.0.18+8 (17.0.18+8, mixed mode, sharing, tiered, compressed oops, compressed class ptrs, g1 gc, linux-amd64)
# Problematic frame:
# V [libjvm.so+0xbf5000] Node::uncast(bool) const+0x0
#
# Core dump will be written. Default location: Core dumps may be processed with "/usr/lib/systemd/systemd-coredump %P %u %g %s %t 9223372036854775808 %h %d" (or dumping to /home/runner/work/Android/Android/app/core.4930)
#
# If you would like to submit a bug report, please visit:
# https://github.com/adoptium/adoptium-support/issues
#
--------------- S U M M A R Y ------------
Command Line: -Djava.awt.headless=true -Djava...
Host: AMD EPYC ...
Time: Fri Feb 13 09:54:19 2026 JST elapsed time: 303.701799 seconds (0d 0h 5m 3s)
--------------- T H R E A D ---------------
Current thread (0x00007f918c19e550): JavaThread "C2 CompilerThread2" daemon [_thread_in_native, id=27777, stack(0x00007f8f651ed000,0x00007f8f652ed000)]
Current CompileTask:
C2:303701 54497 4 android.database.sqlite.SQLiteProgram::<init> (20 bytes)
...
クラッシュログの冒頭にあるとおり SIGSEGV 、いわゆるセグフォが発生していることが分かりました。そして、他に共通していたのは Current Thread が JavaThread "C2 CompilerThread2" daemon となっていたことでした。これが関係していそうです。
C2 とはなにか
JVM では JIT による最適化のためのコンパイルが二段階の仕組みとなっていてそれぞれ C1, C2 と呼ばれています。
そして今回はこの C2 コンパイルをしようとした際に SEGV が起きクラッシュしたと読めます。
さて、ここで一つの疑問が浮かびます。なぜ Android アプリなのに JVM の話が出てくるのでしょうか。 Android アプリが動作する端末はリソースが限られているため、独自に最適化されたランタイムである ART を用意しており JVM ではありません。
ではなぜ JVM のクラッシュが起きていたかというと、ユニットテストでは実際に Android アプリを動かしているわけではないからです。
ユニットテストではロジックの妥当性を素早く検証することが目的となるため Android エミュレータを動かすといったようなことはせず、その代わりに JVM でコードを実行しています。
そして JVM では何度も呼び出されるコードについて JIT による最適化が働き、そこで SEGV が発生していたようでした。
どのような対策をするか
得られたクラッシュログから Room や SQLite 関連のコードを C2 コンパイルする際にクラッシュしている可能性が高いことが分かりました。ただ、サンプル数が少ないためこれら以外の他のコードでも同じ問題が発生する可能性があります。
また、クラッシュするのは決まって CI による自動テストがだいたい 10 分を過ぎたあたりで、一方で成功する場合も 13 分前後で終わっていることからクラッシュする可能性のあるコードの C2 コンパイルはテスト終盤になって行われる状態になると推測できます。
このことから、みてねでは自動テストにおいて C2 コンパイルを無効化する設定を追加してみることにしました。
もし C2 コンパイルが原因であればこれで解決するはずです。また、ユニットテストに関する JVM の設定変更はアプリになんらかの影響を及ぼすこともありません。
一方で、パフォーマンスに関しては懸念があります。
上述の通り C2 コンパイルでクラッシュが発生するコードの最適化は自動テストの終了間際でしたが、頻繁に呼び出されるコードについてはもっと早い段階で最適化されている可能性が高いです。が、 C2 コンパイルを無効化すると最適化によるメリットを比較的享受しやすいコードについても一律で C2 コンパイルがオフになるためです[2]。
C2 をオフにするのではなく特定のコードについてのみ JIT コンパイルの対象から外すことも可能ですが、もぐら叩きをしているとそれはそれで解決までに手間が掛かってしまいます。
そこで、まずは設定を有効にしてみて問題が解決するか、また、どの程度パフォーマンス上の影響があるのかを見てみることにしました。
C2 をオフにした場合の検証結果
修正は次のとおり、 TieredStopAtLevel を 1 にするだけです。これにより C2 コンパイルを無効化することができます。
tasks.withType<Test> {
...
+ jvmArgs("-XX:TieredStopAtLevel=1")
}
上記コードを追加し早速 CI を回してみたところ、クラッシュが再現しなくなることを確認しました。
一方でスタックトレースには以下のような警告が表示されるようになりました。
Warning: [51.713s][warning][codecache] CodeCache is full. Compiler has been disabled.
Warning: [51.713s][warning][codecache] Try increasing the code cache size using -XX:ReservedCodeCacheSize=
CodeCache: size=49152Kb used=48979Kb max_used=48979Kb free=172Kb
bounds [0x00007f50d0800000, 0x00007f50d3800000, 0x00007f50d3800000]
total_blobs=21169 nmethods=19494 adapters=1591
compilation: disabled (not enough contiguous free space left)
stopped_count=1, restarted_count=0
full_count=1
これは C2 コンパイルが制限されたことで本来は C2 へコンパイルされるべきメソッドが C1 へ留まってしまうことによる影響ではないかと推測しています。
そこで、こちらも設定を見直しました。
tasks.withType<Test> {
...
jvmArgs("-XX:TieredStopAtLevel=1")
+ jvmArgs("-XX:ReservedCodeCacheSize=128m")
}
また、パフォーマンスについては手元の環境で TieredStopAtLevel を追加することによってどの程度変わるか計測してみました。
$ ./gradlew :app:test --no-build-cache --rerun-tasks --continue
結果は次のとおりです。
| # | compile | time |
|---|---|---|
| 1 | C2 | 5:15 |
| 2 | C2 | 4:45 |
| 3 | C2 | 4:40 |
| 4 | C1 | 4:02 |
| 5 | C1 | 4:01 |
| 6 | C1 | 4:01 |
| 7 | C1 | 4:04 |
| 8 | C1 | 4:08 |
| 9 | C1 | 3:58 |
| 10 | C2 | 4:28 |
| 11 | C2 | 4:48 |
| 12 | C2 | 4:45 |
C2 コンパイルを使わずに C1 までにすることでパフォーマンスの劣化を懸念していましたが結果はむしろ逆でした。 5 回目を検証しているあたりでなんらかの最適化が働いた可能性を加味し、 7 ~ 12 回目では C1 / C2 の順序を逆にしてみましたがやはりコンパイルを C1 で止めてしまった方が速そうです。
これはおそらく C2 コンパイルがオンだとコンパイルによるオーバーヘッドが増す一方で実行時間が短いためにコンパイルによる恩恵を享受する前に処理が終了してしまうためではないかと推測しています。
もっとも、自動テストの量が増えコードベースが肥大化し実行時間が長くなればそれだけ C2 によるコストを回収できるため損益分岐点に近づき C2 の利点が活きそうです。が、少なくともみてねの現時点におけるソースコードでは C2 を使わないことによるデメリットは特になさそうでした。
CI 環境での検証
CI 環境では C2 をオフにする修正に加え、前回 OOM 対策として行っていた設定がやや過剰に守り気味の設定となっており、今回の調査の過程でメモリについてはまだだいぶ余裕があることが分かったので同時に調整を行いました。
そのため CI 環境では C2 単体での設定変更による評価はできていないのですが、一連の修正によって速度面で 13 分前後から 10 分前後まで速度面を改善でき、なにより自動テストが安定したため良しとしました。
ということでこれにて無事作業完了です。やったね (^o^)v
まとめ
今回はみてねで起きた CI での自動テスト実行時における突発的なエラーについて、調査から暫定的な解決までを紹介させていただきました。
なお、肝心の原因はというと正直分かりません。が、 C2 コンパイル時に SEGV が起きるという事象は過去にも報告されているようでした。
みてねの CI 環境はどうかというと Open JDK 17.0.18 であり上記に挙げられているバージョンではないのですが、 Open JDK 17.0.18 がリリースされたのは 2026/1/20 と最近で、みてねでこの問題が特に顕著になったのは二月の上旬であるため、もしかするとなんらかのバグを踏んでいる可能性はあるかもしれません[3]。
今回はあえてバージョンを変えずに C2 コンパイルをオフにするという対応をとりましたが、言語のバージョンアップはパフォーマンス面の改善やセキュリティパッチなど基本的には追従していくほうが無難なため今回のようなケースでバージョンを固定するかどうかは判断が難しいところですね。このあたりは判断が分かれるところかなと思います。
最後に感想ですが、 Android アプリを開発する上では JVM をそこまで気にすることはないため、調査の過程で JVM について色々と学ぶことができとても面白かったです。
もしも同様の問題に悩まされている方がいてこの記事がなんらかの参考になりましたら幸いです。
Discussion