diff --git a/docs/adr/adr-044-subprocess-utility-extraction-boundary.md b/docs/adr/adr-044-subprocess-utility-extraction-boundary.md index 1ca12da5..ba80e6fa 100644 --- a/docs/adr/adr-044-subprocess-utility-extraction-boundary.md +++ b/docs/adr/adr-044-subprocess-utility-extraction-boundary.md @@ -128,6 +128,33 @@ T5 の由来は本 ADR にとって示唆的である: `run_cmd_shell_capped` **doc の契約だけでは守られず、正しい variant が存在しないと callsite は間違った variant を選ぶ**。 層 2 の「callsite が variant 名で intent 表明」は、選択肢が揃っていて初めて機能する。 +### 後続の判定 (2026-07-17: diff stage の timeout / T6) — variant を**追加しなかった**事例 + +push パイプライン改善 T6 (diff stage の timeout 欠落) で `cli-push-runner` の +`stages/diff.rs::run_diff_cmd` に timeout を導入した。T5 の直後に同 crate で +「shell + 全量 + timeout」が再び必要になったが、**lib への variant 追加は行わず callsite に +残置した**。T5 と逆の結論になったため、境界基準の適用例として記録する。 + +| 論点 | 判定 | 根拠 | +|---|---|---| +| T5 の `run_cmd_shell_unlimited` を使うか | ❌ 使わない | `run_cmd_shell_*` は **3 variant すべてが `combine_output` で stdout と stderr を結合する**。diff の stdout は reviewers が読むレビュー対象そのものとしてファイルに書かれるため、jj が stderr に出す警告 (並列 workspace 運用時の `Concurrent modification detected` 等) の混入は許容できない。variant 間の差は drain 戦略だけで、**結合するか否かは `run_cmd_shell_with` の骨格そのもの**であり variant では表現できない | +| 4 つ目の variant (`_unlimited_separated` 等) を lib に足すか | ❌ 足さない | 戻り値の型が `(bool, String)` から変わり `run_cmd_shell_with` の骨格に載らない = **既存 family への variant 追加ではなく別 family の新設**。層 1 の「1 crate でしか使われていない → extract せず、将来 2 つ目の使用例待ち」が素直に適用される。T5 が層 1 を適用しなかったのは「確立済み family への variant 追加で、代替は骨格の複製」だったためで、本件はその条件を満たさない | +| `bookmark_check::run_jj_bookmark_list` (同 crate に既存の「全量 + 分離 + timeout」) と共通化するか | ❌ しない | 層 1 の「signature が構造的に異なる (shell vs direct args)」に該当。`run_jj_bookmark_list` は direct args (`jj` を直接起動)、diff は config 由来の文字列を `cmd /c` で実行する。`run_cmd_direct` を各 crate に残置した既存判定と同型 | +| `wait_with_timeout_safe` / `_basic` のどちらを使うか | ✅ `_safe` | 層 2 の「Err 経路で kill するか / しないか」。diff は try_wait 失敗時に早期 return するため、child を残さない `_safe` を選ぶ | + +T6 は層 3 の再評価 trigger 3 (「新規 callsite が増えて variant 名の選択が機械的でなくなった」) +に**触れかけた**事例でもある。`run_cmd_shell_*` の variant 名 (`_capped` / `_capped_reporting` / +`_unlimited`) はすべて **drain 戦略**を表しており、「stdout と stderr を結合するか」という +直交する軸は名前に現れない。T6 の callsite はこの軸で family 全体を選べなかった。 +variant を増やす前に「その差異は既存の軸か、直交する新しい軸か」を確認すること — +直交する軸を variant 名に混ぜ始めると層 3 の naming 破綻に向かう。 + +なお T6 の実装過程で、`run_cmd_shell_*` 3 variant すべてに **timeout が wall-clock を縛れない** +欠陥があることが判明した (timeout 検知後に reader thread を join するが、`cmd /c` の孫プロセスが +pipe を保持するため join が孫の自然終了までブロックする。実測 9.23s / `timeout_secs = 1` 指定)。 +本 ADR の境界判定とは別軸の実装欠陥であり、対処は +`docs/push-pipeline-fix-plan.md` §6 backlog 10 に登録済み。 + ## 影響 ### 良い影響 diff --git a/docs/push-pipeline-fix-plan.md b/docs/push-pipeline-fix-plan.md index e5e898c0..76550e84 100644 --- a/docs/push-pipeline-fix-plan.md +++ b/docs/push-pipeline-fix-plan.md @@ -182,6 +182,71 @@ T1 を最優先とする理由: 以降の全 PR の dogfood push が速くなり 大 diff の書き出しを考慮して 60s 程度でも可。 - **テスト**: timeout 経路の unit test (長時間コマンドの fixture で Err になること)。 - **リスク**: 低。 +- **実施結果 (2026-07-17, 実装済み / PR 未採番 — 採番後に backfill)**: + - **timeout 値は 60s + `[diff] timeout` で上書き可 (ユーザー承認済み)**。方針が + 「jj 系 30s に合わせるが 60s 程度でも可」と両論併記だったため確認した。60s の根拠: + diff は working copy の snapshot + 大 diff の書き出しを伴い、読み取りのみの + `jj bookmark list` (30s) より重い。timeout の目的は**ハング検知**であって latency + 制限ではなく、誤 timeout は pipeline 全体の中断 (exit 5) を招くため余裕側に倒す。 + config 化は `[push] timeout` と同形 (`Option` + 既定値定数) で、誤 timeout する + 環境の escape hatch。本リポジトリの config は未指定 = 既定 60s。 + - **実装**: `run_diff_cmd` を `Command::output()` (無限待ち) から + spawn → `drain_pipe_unlimited` × 2 → `wait_with_timeout_safe` に載せ替えた。 + - **`run_cmd_shell_unlimited` (T5 で追加) は使えない**: `run_cmd_shell_*` は全 variant が + `combine_output` で stdout と stderr を結合するが、diff の stdout は reviewers が読む + レビュー対象そのものとしてファイルに書かれる。jj が stderr に出す警告 + (並列 workspace 運用時の `Concurrent modification detected` 等 = **まさに本タスクが + 想定する状況**) が混入するとレビュー対象を汚す。よって分離を維持した。 + - 同型の「全量 + 分離 + timeout」は `bookmark_check::run_jj_bookmark_list` にもあるが、 + そちらは direct args で signature が非互換のため共通化しない (**ADR-044 層 1** の + 「shell vs direct args は各 crate 残置」に該当)。判定は ADR-044 に追記した。 + - `wait_with_timeout_basic` でなく `_safe` を選んだのは、try_wait 失敗時に早期 return する + callsite で child を残さないため (ADR-044 層 2 の「Err 経路で kill するか」)。 + - **⚠ 初版実装の欠陥を回帰テストが検出した (本タスク最大の学び)**: 「timeout 後に + reader thread を join する」初版は、`[diff] timeout = 1s` に対し制御が戻るまで + **9.6s** 掛かった。原因は `cmd /c ` の構造で、`child.kill()` が殺すのは + cmd.exe だけで**孫 (実際の `jj`) は生き残る**。孫は pipe の書き込み端を継承したままなので + EOF が来ず、join が孫の自然終了までブロックする = **timeout が意味を成さない** + (T6 が直そうとしているハングの再生産)。よって失敗経路では thread を join せず + detach して即座に返す (push-runner は直後に exit 5 で終了するため thread は道連れ)。 + 出力は timeout 時に不要 (診断は timeout メッセージ自身が持つ)。 + **教訓**: timeout の回帰テストは「Err が返ること」だけでなく**経過時間を assert する** + こと。Err の内容だけ見る初版テストなら、この欠陥は素通りしていた。 + - **回帰テスト (ADR-049 の流儀)**: `mod t6_diff_timeout` に 7 本 + config 2 本 + (cli-push-runner 206 → **215 passed**)。由来 (コード監査。T5 と同じく in the wild の + 発火記録は無く「他 stage は全て timeout 付き = diff だけが穴」という非対称として特定) + を module doc に明記した。bad = 応答しないコマンドを timeout で打ち切り、かつ + **5s 以内に制御を返す**こと (上記欠陥を固定)、good = timeout 内に終わるコマンドを + 誤って打ち切らないこと。あわせて「stderr を diff に混ぜない」契約も seal した + (`run_cmd_shell_*` に載せ替えると落ちるテスト)。 + **修正前の挙動に対して失敗することを確認済み**: cli-push-runner のテスト全体が + 9.66s → **1.55s** に短縮 = timeout が実際に効いている証跡。 + - **サンドボックス実機検証 (before/after)**: 短いパス (`C:\t6\repo`、MAX_PATH 対策) に + jj repo を張り、`[diff] command` を `ping -t 127.0.0.1` (永久に応答し続ける = + 返らない `jj diff` の代役) に、他 stage を noop にして diff stage まで到達させ、 + `@-` のソースから build した修正前 exe と修正後 exe を比較した。 + + | | before (修正前 exe) | after (修正後) | + |---|---|---| + | 外側 kill 25s | `stage=diff elapsed=24.4s` / exit 124 (**自力で返らない**) | — | + | 外側 kill 10s | `stage=diff elapsed=9.4s` / exit 124 | — | + | 外側 kill なし | **無限ハング** (上記 2 点が実証) | `stage=diff elapsed=3.0s` / exit 5 | + | 診断 | なし (無言で停止) | `diff コマンドがタイムアウトしました (3s): ping -t 127.0.0.1` + jj lock 競合を疑う旨 | + + before は **diff stage の所要時間が外側 kill の時刻にそのまま追随**する + (25s→24.4s / 10s→9.4s) = **内部に上限が一切無い**ことの実証で、放置すれば + 無限に待つ。ユーザーは診断も無いまま手動 kill するしかない。 + あわせて (a) 実 `jj diff -r @` (既定 60s) が誤 timeout せず 0.1s で 28 行を書き出し + takt へ進むこと (good 側) も実機で確認した。 + **副次的実証**: before の run 後に `ping.exe` が残存していた — + 孫プロセスが cmd.exe の kill を生き延びる (= join がブロックする) ことの実機裏付け。 + - **発見 (本タスク外)**: `lib-subprocess` の `run_cmd_shell_*` **3 variant すべてが同じ穴**を + 持つ。timeout 後に reader thread を join するため、孫プロセスが pipe を保持していると + timeout が wall-clock を縛れない。実測: `run_cmd_shell_capped` に `timeout_secs = 1` を + 指定したテストが返るまで **9.23s** (既存テストは経過時間を assert しないため素通り)。 + 影響先は quality_gate (`step_timeout = 300`) と push (`timeout = 300`)、cli-merge-pipeline で、 + ハングした `cargo test` / `jj git push` に対して timeout が効かない可能性がある。 + §2 原則 4 (1 PR 1 変更) に従い本 PR では触れず、§6 backlog 10 に追加した。 ### T7: Stop hook file-length step の cwd 依存 (2026-07-16 に実際に発火した incident) @@ -668,6 +733,18 @@ T1 を最優先とする理由: 以降の全 PR の dogfood push が速くなり 返すが、同関数は exit code のみを見ているため post-PR の re-push が無言で失敗し得る。 出力取得は `run_cmd_direct` (unlimited) なので**判定の追加だけ**で済む (T5 と違い truncate 問題は無い)。規模 XS。 +10. `lib-subprocess` の `run_cmd_shell_*` 3 variant で **timeout が wall-clock を縛れない** + (T6 の実装中に発見、2026-07-17)。`run_cmd_shell_with` は timeout 検知後に reader thread を + join するが、`cmd /c ` の孫プロセス (実際の `cargo` / `jj`) は `child.kill()` の + 対象外で pipe の書き込み端を保持し続けるため EOF が来ず、join が**孫の自然終了まで + ブロック**する。実測: `run_cmd_shell_capped` に `timeout_secs = 1` を指定したテストが + 返るまで 9.23s (`ping -n 10` の自然終了待ち)。既存テストは経過時間を assert しないため + 素通りしている。影響: quality_gate (`step_timeout = 300`) と push (`timeout = 300`)、 + cli-merge-pipeline — ハングした `cargo test` / `jj git push` を timeout で打ち切れない。 + 対処案は T6 と同じ「失敗経路では join せず detach」だが、`_capped` 系は表示用出力を + 捨てることになるためトレードオフの判断が要る (T6 の diff は timeout 時に出力不要だった)。 + 孫まで殺す (`taskkill /T`) 案もある。規模 S。**テストには経過時間 assert を必ず入れること** + (無いと本件は再び素通りする)。 ## 7. スコープ外 (本計画では実施しない) @@ -704,3 +781,4 @@ T1 を最優先とする理由: 以降の全 PR の dogfood push が速くなり | T8 | 実装済 (PR #280) | 2026-07-17 | 「`@` 空 + bookmark が `@-`」を `NoBookmarks` から切り分け、`jj edit @-` を案内するよう修正。`working_copy_is_empty()` を advance と共有して規則の二重定義を解消。`main.rs` 側の重複案内も撤去。回帰テスト 12 本 + サンドボックス実機で before/after 比較 (§4 T8 実施結果)。**post-PR 修正 (CodeRabbit Major 2 件 + simplicity 警告 2 件を採用)**: (a) 判定順を反転し、bookmark が空の `@` にある場合も中断する — 続行すると `jj diff -r @` が空になり祖先の未 push 変更が AI レビューを経ずに push される (方針 2 を却下した理由と同じ穴が bookmark の位置違いで残っていた)。(b) `@-` 照会の失敗を `unwrap_or_default()` で「親はあるが bookmark 無し」に潰していたのを `ParentState::Unavailable` として保持し、親を確認できない場合は実行不能な `jj edit @-` を案内しない (T8 が直したはずの誤誘導の再生産だった)。あわせて simplicity-review の非ブロッキング警告 2 件も採用: (c) `query_parent_state()` の jj 失敗を log する (他の jj 失敗処理の慣習と揃える)。(d) `@-` に bookmark が無い場合は `jj edit @-` だけでは次に `NoBookmarks` で止まるため、bookmark 作成まで含めて案内する。Minor 1 件のうち日付指摘は CodeRabbit が UTC 基準のため不採用 (本 repo の記録は JST 基準で 2026-07-17 が正)。**dogfood 実証**: 本修正の push 作業中に、私自身が `jj new` で空コミットを作ってしまい T8 の incident 状態を再現したが、修正後の bookmark_check が破壊的な `jj bookmark create -r @` ではなく正しい `jj edit @-` を案内し、案内どおりの操作で復旧できた (修正が in the wild で機能することの実証)。**方針変更**: 方針 2 (`@-` を検査対象にして続行) は `[diff] command = "jj diff -r @"` により **takt レビューを無言 skip して push する**ことが判明したため不採用。方針 3 の「push すべき新変更がない」も再現記録の事実 4 (実際に push 成功 = 変更はあった) と矛盾するため不採用。exit 7 は維持し**案内文のみ正す**方針をユーザー承認のうえ採用した。**実施順**: T4-T7 を飛ばして T1 の次に実施 (T1 の dogfood push で再現が取れたタイミングを優先。T8 は他タスクと独立のため順序入替は無害) | | T5 | 実装済 (PR #282) | 2026-07-17 | push 拒否検知を 40 行 truncate 済み出力から**全量出力**に切替。`lib-subprocess` に `run_cmd_shell_unlimited` を追加 (`drain_pipe_unlimited` は pipe 単体、`_capped_reporting` は cap が残るためどちらも判定用には不足だった) し、3 variant の共通骨格を `run_cmd_shell_with` に集約。境界判定は ADR-044 §「後続の variant 追加」に記録。表示は成功時のみ `cap_for_log` で 40 行 + 超過明示に絞り、**失敗経路は全量表示** (診断情報を落とさない)。**副産物**: 唯一の呼び出し元が消えた `runner::run_stage_cmd` を削除 — dead code 除去に加え「capped 経路で control flow 判定する」罠の構造的排除。`MAX_LINES` は表示用として残置し doc に判定禁止を明記。**厳格化は不採用 (ユーザー承認済み)**: `contains` 誤爆の厳格化はリスクが非対称 (誤検知は出力表示で気付けるが、検知漏れは「リモート未反映のまま exit 0」= 本タスクが防ぐ事故そのもの) で ADR-043 (fail-closed) に反するため見送り、§6 backlog 8 を却下記録に変更。**回帰テスト**: `mod t5_truncated_refusal_detection` 6 本 + lib-subprocess 4 本。`run_push_cmd` を capped に戻すと 3 本が fail することを確認済み (回帰テストが素通りしないことの実証)。**サンドボックス実機で before/after 比較**: 拒否行を 41 行目に置いた fake push command で、before = `[push] 成功` + **exit 0 (silent failure 再現)** / after = 拒否検知 + exit 3。成功経路 (50 行) は 40 行 + `... (10 lines truncated)` 表示で exit 0 を維持。**発見 (本タスク外)**: `cli-pr-monitor` の `push_to_remote` は拒否検知が無く同型の穴 → §6 backlog 9 に追加 (1 PR 1 変更のため別 PR)。**post-PR 修正 (CodeRabbit Minor 1 件 + pre-push 非ブロッキング警告 2 件を採用)**: (a) `run_cmd_shell_capped` の doc「Err 経路で child を kill しない」は **pre-existing の stale 記述** (`kill_and_join_err` 導入 = PR #208 以降、実際は kill + reap + reader thread join している) だったため、child lifecycle の記述を 3 variant 共通の骨格 `run_cmd_shell_with` に集約し variant 側は参照のみにした。(b) `cap_for_log` の truncate 書式重複を `lib_subprocess::truncation_notice` として切り出し (実装は streaming vs materialize で共有できないが書式片は共有できる、という指摘は妥当)。(c) T5 行 / §4 の「本 PR」を PR #282 に backfill (T4 行が放置され本 PR で backfill する羽目になった負債を繰り返さないため)。**実施順**: 計画の推奨順どおり T4 の次に実施 | | T4 | 実装済 (PR #281) | 2026-07-17 | `push-runner-config.toml` の `refute_enabled = false → true` で dogfood 開始 (変更は方針どおり 1 行、templates は OFF 据え置き)。**dogfood 開始日を同 PR で固定**: ADR-039 bounded lifetime の起点が無いと 2 週間の期限が判定不能になるため、開始 2026-07-17 → **判定期限 2026-07-31** を ADR-047 (ステータス行 / Config opt-in / Bounded lifetime の 3 箇所) + config コメントに明記した。採否判定自体は本計画と独立に ADR-047 で進行する (§8 完了条件 4. の引き継ぎ先)。**初回 dogfood push で切替を実証** (PR #281 自身の push): 起動ログ `takt (pre-push-review-refute)` + takt の `ワークフロー 'pre-push-review-refute' を起動` → 完走を確認。合計 151s (pre_checks 1.3s / quality_gate 49.7s / diff 0.1s / takt 97.8s / push 2.2s)。**verify は予告どおり未発火**: reviewers 2 本とも APPROVE で `all("approved") → COMPLETE` に抜けたため `any("needs_fix") → verify` に入らず、verify 実動の観測は次の findings 発生 run に持ち越し (完了条件は「有効化が効いていることの確認」までで読む)。**副産物: 計測手順の誤りを発見・修正**。ADR-047 §dogfood 計測項目の `.takt/runs/*-pre-push-review-refute/trace.md` は **1 件もマッチしない** — run ディレクトリ名は workflow 名でなく task 名から作られ (`runSlug` = `-pre-push-review`)、refute run でも `20260716-182505-pre-push-review` になる (timestamp も UTC で JST の日付と 1 日ずれ得る)。放置すると 2026-07-31 の採否判定で run 0 件 →「データなし」誤読の恐れがあったため、ADR-047 と §5 T4 実施結果を `meta.json` の `piece` フィールド基準 (`grep -l '"piece": "pre-push-review-refute"' .takt/runs/*/meta.json`) に修正した。設計時の計測手順が実運用開始まで未検証だった例。有効化前の静的確認 (refute workflow / facet 群の存在、`resolve_takt_workflow` の unit test 4 本、`cli-pr-monitor` への波及なし、Rust 変更ゼロのため exe 再ビルド不要) は §5 T4 実施結果に記載。**実施順**: T5-T7 を飛ばして T8 の次に実施 (T4 は他タスクと独立の XS で、依存なし) | +| T6 | 実装済 (PR 未採番 — 採番後に backfill) | 2026-07-17 | `run_diff_cmd` を `Command::output()` (無限待ち) から spawn + `drain_pipe_unlimited` × 2 + `wait_with_timeout_safe` に載せ替え、timeout 時は `DiffResult::Error` = exit 5 で中断 (fail-closed / ADR-043)。**timeout 値 60s + `[diff] timeout` で上書き可 (ユーザー承認済み)**: 方針が「30s に合わせるが 60s でも可」と両論併記だったため確認した。60s の根拠は diff が snapshot + 大 diff 書き出しを伴い `jj bookmark list` (30s) より重いこと、および timeout の目的がハング検知であって latency 制限ではなく誤 timeout のコスト (pipeline 全体が exit 5) が高いこと。config 化は `[push] timeout` と同形の escape hatch。**T5 の `run_cmd_shell_unlimited` は使えない**: `run_cmd_shell_*` は全 variant が stdout と stderr を結合するが、diff の stdout は reviewers が読むレビュー対象そのものとしてファイルに書かれるため、jj の stderr 警告 (並列 workspace 時の `Concurrent modification detected` = **まさに本タスクが想定する状況**) が混入する。分離を維持し、同型の `bookmark_check::run_jj_bookmark_list` とは direct args で signature 非互換のため共通化しない (ADR-044 層 1 に判定を追記)。**⚠ 初版実装の欠陥を回帰テストが検出した (本タスク最大の学び)**: 「timeout 後に reader thread を join する」初版は timeout 1s に対し制御が戻るまで **9.6s** 掛かった。`cmd /c` の child は cmd.exe で**孫 (実際の jj) は kill 対象外**、孫が pipe を保持するため EOF が来ず join がブロックする = timeout が意味を成さない (T6 が直すハングの再生産)。失敗経路では join せず detach する形に修正。**教訓**: timeout の回帰テストは Err の内容だけでなく**経過時間を assert する** (しないと素通りする)。**回帰テスト**: `mod t6_diff_timeout` 7 本 + config 2 本 (206 → 215 passed)。cli-push-runner のテスト全体が 9.66s → 1.55s に短縮 = timeout が効いている証跡。「stderr を diff に混ぜない」契約も seal (`run_cmd_shell_*` に載せ替えると落ちる)。**サンドボックス実機で before/after 比較**: `[diff] command` を `ping -t` (永久応答 = 返らない jj diff の代役) にし、`@-` から build した修正前 exe と比較。before は **diff stage の所要時間が外側 kill に追随** (25s→24.4s / 10s→9.4s) = 内部に上限が無く放置すれば無限待ち・診断なし。after は 3.0s で exit 5 + 「jj lock 競合を疑え」の診断。実 `jj diff` (既定 60s) が誤 timeout しないことも確認。before の run 後に `ping.exe` が残存し、孫が kill を生き延びる実機裏付けも取れた。**発見 (本タスク外)**: `lib-subprocess` の `run_cmd_shell_*` 3 variant が**同じ穴**を持ち timeout が wall-clock を縛れない (実測 9.23s)。影響は quality_gate `step_timeout` / push `timeout` / cli-merge-pipeline → §6 backlog 10 に追加 (1 PR 1 変更のため別 PR)。**実施順**: 計画の推奨順どおり T5 の次に実施 | diff --git a/push-runner-config.toml b/push-runner-config.toml index ad573c63..6bc76853 100644 --- a/push-runner-config.toml +++ b/push-runner-config.toml @@ -119,6 +119,11 @@ commands = [ [diff] command = "jj diff -r @" output_path = ".takt/review-diff.txt" +# timeout (T6): 未指定時は 60s (DEFAULT_DIFF_TIMEOUT_SECS)。旧実装は無限待ちで、 +# ADR-045 の並列 workspace 運用で jj lock 競合が起きるとパイプラインが無言ハングした。 +# 超過時は diff 取得失敗 = exit 5 で中断する (fail-closed / ADR-043)。 +# 他の jj 系 (bookmark_check 30s) より長いのは snapshot + 大 diff 書き出しを伴うため。 +# 大 diff / 低速環境で誤 timeout する場合のみ延長する (例: timeout = 180)。 # --------------------------------------------------------------------------- # [lint_screen] — Phase c (§8.E lint screen facet) — ADR-038 試験運用配下。 diff --git a/src/cli-push-runner/src/config/mod.rs b/src/cli-push-runner/src/config/mod.rs index b661232c..e962104e 100644 --- a/src/cli-push-runner/src/config/mod.rs +++ b/src/cli-push-runner/src/config/mod.rs @@ -21,6 +21,15 @@ use lint_screen::{apply_lint_screen_env_override, ENV_LINT_SCREEN_ENABLED}; pub(crate) const DEFAULT_STEP_TIMEOUT_SECS: u64 = 120; pub(crate) const DEFAULT_PUSH_TIMEOUT_SECS: u64 = 300; +/// diff stage の既定 timeout (T6)。 +/// +/// 他の jj 系呼び出し (`bookmark_check` の `JJ_TIMEOUT_SECS = 30`) より長く取るのは、 +/// diff が working copy の snapshot + 大 diff の書き出しを伴い、読み取りのみの +/// `jj bookmark list` より重いため。timeout の目的は**ハング検知**であって latency +/// 制限ではなく、誤 timeout は diff 失敗 = pipeline 全体の中断 (exit 5) を招くので +/// 余裕側に倒す。詰まる環境では `[diff] timeout` で上書きする。 +pub(crate) const DEFAULT_DIFF_TIMEOUT_SECS: u64 = 60; + #[derive(Deserialize)] pub(crate) struct Config { pub(crate) quality_gate: QualityGateConfig, @@ -71,6 +80,8 @@ pub(crate) struct PrePushReviewConfig { pub(crate) struct DiffConfig { pub(crate) command: String, pub(crate) output_path: String, + /// 未指定時は `DEFAULT_DIFF_TIMEOUT_SECS` (T6)。`[push] timeout` と同形。 + pub(crate) timeout: Option, } #[derive(Deserialize)] @@ -257,6 +268,61 @@ command = "jj git push" let diff = config.diff.unwrap(); assert_eq!(diff.command, "jj diff -r @"); assert_eq!(diff.output_path, ".takt/review-diff.txt"); + assert!(diff.timeout.is_none()); + } + + /// T6: `[diff] timeout` 未指定時は既定値に落ちる (本リポジトリの config は未指定)。 + #[test] + fn config_diff_timeout_defaults() { + let toml_str = r#" +[quality_gate] +[[quality_gate.groups]] +name = "test" +commands = ["echo ok"] + +[diff] +command = "jj diff -r @" +output_path = ".takt/review-diff.txt" + +[takt] +workflow = "w" +task = "t" + +[push] +command = "echo push" +"#; + let config: Config = toml::from_str(toml_str).unwrap(); + let diff = config.diff.unwrap(); + assert!(diff.timeout.is_none()); + assert_eq!( + diff.timeout.unwrap_or(DEFAULT_DIFF_TIMEOUT_SECS), + DEFAULT_DIFF_TIMEOUT_SECS, + ); + } + + /// T6: 大 diff / 低速環境向けの escape hatch (既定 60s では足りない場合)。 + #[test] + fn config_diff_timeout_explicit() { + let toml_str = r#" +[quality_gate] +[[quality_gate.groups]] +name = "test" +commands = ["echo ok"] + +[diff] +command = "jj diff -r @" +output_path = ".takt/review-diff.txt" +timeout = 180 + +[takt] +workflow = "w" +task = "t" + +[push] +command = "echo push" +"#; + let config: Config = toml::from_str(toml_str).unwrap(); + assert_eq!(config.diff.unwrap().timeout, Some(180)); } #[test] diff --git a/src/cli-push-runner/src/stages/diff.rs b/src/cli-push-runner/src/stages/diff.rs index 9112889c..46e057e2 100644 --- a/src/cli-push-runner/src/stages/diff.rs +++ b/src/cli-push-runner/src/stages/diff.rs @@ -1,7 +1,14 @@ +//! Diff stage — `[diff] command` の出力を reviewers 用ファイルに書き出す。 +//! +//! 出力は takt の reviewers が Read で参照するレビュー対象そのもののため、 +//! **切り詰めない** (`run_diff_cmd` の doc)。実行は timeout 付き (T6)。 + use std::path::Path; -use std::process::Command; +use std::process::{Command, Stdio}; + +use lib_subprocess::{drain_pipe_unlimited, wait_with_timeout_safe}; -use crate::config::DiffConfig; +use crate::config::{DiffConfig, DEFAULT_DIFF_TIMEOUT_SECS}; use crate::log::log_stage; #[derive(Debug, PartialEq)] @@ -14,18 +21,64 @@ pub(crate) enum DiffResult { Error, } -/// diff 取得専用: 出力を切り詰めずに全行を取得する。 -/// runner::run_cmd は MAX_LINES=40 で打ち切るため diff には使えない。 -fn run_diff_cmd(cmd: &str) -> Result { - let output = Command::new("cmd") +/// diff 取得専用: 出力を切り詰めず、stdout / stderr を分離したまま timeout 付きで取得する。 +/// +/// 戻り値: `Ok(stdout)` / `Err(stderr | timeout メッセージ | 起動失敗メッセージ)`。 +/// +/// **stdout と stderr を結合しない**のが本関数の要件で、`lib_subprocess::run_cmd_shell_*` +/// (全 variant が `combine_output` で結合する) を使えない理由でもある。stdout は +/// reviewers が読む diff そのものとしてファイルに書かれるため、jj が stderr に出す警告 +/// (並列 workspace 運用時の `Concurrent modification detected` 等) が混入すると +/// レビュー対象を汚す。読み取り戦略は cap なし (diff は全量が必要) で、shell 経由なのは +/// `[diff] command` が config 由来の文字列だから。同型の「全量 + 分離 + timeout」は +/// `bookmark_check::run_jj_bookmark_list` にもあるが、そちらは direct args で +/// signature が非互換のため共通化しない (ADR-044 層 1)。 +/// +/// timeout (T6): 旧実装は `Command::output()` で**無限待ち**だった。ADR-045 の並列 +/// workspace 運用で jj の lock 競合が起きるとパイプラインが無言ハングする +/// (他 stage は全て timeout 付きで、diff だけが穴だった)。timeout 時は Err を返し、 +/// 呼び出し側が `DiffResult::Error` = exit 5 で中断する (fail-closed / ADR-043)。 +/// +/// child の lifecycle: timeout 経路・try_wait 失敗経路とも `wait_with_timeout_safe` が +/// child を kill + reap する (`_basic` ではなく `_safe` を選ぶ理由 = ADR-044 層 2)。 +/// +/// **child を kill した 2 経路 (timeout / wait 失敗) では reader thread を join しない**。 +/// `cmd /c ` の child は cmd.exe で、その孫 (実際の `jj` 等) は kill の対象外である。 +/// 孫は pipe の書き込み端を継承したまま生き残るため EOF が来ず、join すると孫が自然終了する +/// までブロックする = timeout が意味を成さない (T6 が直そうとしているハングの再生産)。 +/// 実測: 9s 走るコマンドに 1s の timeout を設定し join すると、制御が戻るまで 9.6s 掛かった。 +/// よってこの 2 経路では thread を detach して即座に返す (push-runner は直後に exit 5 で +/// 終了するため thread は道連れになる)。出力も不要 (診断は timeout メッセージ自身が持つ)。 +/// 子が自力で終了した経路 (exit 0 / 非 0) は pipe が閉じるため join してよい。 +fn run_diff_cmd(cmd: &str, timeout_secs: u64) -> Result { + let mut child = Command::new("cmd") .args(["/c", cmd]) - .output() + .stdout(Stdio::piped()) + .stderr(Stdio::piped()) + .spawn() .map_err(|e| format!("Failed to execute {}: {}", cmd, e))?; - if output.status.success() { - Ok(String::from_utf8_lossy(&output.stdout).into_owned()) + let stdout_handle = drain_pipe_unlimited(child.stdout.take().expect("stdout must be piped")); + let stderr_handle = drain_pipe_unlimited(child.stderr.take().expect("stderr must be piped")); + + let status = wait_with_timeout_safe("diff", &mut child, timeout_secs) + .map_err(|e| format!("diff コマンドの wait に失敗: {}", e))?; + + let Some(status) = status else { + return Err(format!( + "diff コマンドがタイムアウトしました ({}s): {}\n\ + jj の lock 競合 (並列 workspace 実行中の別 jj プロセス) を疑ってください。\ + 大 diff で恒常的に超過する場合は `[diff] timeout` を延長してください。", + timeout_secs, cmd, + )); + }; + + let stdout = stdout_handle.join().unwrap_or_default(); + let stderr = stderr_handle.join().unwrap_or_default(); + + if status.success() { + Ok(stdout) } else { - let stderr = String::from_utf8_lossy(&output.stderr).into_owned(); Err(stderr) } } @@ -33,7 +86,8 @@ fn run_diff_cmd(cmd: &str) -> Result { pub(crate) fn run_diff(config: &DiffConfig) -> DiffResult { log_stage("diff", &format!("実行: {}", config.command)); - let output = match run_diff_cmd(&config.command) { + let timeout = config.timeout.unwrap_or(DEFAULT_DIFF_TIMEOUT_SECS); + let output = match run_diff_cmd(&config.command, timeout) { Ok(output) => output, Err(err) => { log_stage("diff", "diff コマンド失敗"); @@ -82,7 +136,7 @@ mod tests { #[test] fn run_diff_cmd_captures_more_than_40_lines() { - let result = run_diff_cmd("for /L %i in (1,1,100) do @echo line %i"); + let result = run_diff_cmd("for /L %i in (1,1,100) do @echo line %i", 30); assert!(result.is_ok(), "command should succeed"); let output = result.unwrap(); let line_count = output.lines().count(); @@ -98,10 +152,11 @@ mod tests { let out_path = std::env::temp_dir().join("test-run-diff-empty.txt"); let _ = std::fs::remove_file(&out_path); + const ZERO_BYTE_OUTPUT_COMMAND: &str = "type nul"; let config = DiffConfig { - // `type nul` produces zero bytes on Windows. - command: "type nul".to_string(), + command: ZERO_BYTE_OUTPUT_COMMAND.to_string(), output_path: out_path.to_string_lossy().into_owned(), + timeout: None, }; let result = run_diff(&config); @@ -116,4 +171,138 @@ mod tests { "output file must not be created for an empty diff" ); } + + /// T6 回帰テスト群: diff stage に timeout が無く無限ハングし得た不具合 + /// (ADR-049 の流儀: 1 test = 1 failure mode + good/bad)。 + /// + /// 由来: 2026-07-16 の push パイプライン調査 (コード監査で発見。T5 と同じく + /// in the wild の発火記録は無く、「他 stage は全て timeout 付き = diff だけが穴」 + /// という非対称として特定された)。 + /// + /// 事故の形: `run_diff_cmd` は `Command::output()` で子プロセスの終了を**無限に** + /// 待っていた。ADR-045 の並列 workspace 運用で jj の lock 競合が起きると + /// `pnpm push` は診断も timeout も無いまま停止し、ユーザーは手動 kill するしかない。 + /// + /// 修正の核心は「timeout 付きで待ち、超過時は Err → `DiffResult::Error` = exit 5 で + /// 中断する (fail-closed / ADR-043)」。あわせて、判定に使う stdout を stderr と + /// 混ぜない契約 (レビュー対象を汚さない) も本 mod で seal する。 + mod t6_diff_timeout { + use super::*; + use std::time::{Duration, Instant}; + + /// 実行し続けるコマンド (ハングした jj の代役)。timeout が無ければ約 9s 待たされる。 + const HANGING_COMMAND: &str = "ping 127.0.0.1 -n 10"; + + const SHORT_TIMEOUT_SECS: u64 = 1; + + /// incident 再現 (bad): 応答しないコマンドを **timeout で打ち切る**こと。 + /// 修正前は `Command::output()` が返るまで待ち続け、本 assert には到達しなかった。 + #[test] + fn hanging_command_times_out_instead_of_waiting_forever() { + let started = Instant::now(); + let result = run_diff_cmd(HANGING_COMMAND, SHORT_TIMEOUT_SECS); + let elapsed = started.elapsed(); + + let err = result.expect_err("timeout は Err で返ること (無限待ちしない)"); + assert!( + err.contains("タイムアウト"), + "timeout と判る診断を返すこと: {:?}", + err, + ); + assert!( + elapsed < Duration::from_secs(5), + "timeout ({}s) 後すぐ制御を返すこと。{:?} 掛かった = コマンドの自然終了を\ + 待っている (T6 の不具合)", + SHORT_TIMEOUT_SECS, + elapsed, + ); + } + + /// timeout の診断は原因調査に足りること: 超過秒数と実行コマンドを含む。 + #[test] + fn timeout_error_reports_the_limit_and_the_command() { + let err = run_diff_cmd(HANGING_COMMAND, SHORT_TIMEOUT_SECS) + .expect_err("timeout は Err で返ること"); + assert!( + err.contains(&format!("{}s", SHORT_TIMEOUT_SECS)) && err.contains(HANGING_COMMAND), + "超過秒数と実行コマンドを診断に含めること: {:?}", + err, + ); + } + + /// timeout は fail-closed で pipeline を止めること (ADR-043)。 + /// `DiffResult::Error` は main.rs で exit 5 = 中断になる。空 diff 扱いで + /// **レビューを skip したまま push に進んではならない**。 + #[test] + fn timeout_aborts_the_pipeline_and_writes_no_diff_file() { + let out_path = std::env::temp_dir().join("test-run-diff-timeout.txt"); + let _ = std::fs::remove_file(&out_path); + + let config = DiffConfig { + command: HANGING_COMMAND.to_string(), + output_path: out_path.to_string_lossy().into_owned(), + timeout: Some(SHORT_TIMEOUT_SECS), + }; + + assert_eq!( + run_diff(&config), + DiffResult::Error, + "timeout は Error (= exit 5 で中断) になること。Empty だとレビューを\ + skip して push に進んでしまう", + ); + assert!( + !out_path.exists(), + "timeout 時に diff ファイルを書かないこと (古い/欠けた diff でレビューさせない)", + ); + } + + /// good: timeout 内に終わるコマンドを誤って打ち切らないこと。 + #[test] + fn command_within_the_timeout_succeeds() { + let output = run_diff_cmd("echo diff line", 30).expect("即終了するコマンドは Ok"); + assert!(output.contains("diff line"), "stdout を返すこと: {:?}", output); + } + + /// `[diff] timeout` 未指定なら既定値が使われること (既定値の適用漏れ防止)。 + #[test] + fn absent_config_timeout_falls_back_to_the_default() { + let config = DiffConfig { + command: "echo ok".to_string(), + output_path: std::env::temp_dir() + .join("test-run-diff-default-timeout.txt") + .to_string_lossy() + .into_owned(), + timeout: None, + }; + assert_eq!( + config.timeout.unwrap_or(DEFAULT_DIFF_TIMEOUT_SECS), + DEFAULT_DIFF_TIMEOUT_SECS, + ); + assert_eq!(run_diff(&config), DiffResult::HasContent); + let _ = std::fs::remove_file(&config.output_path); + } + + /// stderr を stdout に混ぜないこと: stdout は reviewers が読む diff そのものとして + /// ファイルに書かれるため、jj の警告 (並列 workspace 時の `Concurrent modification + /// detected` 等) が混入するとレビュー対象を汚す。`run_cmd_shell_*` (全 variant が + /// stdout/stderr を結合する) に載せ替えるとこのテストが落ちる。 + #[test] + fn stderr_is_not_merged_into_the_diff_output() { + let output = run_diff_cmd("echo real diff& echo Concurrent modification 1>&2", 30) + .expect("exit 0 なら Ok"); + assert!(output.contains("real diff"), "stdout は残ること: {:?}", output); + assert!( + !output.contains("Concurrent modification"), + "stderr の警告が diff 内容に混入しないこと: {:?}", + output, + ); + } + + /// 失敗時は stderr を診断として返すこと (従来契約の維持)。 + #[test] + fn failure_returns_stderr_as_the_diagnostic() { + let err = run_diff_cmd("echo boom 1>&2& exit /b 1", 30).expect_err("exit 1 は Err"); + assert!(err.contains("boom"), "stderr を診断に返すこと: {:?}", err); + } + } } diff --git a/templates/push-runner-config.toml b/templates/push-runner-config.toml index 60167092..33416620 100644 --- a/templates/push-runner-config.toml +++ b/templates/push-runner-config.toml @@ -51,6 +51,8 @@ commands = ["pnpm build"] # git 環境: "git diff origin/HEAD...HEAD" command = "jj diff -r @" output_path = ".takt/review-diff.txt" +# timeout: 未指定時は 60s。超過時は diff 取得失敗 = exit 5 で中断 (fail-closed)。 +# 大 diff / 低速環境で誤 timeout する場合のみ延長する (例: timeout = 180)。 # --------------------------------------------------------------------------- # [pre_push_review] — WP-06 / ADR-047 (試験運用): 反証 (refute) facet。