Skip to content

fix: ログの上限とエントリ単位のメモ化でヒープ枯渇(OOM)を防ぐ - #87

Merged
takecchi merged 2 commits into
mainfrom
codiva/js-stacktrace-fatal-error-ineffective-ma
Aug 4, 2026
Merged

fix: ログの上限とエントリ単位のメモ化でヒープ枯渇(OOM)を防ぐ#87
takecchi merged 2 commits into
mainfrom
codiva/js-stacktrace-fatal-error-ineffective-ma

Conversation

@takecchi

@takecchi takecchi commented Aug 4, 2026

Copy link
Copy Markdown
Owner

背景

実機で次の落ち方が報告された(node 22 / 既定のヒープ上限)。

FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
 8: … v8::internal::MinorGCJob::Task::RunInternal()
zsh: abort      codiva

abort() なので process.on('exit') すら走らず、Phase 21 で入れたクラッシュログにも何も残らない
(Node の診断レポートだけが記録できる経路)。原因は Phase 21 の実績メモで「残る OOM 候補」として
書き残していた 2 点そのまま
だった。

  • state.messages が無制限に伸びる(追記ごとに全体コピー = O(n²))
  • 詳細ビューが更新ごとにログ全体を Markdown 再パースする(logLines にエントリ単位のキャッシュが無い)

Ineffective mark-compacts は「巨大な 1 個」ではなく 確保レートが回収に追いつかない ときに出る
(ネイティブスタック最上位が MinorGCJob = 新世代 GC)。つまり主犯は後者だった。

変更

問題 対策
更新ごとにログ全体を再展開・再パース logLinesエントリ単位でメモ化。エントリは immutable なので幅とプレフィックスが同じなら再利用できる
メモ化した行が永続的に残る(開いた全セッション × 全エントリ) 保持行数の上限 MAX_CACHED_ROWS(LRU)。ただし描画中のログの行は追い出さない(自分が次に使う行を捨てると毎フレーム全再展開に戻る)
messages が無制限 + 追記で全体コピー 新規 core/log-buffer.ts。件数 MAX_LOG_ENTRIES(2000)/ 合計文字数 MAX_LOG_CHARS(400,000)/ 1 件 MAX_LOG_ENTRY_CHARS(20,000。 を付けて切る)。追記経路を pushLogEntry 1 本に集約
10MB の Read / Bash 結果を平坦化 → 全行 splitBash の heredoc も全部組み立ててから切る 読む長さだけ材質化(asStringHead / inputText
streamingText に 1 メッセージ全体を溜め毎フレーム split 末尾 MAX_STREAM_PREVIEW_CHARS だけ保持(描くのは最後の 1 行だけ)
復元時に全セッションのトランスクリプト(各数 MB)を Promise.all で同時読み込み、しかも全エントリを作ってから捨てる 1 本ずつ読む + 読みながら畳む(History)+ capLogEntries

件数の上限だけでは何も縛れない(1 件は 1 文字でも 20,000 文字でもよいので件数 × 1 件上限 =
4000 万文字)。描画コストは文字数に比例し、展開後の行は元テキストの数倍を占めるので、
文字数の予算キャッシュ行数の予算の 2 つが実効的な上限になっている。

seq は振り直していない(描画キー <seq>:<行> がこれで決まる)。切り詰めはサロゲートペアを
分断しない(絵文字の途中で切って にしない)。

実測

測ったもの 結果
2,000 文字級の Markdown 500 件 × 「1 件追記 → 再描画」500 回 メモ化前 23.3 秒(75 万個の DisplayLine)→ 後 0.10 秒
上限いっぱい(2000 件 / 12,000 行 = 予算の 1.5 倍)で 300 回追記 → 再描画 0.40 ms/フレーム(予算超過でも全再展開しない)
上限まで詰めたセッション 6 本を描画したあとの保持量(--expose-gc + gc() 後の heapUsed 差分) 22 MB(行数上限が無いと 1 本で 91 MB・最悪 1.25 GB)

前提と既知のトレードオフ

  • ログは会話の「記録」ではなく「表示」。正本は Claude Code のトランスクリプト
    ~/.claude/projects/、復元元)なので、古い行を落としても読み返す手段は残る。
  • スクロール位置は「文書先頭からの表示行 index」なので、上限に達したログが古い行を落とすと
    その分ズレる
    (上スクロール中に追記が続くとビューが少しずつ新しい方へ動く)。
    選択の方はクリアする(触っていない行がコピーされるのは重すぎるため。端末幅の変化と同じ扱い)。
    完全に直すなら基準を DisplayLine.key<seq>:<行>。トリム・追記の双方で不変)にする必要があり、
    core/scroll.ts / core/log-selection.ts / 当たり判定まで波及するので別 Phase に分離した
    docs/TASKS.md に記載)。
  • toolResultSummary は CR も行区切りとして切るようになったので厳密には従来と同値ではない
    Progress\r50%\r100% のような結果が 1 行に収まる方向の変化。復元ログも同じ関数を通るので一致は保たれる)。

