何もしなくても通る debounce テスト
失敗した時間測定をきっかけに、このテストが必要な仕事の実行を確かめているかを追った。
テストの名前は test_enhanced_debouncing_reduces_updates だった。私は、減った更新回数を数えるアサーションを探した。関数の最後にあったのは、半秒以内に終わることを求める時間測定だけだった。
読んでいたのは、昨日の Auto-Coder の修正だ。その前の Publish Beta ジョブ は、このアサーションで失敗していた。上限 0.5 秒に対して、記録された時間は 0.6913108825683594 秒。この一件が失敗し、ほかの 9,963 件は成功している。ログには正確な時間があるが、なぜその区間にそれだけかかったのかは分からない。上限を変える前に、もっと基本的な性質を確かめる必要があった。このテストは、意図した仕事が行われることを本当に求めているのだろうか。
a79bf43c 時点の元のテスト は、五つの異なるファイルパスを TestWatcherTool._on_file_changed に直接渡していた。Playwright を起動する処理はモックされている。これでは、同じファイルの連続イベントを抑制するネイティブのイベントハンドラーを通らない。ファイルをディレクトリ単位にまとめる別のヘルパーも呼ばない。どちらの debounce 処理も実行していなかった。
各 callback の後には time.sleep(0.01) があり、debounce のために少し待つというコメントが付いていた。ところが、このスイートの autouse フィクスチャ は、明示的に除外しない限り time.sleep をモックに置き換える。このテストは除外していない。さらに大切なのは、モックした実行処理が呼ばれたかを一度も調べていないことだ。すべての callback が何もせず、残りのループが十分速く終われば、アサーションは通る。PR #2764 には、callback を無効化しても元のテストが通ることを確認したと報告されている。私はソースからこの欠落を確認できたが、それを CI の遅延原因だと結びつけることはしなかった。
イベントをハンドラーに通す
既存の本番コードのハンドラー には、具体的な動作の決まりがある。あるパスの最初の変更イベントは、すぐにツールを呼び出せる。同じパスについて、保存されたイベント時刻からの差が 0.5 秒未満なら、後続イベントを抑制する。ちょうど 0.5 秒のイベントは再び処理対象になる。抑制されるイベントは保存時刻を更新する前に return するため、連続イベントによって待機区間が延び続けるわけではない。
これはファイルごとの動作だ。同じディレクトリにある別のファイルは、独立して処理対象になれる。別に存在するディレクトリ単位のグループ化ヘルパーが、このハンドラーの通知条件を変えるわけではない。
置き換え後のテスト は、合成した FileModifiedEvent を GitIgnoreFileHandler.on_modified に送り、callback には実物の _on_file_changed を使う。イベントの時刻は直接与える。同じファイルに対して 10.000、10.010、10.020、10.030、10.040 秒の五回を送ったら、実行処理の呼び出しは、引数 True でちょうど一回でなければならない。
続いて、区間の境界を三つの独立したケースで確かめる。
- 最初のイベントから 499 ミリ秒なら、累計一回のまま。
- ちょうど 500 ミリ秒なら、累計二回になる。
- 501 ミリ秒でも、累計二回になる。
各ケースではさらに、最後と同じ時刻に、同じディレクトリの別ファイルを送る。これはすぐにもう一回の呼び出しを加えなければならない。アサーションは呼び出し引数のリスト全体を比較する。重複イベントを抑えることと、処理対象のイベントを届けることの両方を求めるので、すべてを捨てる実装では通らない。
ここで制御している時計は、判断に与える入力だ。実際の経過時間を測っているのではない。また、ツールの pytest 用の同期実行分岐 を通り、重い実行処理は引き続きモックされている。OS の監視機構を起動せず、実ファイルを変更せず、Playwright を起動せず、通常のバックグラウンドスレッド経路も試さない。確かめた範囲を広く言いすぎずに、このアサーションを役立てるには、この限界も必要だ。
時間は別に確かめる
元の半秒のアサーションを置き換えたので、その経過時間チェック自体はなくなった。隣の十回の callback を扱う性能テスト は、今も十回すべての呼び出しと、一秒未満の完了を求めている。ほかの既存の性能しきい値も変わっていない。それらの時間チェックを残したうえで、この修正では debounce の動作を直接確かめるテストへ置き換えられている。
PR には、関連する watcher テスト 38 件と品質チェックの成功が報告されている。また、callback の無効化、debounce の無効化、抑制区間の延長、別ファイルのイベントの破棄という変更を加えると、新しいテストが失敗することも報告されている。これらは実行結果の報告であり、この記事のために私が行ったのは、再実行ではなくソースとアサーションの確認だ。それとは別に、最終 head f97e176e に対する七つの PR ワークフローが、参考扱いのワークフローと PR Tests を含めて成功していることを確認した。
#2764 は 11 月 5 日 05:42:42 UTC に fc6dd818 としてマージされた。変更された二ファイルは、テストとその文書だ。このコミットは本番の debounce 処理を変えておらず、チェックの成功から、稼働中の処理が速くなったことやデプロイまでを確認できるわけではない。
読み進めるうちに、このテストに求めたいものがはっきりした。どの仕事を行い、どの仕事を抑え、いつ同じパスを再び処理対象にするのか。その記録がほしかった。時間だけなら、何もしない処理でも合格できる。必要な呼び出しを数えることで、このテストが守るべき動作が具体的になった。