Claude CodeでNodeのcpuprofileを解析し遅い関数を絞る

Node.jsの --cpu-prof が出す .cpuprofile は、そのままClaude Codeに読ませる形をしていません。自己時間の合計を出すだけでも手計算が要り、ファイル全体を貼ると本題と無関係な行が大半です。

先に前処理でjqを挟み、自己時間の上位だけ、しかも node_modules の時間を呼び元のアプリ関数に畳んだ表を作ります。その表を claude -p に渡せば、「どの関数を見直すか」の相談がすぐ始められます。

手順はプロファイル取得、jqで上位抽出、node_modules の畳み込み、Claude Codeへの依頼の4段です。サンプルは手元のNode.js v20.18.0で実際に動かした出力を使います。

プロファイルを取る — --cpu-profの使い方

--cpu-prof はV8のCPUプロファイラーを起動時に有効にし、終了前にプロファイルをディスクへ書き出します。出力先を指定しなければカレントディレクトリに、CPU.${yyyymmdd}.${hhmmss}.${pid}.${tid}.${seq}.cpuprofile の名前で保存されます。

node --cpu-prof --cpu-prof-dir=./prof src/report.js
ls prof

周辺のフラグは次のとおりです。

フラグ	役割
`--cpu-prof-dir`	役割出力先ディレクトリ(既定は `--diagnostic-dir` の値)
`--cpu-prof-name`	役割ファイル名。`${pid}` が置換される
`--cpu-prof-interval`	役割サンプリング間隔(マイクロ秒)。既定は1000

--cpu-prof 系のフラグは、v22.4.0とv20.16.0で安定版になりました。それより前のNodeでは実験的な扱いです。

短い処理だとサンプル数が足りず、上位の順位が実行ごとに入れ替わります。間隔を --cpu-prof-interval=200 のように縮めるか、処理を繰り返してから終了させると安定します。

なぜ丸ごと渡さず前処理するのか

.cpuprofile はJSONで、トップレベルのキーは startTime / endTime / nodes / samples / timeDeltas の5つでした(v20.18.0で取った出力)。

nodes は呼び出しツリーの各ノードです。callFrame に関数名・URL・行番号が入り、親子関係は children のid配列で表します
samples は各サンプル時点で実行中だったノードのid列です
timeDeltas は各サンプル間の経過マイクロ秒です

「どの関数で時間を使ったか」は、samples と timeDeltas を突き合わせて初めて出ます。nodes の hitCount を見る手もありますが、サンプル間隔が一定でないとずれるため、ここでは timeDeltas の合計を自己時間として扱います。

実運用のアプリでは、このJSONがメガバイト級になります。claude -p の標準入力は10MBが上限で、超えると明確なエラーとともに非ゼロの終了コードで止まります。10MB以内に収まっても、大半は読み取っても意味のないノードです。上位の数行に絞って渡すほうが、トークンも回答の焦点も節約できます。

jqで自己時間の上位を抜く

まず samples ごとの経過時間をノード単位で合計し、降順に並べます。

. as $p
| ([range(0; $p.samples|length)]
   | map({id: $p.samples[.], dt: $p.timeDeltas[.]})) as $s
| ($p.nodes
   | map({key:(.id|tostring), value:.callFrame})
   | from_entries) as $cf
| $s | group_by(.id)
| map({id: .[0].id, selfUs: (map(.dt)|add)})
| map(. + {
    fn: $cf[(.id|tostring)].functionName,
    url: ($cf[(.id|tostring)].url | sub("^file://.*/prof/";"")),
    line: ($cf[(.id|tostring)].lineNumber + 1)})
| sort_by(-.selfUs) | .[0:8]
| .[] | "\(.selfUs/1000|floor)ms\t\(.fn)\t\(.url):\(.line)"

lineNumber は0始まりなので、1を足してエディターの行番号に合わせます。このファイルを top.jq として保存し、jq -r -f top.jq prof/*.cpuprofile で実行します。

検証用に、6万行の配列を集計してソートする小さなスクリプトを --cpu-prof で計測した結果が次の表です。slugify-lite は node_modules に置いた自作の小さなパッケージです。

551ms		src/report.js:4
87ms	(garbage collector)	:0
47ms	slugify	node_modules/slugify-lite/index.js:1
45ms	aggregate	src/report.js:3
24ms		src/report.js:1
23ms	RegExp: [a-z0-9]	:0
12ms	sortRows	src/report.js:4
10ms	buildKey	src/report.js:2

1行目は関数名が空です。sortRows の中で .sort() に渡した無名のコンパレーターで、行番号がなければ何の関数か分かりません。関数名だけを渡すと原因を取り違えるので、url:line は必ず付けます。

node_modulesを呼び元のアプリ関数に畳む

上位の表を見ると、slugify の47msと RegExp の23msは、実際には buildKey が呼んだ時間です。このまま渡すと、Claude Codeは「自作の slugify を直す」方向に答えがちです。直せるのは自分のコードなので、依存パッケージの時間は呼び元に寄せます。

親ノードを順にたどり、URLが file:// で始まり node_modules を含まない最初のフレームに、サンプルの時間を加算します。

. as $p
| ($p.nodes
   | map({key:(.id|tostring), value:.}) | from_entries) as $n
| ($p.nodes
   | map(.id as $pid | (.children // [])[]
         | {key:(.|tostring), value:$pid})
   | from_entries) as $parent
| def app($id):
    $n[($id|tostring)].callFrame as $c
    | if ($c.url | test("^file://") and (test("node_modules")|not))
         or ($parent[($id|tostring)] == null)
      then $id else app($parent[($id|tostring)]) end;
  [range(0; $p.samples|length)
   | {id: app($p.samples[.]), dt: $p.timeDeltas[.]}]
| group_by(.id)
| map({id: .[0].id, us: (map(.dt)|add)})
| sort_by(-.us) | .[0:5]
| .[] | $n[(.id|tostring)].callFrame as $c
| "\(.us/1000|floor)ms\t\($c.functionName
    | if .=="" then "(anonymous)" else . end)\t\($c.url
    | sub("^file://.*/prof/";"")):\($c.lineNumber+1)"

同じプロファイルに適用すると、次の出力になりました。

551ms	(anonymous)	src/report.js:4
104ms	(root)	:0
83ms	buildKey	src/report.js:2
45ms	aggregate	src/report.js:3
24ms	(anonymous)	src/report.js:1

buildKey が83msになりました。畳む前の buildKey の10msに、slugify の47msと正規表現の23msを足した値に近い数字です。依存側に見えていた時間が、手を入れられるアプリ関数へ集まっています。

(root) の104msは、親をたどっても file:// の関数に行き着かなかった分です。この例ではガベージコレクションの時間が含まれていました。(root) の行は自分のコードの修正対象ではないので、依頼文の側で「この行は無視する」と書いておきます。

この畳み方は、node_modules を含まないURLをすべて「自分のコード」と見なします。バンドラーで1枚のJSにまとめたアプリや、node: で始まる組み込みモジュールを含む呼び出しでは、条件の test を実際のURLに合わせて直します。

累積時間の表も添えて、呼び出しの経路を見せる

自己時間の表は「どこで時間が消えたか」を示しますが、「どの入口から呼ばれたか」は示しません。上の例では、sortRows 自体の自己時間は12msです。原因は中のコンパレーターにあり、自己時間の表だけだと sortRows を見落としかねません。

そこで、サンプルごとに祖先ノードをすべてたどり、アプリ側のフレームへ時間を加算した累積時間の表も作ります。

. as $p
| ($p.nodes | map({key:(.id|tostring), value:.callFrame})
   | from_entries) as $cf
| ($p.nodes
   | map(.id as $pid | (.children // [])[]
         | {key:(.|tostring), value:$pid})
   | from_entries) as $parent
| def chain($id):
    $id, (($parent[($id|tostring)]) // empty | chain(.));
  [range(0; $p.samples|length)
   | {ids: [chain($p.samples[.])], dt: $p.timeDeltas[.]}
   | .dt as $dt | .ids[] | {id: ., dt: $dt}]
| group_by(.id) | map({id: .[0].id, us: (map(.dt)|add)})
| map(select($cf[(.id|tostring)].url | test("^file://")))
| sort_by(-.us) | .[0:5][]
| $cf[(.id|tostring)] as $c
| "\(.us/1000|floor)ms\t\($c.functionName
    | if .=="" then "(anonymous)" else . end)\t\($c.url
    | sub("^file://.*/prof/";"")):\($c.lineNumber+1)"

同じプロファイルでの出力は次のとおりです。

721ms	(anonymous)	src/report.js:1
564ms	sortRows	src/report.js:4
551ms	(anonymous)	src/report.js:4
129ms	aggregate	src/report.js:3
83ms	buildKey	src/report.js:2

1行目はモジュール全体を包む無名関数なので、全体の所要時間に近い数字です。累積時間は親が必ず子より大きくなるため、合計しても100%にはなりません。見るのは、sortRows(564ms)が自己時間では12msだったのに、累積では2位に上がるという差です。

2つの表の使い分けは次のとおりです。

渡す表	分かること	向いている質問
自己時間(畳み込みあり)	分かること手を入れる関数そのもの	向いている質問「どの行を直すか」
累積時間(アプリのみ)	分かること遅い処理の入口と経路	向いている質問「どの機能が重いか」

両方を渡す場合は、先頭に「1つ目が自己時間、2つ目が累積時間」と書き添えます。区別が付かないと、累積の数字を自己時間として読み違え、親関数ばかり直す提案になりかねません。

Claude Codeに渡して遅い関数を絞る

畳んだ表を標準入力で渡し、依頼文でどこを見るかを指定します。非対話モードの claude -p は標準入力を読めるので、パイプでそのまま渡せます。

jq -r -f fold.jq prof/*.cpuprofile | claude -p \
  "Node.jsのCPUプロファイルの自己時間上位です。\
node_modules分は呼び元に畳んであります。\
(root)の行は無視して、src/配下を読み、\
時間を使っている理由と直す候補を3つ以内で挙げて" \
  --allowedTools "Read"

--allowedTools に Read を指定すると、ファイルを読む許可の確認が出ません。診断だけなら編集権限は付けないほうが安全です。直させるときは、結果を見たうえで別の呼び出しで Edit を足します。

依頼文に入れておくと回答が散らばらない項目は次の3つです。

「表は自己時間の上位で、node_modules は呼び元に畳み済み」と前提を書く
見てほしいディレクトリを src/ のように限る
出力の形を「候補3つ以内、行番号つき」のように決める

--output-format json を付ければ、jq -r '.result' で回答の本文だけを取り出せます。CIで毎回プロファイルを取り、悪化した関数だけを通知する用途にも使えます。

生のプロファイルをClaude Codeに読ませない設定

パイプで表を渡しても、Claude Codeが作業中に prof/ の中身を自分で開くことがあります。メガバイト級のJSONを一度読むと、コンテキストの多くをそれだけで使います。プロファイルの置き場を Read の拒否ルールに入れておくと、ファイル系ツールからの読み取りを止められます。

{
  "permissions": {
    "deny": [
      "Read(./prof/**)"
    ]
  }
}

これを .claude/settings.json に置きます。Read(./secrets/**) のようなパス指定は、権限の説明にある書き方と同じ形です。拒否ルールが止めるのは、ファイル系ツールによる読み取りです。表はパイプで渡すので、この設定とは両立します。

あわせて CLAUDE.md に、プロファイル調査の約束事を数行書いておくと、毎回の依頼文が短くなります。

## プロファイル調査
- prof/ の .cpuprofile は直接開かない。jq で畳んだ表だけを根拠にする
- 表の (root) と (program) の行は修正対象にしない
- 提案には必ず src/ のファイル名と行番号を付ける
- 直したあとは npm run prof:top で測り直した結果を報告する

npm scriptにまとめて毎回同じ表を作る

jqコマンドは長いので、package.json のscriptにしておくと、取得から表の作成までが1コマンドになります。非対話モードをbuild scriptに組み込む書き方は、公式の lint:claude の例と同じ形です。

{
  "scripts": {
    "prof": "node --cpu-prof --cpu-prof-dir=./prof src/report.js",
    "prof:top": "npm run prof && jq -r -f tools/fold.jq prof/*.cpuprofile",
    "prof:ask": "npm run prof:top | claude -p \"上位の理由と直す候補を3つ以内で\" --allowedTools Read"
  }
}

古い .cpuprofile が prof/ に残っていると、prof/*.cpuprofile のワイルドカードが複数ファイルに展開されます。prof の先頭で rm -rf prof を実行するか、--cpu-prof-name で名前を固定してください。

常駐サーバーやワーカーを測るときの注意

--cpu-prof がプロファイルを書き出すのは、プロセスが終わる前です。バッチ処理のように自然に終わるスクリプトなら、そのまま prof/ にファイルが残ります。APIサーバーのような常駐プロセスは、負荷をかけたあとにシグナルなどで正常に終了させる運用にしないと、ファイルが残りません。

もうひとつ、出力ファイル名の既定値には ${tid} が入っています。worker_threads を使うアプリでは、スレッドごとにファイルが分かれる前提で見てください。prof/*.cpuprofile を丸ごとjqに渡すと、複数ファイルのJSONが連続して処理されます。ノードのidはファイル単位の値なので、集計は1ファイルずつ分けて実行するのが安全です。

その1ファイルを選ぶには、ls -S prof/*.cpuprofile | head -1 のようにサイズ順で先頭を取る方法があります。まずは最大のファイルを渡し、ワーカー側の時間が気になった時点で別のファイルを同じ手順に通します。

直したあとは同じ手順で測り直す

Claude Codeの提案は仮説にすぎません。実際に効いたかは、同じスクリプトで --cpu-prof を取り直し、同じjqに通した表で比べます。この例なら、コンパレーター内の JSON.stringify を毎回呼ぶ作りが551msの大半を占めると読めるので、キーを先に作ってからソートする直し方が候補になります。直したあとに無名関数の行が表の上位から落ちたかを確かめます。

比較するときは、次の点をそろえます。

入力データと件数を同じにする
実行は複数回行い、上位の順位が安定していることを見る
--cpu-prof-interval の値を変えない

プロファイルの関数名と行番号は、TypeScriptをトランスパイルした出力側のものです。ソースマップを経由していないと、src/ のTSファイルの行とはずれます。元のファイルを読ませたい場合は、tsc の出力先を依頼文に書いておきます。

同じ型の前処理は、HARファイルで失敗リクエストだけを抜く場面にも使えます。手順はHARファイルの解析記事にあります。Node自体の対応バージョンはClaude CodeとNode.jsの関係に整理してあります。

まとめ

.cpuprofile は「ノード」「サンプル」「経過時間」の3つを突き合わせて初めて自己時間になるため、生のまま渡す形式ではありません。jqで上位だけに絞り、node_modules を呼び元に畳んでから渡すと、Claude Codeの提案が自分で直せる関数に向きます。

次に自分のプロジェクトで試すなら、まず top.jq で上位を見て、依存パッケージが目立つときだけ fold.jq に切り替える順がやりやすいはずです。

Claude CodeでNodeのcpuprofileを解析し遅い関数を絞る

プロファイルを取る — --cpu-profの使い方

なぜ丸ごと渡さず前処理するのか

jqで自己時間の上位を抜く

node_modulesを呼び元のアプリ関数に畳む

累積時間の表も添えて、呼び出しの経路を見せる

Claude Codeに渡して遅い関数を絞る

生のプロファイルをClaude Codeに読ませない設定

npm scriptにまとめて毎回同じ表を作る

常駐サーバーやワーカーを測るときの注意

直したあとは同じ手順で測り直す

まとめ

参照した一次ソース

Claude Codeとは — できること・料金・始め方と使い方の全体像

Claude Codeでソースマップからスタックトレースを元のコードに戻す

Claude Codeでsemverの破壊的変更を判定 — api-extractor差分を読ませる

Claude CodeでPythonのメモリリークを特定する — tracemallocとmemray

Claude CodeとplutoでKubernetesの非推奨APIを移行する手順

Claude CodeでnoImplicitAnyを有効にして暗黙のanyを段階的に潰す

プロファイルを取る — --cpu-profの使い方

なぜ丸ごと渡さず前処理するのか

jqで自己時間の上位を抜く

node_modulesを呼び元のアプリ関数に畳む

累積時間の表も添えて、呼び出しの経路を見せる

Claude Codeに渡して遅い関数を絞る

生のプロファイルをClaude Codeに読ませない設定

npm scriptにまとめて毎回同じ表を作る

常駐サーバーやワーカーを測るときの注意

直したあとは同じ手順で測り直す

まとめ

参照した一次ソース

関連する記事

Claude Codeとは — できること・料金・始め方と使い方の全体像

Claude Codeでソースマップからスタックトレースを元のコードに戻す

Claude Codeでsemverの破壊的変更を判定 — api-extractor差分を読ませる

Claude CodeでPythonのメモリリークを特定する — tracemallocとmemray

Claude CodeとplutoでKubernetesの非推奨APIを移行する手順

Claude CodeでnoImplicitAnyを有効にして暗黙のanyを段階的に潰す