テスト

  • core/log-buffer.spec.ts(新規): 件数・文字数・1 件の上限 / 切り詰めとサロゲート保護 / 不要なら同一参照のまま返す(= メモ化が効く)/ kindtimestamp を保つ
  • core/scroll.spec.ts: 同じエントリは 2 度展開しない / 追記時に古い行は同一参照 / 幅・プレフィックス変更で再計算 / Markdown 経路の再折り返し / メモ化の結果が非メモ化と一致 / LRU で古い行は落ちる / 予算より大きいログでも自分の行は追い出さない
  • core/sdk-parse.spec.ts: SDK 経路の上限 / 巨大 heredoc の切り詰め / 切られた回答の result エコー除去(レビューで見つかった二重表示の回帰テスト)/ toolResultSummary の各分岐と 10MB ペイロード / summarizeToolUse の表
  • core/status-reducer.spec.ts: appendLog の上限
  • core/transcript.spec.ts: 復元の上限 / 読みながらのトリム / 切り詰め

lint / typecheck / test(2037 件・coverage 閾値クリア)/ build すべて緑。

動作確認 TODO(実機)

  • 長時間動かしたセッションで詳細ビューを開いたままにしてもメモリが伸び続けないこと(~/.codiva/logs/crash-*.logmemory 行 / ps の rss)
  • 上限を超えるログでも詳細ビューのスクロール・範囲選択が壊れないこと
  • 復元(.codiva/state.json ありで起動)でログが従来どおり出ること
  • 長い回答(20,000 文字超)が二重に出ないこと

ドキュメント

  • docs/TASKS.md: Phase 23(実測表・残した課題つき)。Phase 21 のメモに「実際にこれで落ちた」を追記
  • docs/ARCHITECTURE.md: 「ログのメモリ上限(OOM 対策)」節(不変条件とトレードオフ)
  • docs/TECH_NOTES.md: 「ヒープ枯渇の実測」節(保持量・LRU の落とし穴)
  • .claude/rules/session-domain.md / CLAUDE.md: 追記経路は pushLogEntry だけ、を不変条件として追加
  • README.md: トラブルシューティング「詳細ログの古い行が消える」

🤖 Generated with Claude Code

`FATAL ERROR: Ineffective mark-compacts near heap limit` で abort する報告への対応。
Phase 21 で「残る OOM 候補」として記録していた 2 点がそのまま原因だった。

- 保持側: `SessionState.messages` に上限が無く、追記が `[...messages, entry]` =
  全体コピー(O(n²))だった。新規 `core/log-buffer.ts` に件数・文字数の上限を置き、
  追記経路を `pushLogEntry` 1 本に集約する(`appendLog` と `sdk-parse` の直書き)。
- 確保側: 詳細ビューが更新ごとにログ全体を折り返し + Markdown 再パースしていた。
  `logLines` をエントリ単位でメモ化(`WeakMap<LogEntry, rows>`)。実測で
  500 件・500 フレームの再描画が 23.3 秒 → 0.10 秒。
- ツール結果は先頭 200 文字しか使わないのに 10MB のペイロードを平坦化して
  全行 split していたため、読む長さだけ材質化する(出力は従来と同値)。
- `streamingText` は末尾だけ保持(描くのは最後の 1 行)。
- 復元はトランスクリプトを 1 本ずつ読み、`capLogEntries` で上限に収める。
@takecchi
takecchi marked this pull request as ready for review August 4, 2026 08:52
レビュー指摘の反映。

- **切り詰めたエントリと result のエコー判定が食い違っていた**: 20,000 文字を超える回答は
  保存時に切られる一方、`result` 文字列は素で比較していたため一致せず、長い回答が
  「白い assistant_text + 緑の result」で二重に出ていた。切った形どうしで比べる。
