Skip to content

fix(git): git 読み取りのタイムアウトを git:command-failed の warn に下げる - #3433

Merged
Kewton merged 3 commits into
developfrom
feature/3416-git-exec-command-failed
Oct 8, 2026
Merged

Kewton merged 3 commits into
developfrom
feature/3416-git-exec-command-failed

Conversation

@Kewton

@Kewton Kewton commented Oct 8, 2026

Copy link
Copy Markdown
Owner

Summary

日次メトリクスが、git-exec git:command-failed の ERROR を 1 日 85 行と報告した(#3416)。

内訳(本番ログを読み取りのみで集計。2026-10-05〜10-08 の 127 件):

  • サブコマンド: status --porcelain 126 件、rev-parse --abbrev-ref HEAD 1 件
  • 127 件すべてが Command failed: git <args> で stderr が空。つまり git 自身の失敗ではなく、execFile の timeout(GIT_COMMAND_TIMEOUT_MS=1000ms)で kill されたもの
  • 時間分布: 10-07T17 に 35 件が連続(同時刻に別リポジトリでビルド負荷)。平常時の git status は 27〜325ms で、1 秒を超えるのはホスト負荷の時だけ

変更(src/lib/git/git-exec.ts の execGitCommand): timeout で打ち切られた失敗は git:command-failed の warn(timedOut / timeoutMs つき)にし、git が非 0 で終わった失敗は従来どおり ERROR。ログキーはメトリクスとテストが参照しているので残した。次の計測で呼び出し元を数えられるよう、ログに worktree(cwd の basename)を足した。timeout 判定は execGitCommandCapture と同じ条件を isExecTimeout に寄せて共用。閾値(1 秒、#779 の「UI を止めない」上限)は変えない。

Refs #3416(develop 向けのため Closes は使わない。ERROR 行数の減少は翌日以降の計測で確認する)

範囲外(この PR では扱わない。追跡 Issue にするかは run の完了報告で判断する)

  • src/lib/git/git-status.ts:50: status が timeout で null のとき isDirty=false になり、負荷時に未コミットの変更がある worktree が clean と表示される
  • src/lib/git/git-branches.ts:322: checkout の dirty ガードが status の null(timeout を含む)を clean として通す

Test plan

  • commandmatedev verify --task: work-evidence / scope / env-clean / lint / typecheck / unit-related すべて PASS(exit 0)
  • 新規 tests/unit/lib/git/git-exec-log-level.test.ts(一時 git リポジトリ): timeout → warn のみ/unknown revision・リポジトリでないパス → ERROR のまま/成功 → ログなし
  • develop 取り込み後に npx tsc --noEmit、tests/unit/lib/git・guards・docs が合格。既存の it/describe の削除 0 件、changelog-fragments.mjs check exit 0
  • CI の Unit Tests(unit-related で裁定したので、マージは Unit Tests の pass 後)

🤖 Generated with Claude Code

Kewton and others added 3 commits October 8, 2026 16:24
…3416)

## 失敗の内訳(本番ログを読み取りのみで集計)
対象: MyCodeBranchDesk/logs/server.log(0件) .1(103件) .2(17件) .3(7件) = 計127件
(2026-10-05T02 〜 2026-10-08T00)。ERROR の [git*] はこのキー以外 0 件。
- (a) サブコマンド: `status --porcelain` 126 件 / `rev-parse --abbrev-ref HEAD` 1 件
- (b) エラー文言: 127 件すべて `Command failed: git <args>\n` で stderr が空。
  git 自身が失敗すると stderr に `fatal: ...` が付くので、空 = execFile の
  timeout(GIT_COMMAND_TIMEOUT_MS=1000ms)で kill された子プロセス。
  `not a git repository`・上流なし・HEAD なし等の文言は 0 件。
- (c) 呼び出し元: ログに cwd が無く worktree 単位では数えられない。
  `status --porcelain` を 1 秒枠で呼ぶのは getGitStatus(git-status.ts:36。
  GitPane 5 秒ポーリング / GET /api/worktrees/[id] 等)・preview-diff.ts:473・
  git-branches.ts:322。rev-parse と status が同じ回で落ちたのは 1 回だけで、
  他は status だけが 1 秒を超えている=getGitStatus の 3 並列のうち一番重い読み取り。
  時間分布: 10-07T17 に 35 件(17:36〜17:48 に約 22 秒間隔で連続。同時刻は
  CommandAgent の worktree で command-code が稼働中=cargo のビルド負荷)、
  他は 1 時間あたり 1〜11 件。list:slow(WARN) の前後 60 秒に重なるのは 127 件中 39 件。
- 平常時の実測(git --no-optional-locks status --porcelain、書き込みなし):
  CommandMate の worktree 群 27〜48ms、CommandAgent の worktree 群 213〜325ms。
  1 秒枠に対し平常時は 3〜40 倍の余裕があり、超えるのはホスト負荷の時だけ。

## 判断
- 切り分け: 想定内の結果。無駄な再試行・消えた worktree への繰り返し呼び出しは
  見つからない(失敗文言に存在しないパスの痕跡なし)。呼び出し側は null を
  '(unknown)' / not dirty として既に扱っている。
- 閾値は変えない: 1 秒は Issue #779 の「UI を止めない」ための上限で、平常時は
  十分な余裕がある。原因は負荷であり、閾値を上げても負荷時のポーリング応答が
  遅くなるだけで失敗の原因は消えない。
- 直したこと(src/lib/git/git-exec.ts execGitCommand):
  timeout で kill された失敗は `git:command-failed` の warn(timedOut/timeoutMs つき)、
  git が非 0 で終わった失敗は従来どおり ERROR。キー `git:command-failed` は
  scripts/agent-health のメトリクスと tests/unit/lib/agent-health/*,
  tests/unit/scripts/agent-health/*, tests/unit/logger.test.ts が参照しているので残した。
  次の計測で呼び出し元を数えられるよう、ログに worktree(cwd の basename)を足した。
  timeout 判定は execGitCommandCapture と同じ条件を isExecTimeout に寄せて共用。
- 期待値: 127 件すべてが warn になるので、ERROR は 0 件近くまで減る見込み
  (翌日以降の計測で別途確認)。

## 対になる場所
- 同じ ERROR キーの 2 か所目 git-exec.ts:192(execGitCommandTyped): timeout は
  その前で GitTimeoutError に変わり到達しないので、到達するのは本当の失敗だけ。直さない。
- 同じ「logger.error で失敗を握りつぶす」型: git-log.ts:220 git:commit-log-failed、
  git-diff.ts:132 git:working-diff-failed、git-exec.ts git:conflict-aware-failed。
  本番ログでの ERROR は 0 件で、下げる根拠がないので直さない。
- execGitCommandCapture の timeout 判定は同じ条件の写し → isExecTimeout を共用。
  execGitCommandTyped / execGitConflictAware / execGitNetworkAware / git-diff.ts の
  同条件は timeout を型付きエラーに変える別の契約なので触らない。
- 古い動きを固定したテスト: execGitCommand の失敗を logger.error で固定したテストは
  無い(tests/unit/lib/git, tests/unit/git-utils.test.ts を確認)。
- docs: git-exec.ts の行は docs/module-reference.md に無い。注記は断片で出す。

## テスト
tests/unit/lib/git/git-exec-log-level.test.ts(os.tmpdir() 配下の一時 git リポジトリ):
timeout → warn のみ・ERROR なし(陽性)/unknown revision・リポジトリでないパス →
ERROR のまま(陰性)/成功 → ログなし。

## 本文に無い指摘
- 本文に無い指摘: src/lib/git/git-status.ts:50 status が timeout で null のとき
  isDirty=false になり、負荷時に dirty な worktree が clean と表示される。
- 本文に無い指摘: src/lib/git/git-branches.ts:322 checkout の dirty ガードが
  status の null(timeout を含む)を clean として通すため、負荷時に force なしの
  checkout が未コミット変更の上で進みうる(git 自身の拒否が最後の砦)。

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@Kewton Kewton added the bug Something isn't working label Oct 8, 2026
@Kewton
Kewton merged commit 95fef89 into develop Oct 8, 2026
16 checks passed
@Kewton
Kewton deleted the feature/3416-git-exec-command-failed branch October 8, 2026 09:16
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

bug Something isn't working

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant