長時間ランニングテストの勧め 〜開発用ノートPCの活用〜

Merpay Advent Calendar 2020 の15日目は、メルペイスマート払いの開発を担当しているCredit Designチーム/Backend Engineer の 柴田 がお届けします。

はじめに

私が1984年に社会人になった頃は、ソフトウェア開発を行うためには会社に行くしかありませんでした。当時は、共用のVAXマシンで4.2/4.3 BSD Unixを使って開発していました。その後は、コンピュータハードウェアの発達に伴い、開発者ごとにワークステーションを用いて開発するようになり、デスクトップPCを用いた開発、そして今日のMacBook ProといったノートPCによる開発と時代が変わってきています。

2000年代には、安価で高性能なコンピュータの恩恵により、テスト駆動開発が徐々に広まってきました。そして、継続的インテグレーション（Continuous Integration）もオンプレミスのサーバでの実行から、Circle CIといったクラウドサービスを使う時代と変わってきています。さらに、開発された自動テストはCIの一部として、クラウドで実行されます。

このような技術の変遷に逆行しているように思えるかもしれませんが、今回は手元の開発用ノートPC（私の場合は、MacBook Pro）での長時間ランニングテストを行うことについて話します。

過去の経験

最初に、長時間ランニングテストに関する私自身の過去の経験について話します。

2003年から始まったある組み込みシステムの開発では、C++言語でマルチスレッドプログラミングを行っていました。ハードウェアを制御する組み込みシステムでしたが、完全なテスト駆動開発を目指して、開発者のデスクトップPCでほとんどの開発が完結できるようになっていました。

すべてのテストコードを実行すると、当時のデスクトップPCで2時間以上を要していました。テストコードを実行していると開発できないので、当時の私の開発部門では、すべてのエンジニアに2台のデスクトップPCを配布していました。1台でテストコードを実行しながら、もう1台で開発を続けるためです。

さらに、マルチスレッドプログラミングを駆使するようなシステムでは、テストコードが1回合格したからといって、作成されたソフトウェアが正しいことの保証にはなりません。そのため、さまざまな性能のコンピュータを使い、さらにスレッドのスケジューリングに影響を与えるようなシステム負荷をかけながら、テストコードを繰り返し実行する必要があります。

夜間・週末の実行

テストコードは、各人のデスクトップPCだけではなく、マルチプロセッサーのサーバやCI用のサーバで実行されていました。それに加えて、開発者全員のデスクトップPCを活用して、夜間および週末も繰り返しテストコードを実行していました。

何十台もある開発者のデスクトップPCを夜間遊ばせる（つまり、電源オフにして帰宅する）というのはもったいないのと、完全なテスト駆動開発であったため、私を含めて開発者全員が夜間と週末は繰り返しテストコードを実行する設定で帰宅するようにしていました。

デバッグは最優先業務

朝、出社して、自分のデスクトップPCでテストが停止していたら、そのデスクトップPCの所有者である開発者が最優先業務として調査することが求められていました。マルチスレッドプログラミングの場合、停止している状態で徹底的に調査する必要があります。なぜなら、再び実行しても、再現する保証は全くないからです。

ある朝出社したら私のデスクトップPCでテストが停止していました。最初は一人でデバッグしていたのですが、何が発生したのか原因を突き止めるのが難しく、若手のエンジニアにも手伝ってもらいながら2人で2時間ほどデバッグしました。原因は分かったのですが、ソースコードを慎重にレビューしてもおそらく見つけられなかったであろう難しいバグでした。さらに、原因となったソースコードの修正が行われたのが3か月前でした。つまり、毎日何十台というデスクトップPCで実行されたにも関わらず、3か月間に一度も発生しなかった不具合でした。

このプロジェクトでは、朝出社して全員のデスクトップPCでテストコードが動き続けていたのは、まれでした。必ず誰かのデスクトップPCでテストコードが停止していました。

Go言語での経験

2013年5月からほぼ2年間、私が率いたGo言語による組み込みシステムの開発プロジェクトでも同じように開発を行いました。Go言語の場合、ゴルーチンのスケジューリングに影響を与えるようにいくつかのパラメータを設定し、それらのパラメータを組み合わせて実行していました。組み合わせたパラメータは、以下の通りです。

• GOMAXPROCS : 1から256までいくつかの値を選んで設定
• -race : 競合検出器（race detector）を有効・無効に設定
• カバレッジ : カバレッジ測定を有効・無効に設定

これらは、ゴルーチンのスケジューリングに影響を与えるので、組み合わせて実行するスクリプトを作成して、すべてのテストコードを夜間や週末にデスクトップPCで実行していました。