- **メモ化は一過性のゴミを永続的な保持に変える**: 行はエントリが生きている限り残るので、
  上限が無いと「開いた全セッション × 全エントリ」を抱える(実測 1 セッション 91MB、
  最悪 1.25GB)。保持行数の上限(`MAX_CACHED_ROWS`・LRU)を入れ、ただし**描画中のログの
  行は追い出さない**(自分が次に使う行を捨てると毎フレーム全再展開に戻る)。
  実測: 6 セッション描画後の保持 22MB、上限いっぱいのログで 0.40 ms/フレーム。
- **件数の上限だけでは何も縛れない**(1 件は 1 文字でも 20,000 文字でもよい)ので、
  合計文字数の予算 `MAX_LOG_CHARS` を追加。
- 復元は**読みながら**畳む(`History`)。全エントリを作ってから捨てていた。
- `Bash` の heredoc など tool_use の入力も、組み立てる前に切る。
- 上限に達して古い行が落ちたときは**選択を捨てる**(選択は文書先頭からの表示行 index
  なので、触っていない行がコピーされる)。スクロール位置のズレは既知の課題として明記。
- ドキュメントの誇張を修正(`toolResultSummary` は CR も切るので従来と完全同値ではない、
  `onApiRetry` は書き換えなので `pushLogEntry` を通らない、など)。
@takecchi
takecchi merged commit cd15a62 into main Aug 4, 2026
1 check passed
@takecchi
takecchi deleted the codiva/js-stacktrace-fatal-error-ineffective-ma branch August 4, 2026 09:27
takecchi added a commit that referenced this pull request Aug 5, 2026
## 何をしたか

