macos-latest runnerでtest_remote_status_liveness.batsのsync startテスト群が断続的にハングする

[kappaseijin4claude]

概要

tests/test_remote_status_liveness.batsの「sync start ...」テスト群が、macOS runner上でごく稀に完全にハングし、CIワークフロー自身が持つhang検知機構（後述）によって強制cancelされる現象が、日付・ブランチをまたいで複数回観測されています。まだ原因を特定できていないため、追跡用に起票します。

観測事実

日時	ブランチ	run	job	状況
2026-08-17T10:11:22Z	fix/herdr-window-default-issue57-ac3	32018951716	bats (macos-latest 2/4)	cancelled
2026-08-19 03:23〜	fix/85-team-work-store-init（PR #87）	32211975474	bats (macos-latest 4/4)	同一runで3回連続cancelled（guarded single-job rerunを3回試行、いずれもハング）

PR #87での3回のハング詳細（job logより）:

• 1回目: ok 247 sync start reaps a ready-timeout child before releasing ownership (03:36:22Z) を最後に出力が止まり、##[error]The operation was canceled. (03:53:01Z) まで約17分間無音。
• 2回目: ok 382 sync start: two at once leave exactly one engine, on the blind probe (#817, #652) (04:19:48Z) を最後に出力が止まり、04:21:18Zにcancel。
• 3回目: 同じjobを再度rerunしたが、再度cancelled（詳細ログ未取得）。

いずれも直前に出ていた最後のテストはtest_remote_status_liveness.bats内のsync start系だが、ハングした具体的なテスト名は毎回異なる（#247と#382）。特定の1テストに固定された再現ではなく、この一帯（プロセスspawn/readiness pollingまわり）で断続的に起きている様子。

PR #87の変更との関連は無いと判断した根拠

• PR #87で実際に変更したtests/test_team_work_audit.bats・tests/test_team_work_reconciler.batsは、.github/scripts/shard-tests.sh 4 4の出力に含まれていない（ハングが起きているshard 4には無い）。
• PR #87で変更したscripts/team-work.shのうち触れたのはobserve|queue|audit・reconcile|watchdog分岐のみ。shard 4に含まれるtest_team_work_state.batsはteam-work.shのcatch-all（claim/renew/ack等）分岐しか使わず、そちらは元々agmsg_storage_ensure_initializedを呼んでおり今回の差分と無関係。
• 2026-08-17の別ブランチ（PR #87とは無関係、shard番号も2/4で別）でも同じ症状が確認されている。
• githubstatus.com は本日確認時点でAll Systems Operational。GitHub側の広域障害ではなさそう。

以上から、PR #87の差分が原因ではなく、既存のsync startテスト群がmacOS runner上で持つ既知の潜在的なハングと判断し、PR #87側はguarded single-job rerunで進めています。

既にある手掛かり

.github/workflows/tests.ymlには、この種の症状（"a shard that reports every test ok and then sits"）を見越したhang検知・診断の仕組みが既にあります:

• hang-samples.txt（RUNNER_TEMP配下）に定期的なプロセス診断スナップショットを記録し、ジョブ終了時にartifactとしてアップロード（hang-samples-${{ matrix.os }}-${{ matrix.shard }}）。
• ワークフロー内のコメントに「the 08-01 hang」という記述があり、過去に少なくとも1回、同種の事象が診断された形跡がある。

ただし本Issueを起票する前に検索した範囲では、この現象を追跡する既存のGitHub Issueは見つかりませんでした（"hang"・"macos.*timeout"等でissue一覧を検索、0件）。ツールは用意されていたが、issueとしては追跡されていなかったようです。

次のステップ（未着手）

• PR #87がマージされ次第、hang-samples-macos-latest-4（run 32211975474の該当attempt）のartifactを取得し、スタックサンプルから具体的にどのプロセス/syscallでブロックしているかを特定する。
• 再現性が高いようなら、ローカルのmacOS環境でtest_remote_status_liveness.batsのsync start系テストを繰り返し実行し、再現を試みる。
• 原因が特定できるまでの緩和策として、該当jobのタイムアウトを短縮してCI全体の待ち時間を減らす、または既知のハングに対する自動リトライをワークフロー側に組み込む、などを検討する。

まだ具体的な修正の範囲は決めていません。追跡・情報集約のために起票します。

[kappaseijin4claude]

追記: 同一run(32211975474)内でのjob単位再実行を4回試したところ、4回ともbats (macos-latest 4/4)がハング→cancelされました。単なる低確率のflakeにしては再現率が高すぎるため、同一run内の再実行に依存するのをやめ、空コミット(f7f7d2d)を積んで新しいworkflow run(32218855339)を発火させました。新runの結果次第で、「同一runへの再実行そのものに何らかの相関がある」のか「単に運が悪かっただけ」なのかの切り分け材料になります。結果はこのissueに追記します。

[kappaseijin4claude]

重要な追加証拠です。空コミットで発火させた新run(32218855339)でも、macos-latest 4/4が5回目のハング（旧run 4回+新run 1回目の再実行）となりました。同時に同じ新run内でWindowsのbats (windows-latest, driver input (fujibee#817))も1回だけハングしましたが、こちらは再実行1回で即座に成功しました。macos-latest 4/4だけが再現率高く持続してハングしています。

PR #87の差分が原因ではないことをshard実行順で確定できました。 .github/scripts/shard-tests.sh 4 4が返すファイル順は次の通りで、bats はこの順に逐次実行します:

1: tests/test_spawn.bats
...
5: tests/test_remote_status_liveness.bats   ← ハング箇所（sync startテスト群）
...
16: tests/test_team_work_state.bats          ← PR #87がteam-work.shへ加えた分岐を唯一exerciseするファイル
...

ハングが起きるtest_remote_status_liveness.bats（5番目）は、PR #87の差分を経由するtest_team_work_state.bats（16番目）よりも前に実行されます。 つまりハングが発生した時点でPR #87の変更コードはまだ一度も実行されておらず、原因になり得ません。

現時点でmacos-latest 4/4のみ再実行を継続しています。5回連続という高い再現率は、通常の低確率flakeというより、今日この時間帯のmacOS runnerプール（またはこのshardの並び）に特有の問題を示唆している可能性があります。

[kappaseijin4claude]

【ユーザー決定】本issueの根本調査は、Codexが復帰次第（2026-08-20T12:37+09:00予定）着手を依頼する方針としました。「間隔を空けて再試行継続／しばらく待って再試行／admin mergeで必須チェックを回避」の3択を提示しましたが、ユーザーの回答は「codexが戻ってくるまで調査させる。」でした。

このためPR #87は、CI clean になるまでmergeせずopenのまま保持します（差分自体はテスト済み・レビュー済みで、本issueのハングとは無関係と実行順の解析で確定済みです）。日常的なflaky test（1回のguarded rerunで解消する範囲）はこれまで通りClaude単独で対応を継続しますが、本件のように単発では解消せず原因も特定できない問題は、根本調査をCodexへ引き継ぎます。

詳細はdocs/decisions/2026-08-17T060000_codex不在期間のClaude単独運用とmerge方針.md「適用の限定」に記録済みです。

[kappaseijin4claude]

PR #90（upstream同期、mainへmerge済み）にupstream commit f7de22a（fix(roster): bound the wait on the local child without spawning anything to do it, fujibee#821）が含まれていました。このコミットのメッセージは「ローカル子プロセスのハングでロックが永久保持される」「macOSのbash 3.2ではread -tのタイムアウト判定が機能しない」という趣旨で、本issueの症状と酷似していたため、経過を記録します。

PR #90同期後、以下2回のCI実行でmacos-latest全4shard、計8回の実行がありましたが、ハング/cancelは1件も発生しませんでした（通常のtest failureは2件ありましたが、いずれもハングとは別の症状で、guarded rerunで解消・Issue #91として別途記録済みです）。

• PR #90自体のCI（run 32236810626）: macos-latest 1/4〜4/4、4件とも通常完了
• PR fix: team-workのread/reconcile系コマンドがstore未初期化時にunknownを返さないようにする #87（team-work.sh修正）をPR #90後のmainへrebaseして再実行したCI（run 32240881039）: macos-latest 1/4〜4/4、4件とも通常完了（1件は別原因のtest failureで再実行後pass）

同期前は同一shard(macos-latest 4/4)で5回連続ハングしていたことと比べ、明確な改善が見られます。upstream commit f7de22aが本issueを解消した可能性が高いと考えていますが、根本原因の確定・issue closeの判断はユーザー決定通りCodex復帰後にお任せします。それまでの追加データとして記録しておきます。

[kappaseijin]

検証結果: f7de22a は本 issue の hang artifact の経路と一致しない

verifier（agmsg_verifier_codex）が run 32211975474 の hang-samples-macos-latest-4 artifact（9353222416）を実測した。

• artifact は test_remote_status_liveness.bats の remote.sh sync start testteam → remote-sync.mjs run --team testteam 経路を記録していた（remote経路marker 48件、対象testmarker 166件、roster同期marker 0件）
• 一方、f7de22a が変更したのは scripts/internal/roster-sync-driver.sh・scripts/lib/roster-journal.sh・tests/test_roster_journal.bats で、artifact に roster-sync driver 経路の実行証跡は無い
• 負の対照: 同一 artifact 検索で対象 test/remote marker は検出できているため、roster marker 0 件は検索不能ではなく実際に経路が異なることを示す

結論: この artifact 単体を根拠にした close は提案しない。

未確認・既知の限界

• f7de22a 後の 8 shard 実行でハング 0 件、という本 issue のコメント（2026-08-19T11:03Z 時点）の統計的観測は今回再集計していない。コード経路の不一致とは別の話であり、これ自体を否定する結果ではない
• process snapshot は根本原因を完全には証明しない。両経路が registry lock を共有する可能性は残る

詳細な証跡: docs/plan/2026-08-21_issue-88-hang-artifact-verification.md（agmsg リポジトリ内）

[kappaseijin]

close: PR #137で根因修正・配備・再現試験で確認済み

根因

scripts/remote.shのcmd_sync_startのready待ちが、実時間deadlineではなく1600回の反復(sleep 0.01)で制御されていた。高負荷ホストでは1周が伸び、待ち総時間が無際限に膨らんでいた(コード内の既存コメントが「1600 turns … is not sixteen seconds」(fujibee#779)と実時間でないことを明記済み)。

修正

PR #137(https://github.com/kappaseijin/agmsg/pull/137、merge commit 12af3282f6b30f4cdd8192dc1da59cc3e7f3bca7)で、ready待ちを既定16秒の実時間deadlineへ変更(AGMSG_REMOTE_SYNC_READY_TIMEOUT_Sで上書き可能)。既存のnonce check・cleanup・lock再取得・所有権fail-closedは維持。

本番配備(~/.agents/skills/agmsg/)もinstall.sh --updateで反映済み(v1.2.3-126-g12af328)。

再現試験(post-merge、verifier実測)

• value: #731(unreapable engine fixture)を90秒cutoffで実行、timeout 0/1・exit 0・69.242秒で正常終了(修正前の同一条件は720秒超過)
• 負の対照: owned ready-timeout childも同じ90秒cutoffでtimeout 0/1・exit 0・59.136秒
• source: PR fix: bound remote sync readiness wait #137 merged、installed v1.2.3-126-g12af328、tests/test_remote_status_liveness.bats #731
• command: python3 /private/tmp/agmsg-issue88-watchdog.py 90 ... -- env BATS_SHELL=/bin/bash bats --filter "sync start says a live engine was left behind" tests/test_remote_status_liveness.bats
• 限界: #731の1試行のみで、全sync start経路を網羅する検証ではない
• 証跡: docs/plan/2026-08-24_issue-88-pr-137-post-merge-verification.md

判断

ユーザー承認により、reopen条件なしの通常closeとする。