Go言語でチャネルとゴルーチンを駆使したソフトウェア開発でしたが、複雑なシステムの制御という点では、前述の2003年から行ったプロジェクトと同じで、デッドロックやデータ競合（Data Race）も多く経験しました。幸いなことに、Go言語では競合検出器が提供されているおかげで、テストコードを10数台のデスクトップPCで夜間・週末実行することで、データ競合を容易に発見し解決できていました。

デスクトップPCからMacBook Proへ

デスクトップPCは、その名前の通りオフィスの机の上で使い、移動させることはないです（ただし、盗難防止のための対策は行っていました）。しかし、今日では、MacBook Proを使った開発を行っている企業が多くなっています。デスクトップタイプのiMacと異なり、退社時にMacBook Proを袖机に入れて鍵をかけることが多いのではないかと思います。そうなると、せっかくの高性能なMacBook Proを夜は遊ばせることになります。

そのような状況が変わったのが、コロナ禍の在宅勤務（Work From Home）です。会社のMacBook Proを自宅に持ち帰り、開発を行います。私自身は、往復約4時間弱の通勤から解放されて、9か月以上在宅勤務しています。

自宅であれば、MacBook Proを夜中に遊ばせることなく、テストコードを実行できます。もちろん、各人の事情もあるでしょうから、仕事をしていないときに、MacBook Proを動作させることはできない場合もあると思います。

長時間ランニングテスト

今年7月に、現在所属しているマイクロサービスのチームへ異動しました。そこで取り組んだことの一つが、私が仕事をしていないときにMacBook Proを遊ばせることなく、そのマイクロサービスのテストコードを実行することでした。動作条件は、以下のように単純です。

• 会社へはVPNで接続
• データベースであるGoogle Cloud Spannerを使ってテストコードは実行される（つまり、ある程度クラウドサービスは使われる）

チームではCircle CIを使ったテストコードの実行は行われていますが、自宅で行う場合、以下の点が異なっています。

• ゴルーチンのスケジューリングに影響を与えるようにパラメータを組み合わせる
• Spannerへの遅延時間が異なる
• テストコードを実行しながら、システムに負荷かける

パラメータを組み合わせる

試行錯誤しながら、現在は以下のようなパラメータの組み合わせでテストコードを実行しています。

• GOMAXPROCSを8、16、32、64、96：使っているMacBook Proはデュアルコアですが、大きな値を指定することで、多くのカーネルスレッドが使われることにより、ゴルーチンのスケジューリングが変化します。
• -pオプションを2、4、8：並行してテストされるパッケージの数を指定します。
• -raceオプションを指定する/しない：競合状態を見つけるための指定ですが、ゴルーチンのスケジューリングにも影響を与えます
• TZをUTCかAsia/Tokyo：日本時間で正しく計算していない処理を見つけるために、タイムゾーンを指定します

さらに、テストが失敗するまで、全体を何度も繰り返すスクリプトと組み合わせることで連続実行を行うようにしています。

Spannerへの遅延時間

VPNで会社を経由してアクセスするので、Spannerへの遅延時間は、Circle CI上での実行よりも長くなります。その結果、テストが失敗する場合があります。失敗する理由としては、以下のようなものがあります。

• レコード内に記録されているタイムスタンプ（たとえば、作成時刻）の期待値とテストが期待している値が異なる。1秒の誤差を許容範囲としていたとしても、許容範囲が小さすぎて「ほぼ等しい時刻」と見なされない。この場合、許容範囲を大きくする必要があります。

• MacBook Proの時刻とSpannerサーバの時刻に差があると、「未来の時間を指定している」としてエラーになることもあり、その場合、MacBook Proの時刻を調整する必要があります。

負荷をかける

いつも行っているわけではありませんが、負荷をかけるケースとしては、以下の2つです。

• テストコードを実行しながら、開発以外の業務（たとえば、文書作成やオンラインでのミーティング）を同じMacBook Proで行う。
• テストコードを実行しながら、最新の開発版のGo言語一式をソースコードからビルドする。一時的にシステム全体にかなりの負荷がかかります。

テスト失敗時の対応

テストが失敗していた場合、次の対応となります。

1. ログをファイルに記録する（ファイル名は発生時刻に基づいて付ける）。スクリプトでは、どのパラメータで実行したのかも分かるようにログに出力しているので、その情報も一緒に記録します
2. どこで失敗したのかを調べる

自宅で長時間ランニングテストを始めた頃は、2.のステップは後回しにして、どのような失敗が多発するかを調べるために、テスト失敗のログを記録して、調査せずにテストの再開を行っていました。ある程度の数の失敗が溜まってきたら、発生頻度が最も高いものから調査して対応を行いました。最近は再現性が低い失敗が多くなっており、時間をかけてログやソースコードを調べるようにしています。

本来なら、調査をせずにテストを再開するというのは好ましくはないです。なぜなら、同じ問題がもう一度再現する保証はないからです。今回は、私が最初から開発に関わったマイクロサービスではないため、実装コードに不慣れなのと、どの程度安定しているかを知るために、当初はテスト失敗のログを記録して、テストを再開していました。

記録したログは、問題が解決しても保存しておきます。それにより、発生した失敗が新規なのか、過去にも発生していたのかを調べるのが容易になります。

また、私が使っている長時間ランニングテスト用のスクリプトは、担当しているマイクロサービスのリポジトリに入っており、誰でもローカルで実行できるようになっています。

いつ実行するのか

在宅勤務なので、次のようにテストコードを実行しています。

• 昼間は、食事や外出でMacBook Proを使っていないときや、開発以外の業務を行っているとき
• 就寝中
• 休日

4か月半の結果

7月から長時間ランニングテストを行って、11月中旬までの4か月半の間、15件の不具合を見つけて私自身で修正しています。その結果、テストコードは安定して動作するようになっています。

修正した不具合の原因を分類すると以下の通りです。

• テストコードで許容している時刻の差が小さい

  • コミットされた時刻などを比較する際、正確な時刻の比較はできないため、ある許容範囲内の誤差であれば期待した時刻と見なします。しかし、その許容範囲が小さすぎる場合です。

• テストコードで作成しているテーブルのレコードの作成時刻に差が出ないことがある

  • テストコードで複数のレコードを作成するのですが、その中に設定するある種の時刻が、単純にtime.Now()を都度呼び出して設定してもまれに同じ時刻になってしまうことがある。

• テストコード間でのデータベースアクセスの排他処理が正しくない

  • 必要に応じて他のテストを待たせるために、データベースアクセスの排他処理を行う機構を用意しています。しかし、テストコードでその機構が正しく呼ばれていない。

• SpannerのトランザクションのAborted処理が正しくない

  • Read/Writeトランザクション内の処理でSpannerからAbortedが返される場合の処理が正しく書かれていない。SpannerはAbortedを返してリトライすることを要求してくることがあります。ただし、Spanner用のGo言語のライブラリがそのリトライの実行を自動で行なってくれます。自動的に処理がリトライされた場合に処理内容が正しくないと問題になります。

• ゴルーチンのスケジューリング次第で発生する

  • システムの負荷などの影響で、ゴルーチンのスケジューリング次第で発生する潜在的な不具合です。この種のバグは、簡単には再現テストが書けません。

最後の原因以外は、原因さえ分かってしまえば、容易に修正できます。やっかいなのは、最後の原因です。調査して仮説を立て、立てた仮説通りにゴルーチンがスケジューリングされれば問題が発生するはずだと分かっても、それを確かめる必要があります。

実行フロー制御ロガー

ゴルーチンのスケジューリング次第で発生する不具合を再現するために、ゴルーチンのスケジューリングをテストコード側から制御して、意図したタイミングで処理を実行させる「実行フロー制御ロガー」を作成しました。実行フロー制御ロガーの詳細は説明しませんが、NetBeansが提供しているライブラリを模倣したものです（詳しくは、『APIデザインの極意』の「11.3.8 ロギングを使用する実行フロー制御」を参照してください）。

まとめ

プロジェクトの共通サーバでテストコードが実行されて成功しているから問題ないと考えるのは間違いです。特定のサーバでは、動作条件がいつも同じようになりがちです。その結果、何度実行しても見つからない問題もあります。それを補うための方法の一つとして、開発者に支給されているMacBook Proでローカルに実行することには意味があります。

MacBook Proといっても、時期によっては性能（CPUのコア数や動作クロック、およびメモリ容量など）が異なっています。自宅からの場合、インターネット環境も異なっています。その差異が、さまざまな問題を発生させることに役立ちます。

テストコードが安定して動作しても、機能の追加や修正は日々行われているため、最新のバージョンに対して長時間ランニングテストを継続して行う必要があります。みなさんも、開発用マシンを自宅で遊ばせることなく、長時間ランニングテストを試みてはいかがでしょうか。

メルペイではミッション・バリューに共感できるバックエンドエンジニアを募集しています。一緒に働ける仲間をお待ちしております。

明日のMerpay Advent Calendar 2020 執筆担当は、 Android Engineer の @yhanada さんです。引き続きお楽しみください。