`~/.codiva/logs/` に残っていた Node の診断レポート 3 件を調査したところ、**0.3.8
でもヒープ枯渇(OOM)で落ちていた**ことが分かったので、その原因を潰しました。Phase
23(#87)で直したものとは**別のバグ**です。

## 原因

診断レポートの読み方から始めています。

| | 14:34 | 23:45 | 23:50 |
|---|---|---|---|
| cwd | codiva | glucose-flight-frontend | codiva |
| event | `Allocation failed - JavaScript heap out of memory` | 同じ | 同じ
|
| `old_space` | 4.23GB(使用率ほぼ 100%) | 4.2GB | 4.23GB |
| `large_object_space` | 55MB | 同程度 | 同程度 |
| 消費 CPU 時間 | 1628 秒 | 1987 秒 | 1571 秒 |

`old_space` が生存データで埋まる一方 `large_object_space` は 55MB だけ =
**小さいオブジェクトの保持漏れ**(Phase 23 の `Ineffective mark-compacts` =
確保レート過多とは別物)。ヒープスナップショットを取ると上位が `PerformanceMeasure` × 60,003(= 20,000
描画 × **3**)と `Components ⚛` / `Changed Props` / `Scheduler ⚛` で、正体は
**React 19.2 の Performance Tracks** でした。

- `react-reconciler` は dev ビルドの**モジュール評価時**に
`supportsUserTiming`(`console.timeStamp` && `performance.measure`。Node
には両方ある)を確定し、以後レンダーごとに `performance.measure()` を 3 本積む。
- **Node の user timing は呼んだ側が捨てるまで保持され続ける**(ブラウザの devtools が消費する前提の
API)。
- `bin` から `node` で直に起動され `NODE_ENV` は未設定 = **利用者は必ず dev ビルド**だった。


描画内容に一切依存しないので、ログの上限では止まりませんでした。なお同じ結論が上流に既報でした([ink#869](vadimdemedes/ink#869)
/
[react/react#35761](https://github.com/facebook/react/issues/35761)。どちらもクローズ済み・対策も同じ)。

## 実測

`--expose-gc` + 強制 GC 後の `heapUsed` 差分。**空 Box** を 8,000 回再描画(= 描画内容ゼロ)。

| 条件 | 永久保持 | perf エントリ | 所要 |
|---|---|---|---|
| dev ビルド(従来) | **2,230 B/フレーム** | 24,003 件 | 414ms |
| `NODE_ENV=production` | 117 B/フレーム | 0 件 | **166ms** |
| dev + 定期 `clearMeasures()` | 174 B/フレーム | 1 件 | 406ms |

描画は約 10/秒(ストア購読の ~100ms スロットル)⇒ **約 86MB/時**。既定のヒープ上限 ~4GB に半日〜1
日で到達します。production ビルドは**描画自体も 2.5 倍速い**(報告された 26〜33 分の CPU 時間の相当部分がこれ)。

## 変更点

1. **`src/index.tsx` を起動シムにする**(本体は `src/main.tsx` へ改名)
`process.env.NODE_ENV ??= 'production'` を `await import('./main')`
**より前**に置きます。ESM の static import は巻き上げられて本文より先に評価されるため、`tsup` の `banner`
では間に合いません。シバンに `env -S NODE_ENV=production` を書く手も、**mise 経由の起動が `node
<path>` 直叩きでシバンを通らない**ため当てになりません(実際のクラッシュレポートの `commandLine` がそれ)。`tsup`
は `splitting: true` が必須で、`dist` は `index.js`(113B のシム)+
`main-<hash>.js`(本体)の 2 ファイルになります。`bin` が指すパスと `packageRootFrom`
の前提(`package.json` の 1 つ下)は変わりません。
→ 番人として **`tests/entry-shim.test.ts`** がシムに static import が無いこと・代入が動的
import より前にあることを固定します(1 本足すだけで見た目に気づけないまま壊れるため)。
2. **`bootstrap/perf-timeline.ts`(保険)**: 30 秒ごとに
`performance.clearMeasures()` / `clearMarks()`。`NODE_ENV=development`
で起動したときや、将来 React / Node が別の形で user timing を積み始めたときに効きます。タイマーは
unref、失敗は握り潰し。
3. **ストリーミングプレビューを表示幅で切る**: `streamTail(text, width)` + 純粋な
`clipToWidth`(グラフェム単位・早期打ち切り・ANSI を含む行は切らない)。Ink 7.1.1 の
`measure-text.js` / `wrap-text.js` は**キー = テキスト全文の上限なしキャッシュ**で、4,000 文字の
`<Text>` 1 描画で約 17.8KB が永久に残ります。`wrap="truncate-end"`
は描画時に切るだけなのでキーは切る前の文字列 =
効きません。**見た目は不変**で、行が幅を超えたあとは文字列が変化しなくなるためキャッシュに当たるようになります(4,000
文字の最悪ケースで 6,786 → 3,129 B/フレーム)。渡す幅はログ行の折返しと同じ `logWidth` を共有します。
4. **`startPrPolling` の `void manager.refreshPrs()` に
`.catch()`**(規約違反の修正)。20 秒ごとの reject が unhandled rejection =
プロセス死になり、**死因が OOM と見分けづらい**ため、OOM 調査中は特に紛らわしい箇所でした。

## テスト計画

- [x] `npm run lint` / `npm run typecheck` / `npm test`(**2175
件パス**、カバレッジ statements 95.7% / branches 90.7%)/ `npm run build` 緑
- [x] `node dist/index.js --reset-terminal` と `npx tsx src/index.tsx
--reset-terminal` の両経路が起動する(シムを通ることの確認)
- [x] ビルド出力の `dist/index.js` に static import が無いことを目視 + テストで固定
- [ ] **実機での体感確認はお願いします**(TTY と認証が必要なため非対話セッションでは実行できません)。長時間動かしたときに RSS
が増え続けないか、`~/.codiva/logs/` に新しい `report.*.json` が出ないかを見ていただけると確実です

## 残した課題

- **Ink のキャッシュ自体に上限が無いこと**は上流の修正が必要なので issue を出しました →
[ink#986](https://github.com/vadimdemedes/ink/issues/986)(未報告のバグでした。再現コードと実測付き)。新しく現れたログ行
1 本ごとに約 1.7KB が永久に残ります。codiva 側で上限を付けるには `noExternal: ['ink']` でバンドルして
LRU 化する必要があり(`signal-exit` の CJS `require` シム + チャンク分割 +
`react-devtools-core` の external が付き、dist は 322KB →
1.8MB。実験済み)、「ビルド構成は変えない」方針との兼ね合いで見送っています。
- 調査の副産物として見つかった**本件と独立な別バグ**を `docs/TASKS.md` に次 Phase の候補として残しました:
`SessionStore.set` による削除済みセッションの復活 / `canUseTool` の pending が 1
スロットで並行要求を取りこぼす(サブプロセスが永久待機になる)/ `AsyncQueue` の待機 resolver
が死んだイテレータへ配送する / discard・merge が `SessionHandle`
を解放しない。いずれもメモリの主因ではありませんが実害があります。
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant