Windows Defenderの除外でNuxtのビルドは半分になったが、記事のプリレンダーは16%しか縮まなかった

Macで4分40秒で終わるデプロイが、Windowsでは20分を超える。 前の晩に1回目を測ったときは、Windows Defenderの除外を入れないまま回した。 除外の投入には管理者権限が要るのに、その場でUACを出せなかったからだ。 条件として残っていたのはそこだけだったので、除外を入れればMacの数字に近づくと踏んでいた。

「Defender除外を入れてrun2を測る」というタスクは、そのまま積み残しになっていた。 これを引き出して、計画書ごと読ませるところから始めた。

条件を1つだけ変えて回す

比べる相手は前日の21分44秒である。 変える要素を1つに絞らないと、あとで何が効いたのか言えなくなる。

除外を投入するために、Start-Process powershell -Verb RunAs でUACを出させた。 こちらは「はい」を押すだけで済む。 入れたのはリポジトリのパスと、node.exe と pnpm.exe の2プロセスである。 最初は pnpm.cmd を指定しかけたが、これは実行イメージではないので除外にならない。 miseが置いている pnpm.exe のほうに読み替えさせた。

メモリは開始前に空きが5.3GBまで落ちていた。 古いchrome-devtools MCPを3本止めて7.8GBに戻した（run1は8.2GB）。 devサーバー2本は別セッションが使っていたので残した。 ビルドキャッシュも前回と同じく消してから始めた。

段階別に前日と並べる

サーバービルドが94.5秒で抜けた通知を見た時点では、勝ったと思った。 プリレンダーの進みも1秒あたり36ルートで、run1平均の17ルートのおよそ倍で流れていた。

そのままプリレンダーの完了を待って、7,831ルートで383.4秒と出た。 run1が454.4秒だから、16%しか縮んでいない。 ビルドが2倍速になった横で、いちばん重い工程だけが動かなかった。

どのルートが縮んで、どのルートが縮まなかったか

ルート種別ごとにrun1とrun2を並べさせると、境界がはっきり出た。

Defenderが効いていたのは、JSチャンクを次々に開くVueページと、distの1万4千ファイルを読み歩く検証スクリプトだった。 検証スクリプトが5倍から10倍まで速くなったのはそのためで、合計を47%押し下げたのも主にここである。

一方、記事は1.01でぴくりとも動いていない。 記事1,764本はプリレンダー総コストの6割を占める。 いちばん太い6割を素通りしたまま、合計だけが半分になった。

Defenderは主犯の一人ではあった。 ただし、単独犯ではなかった。

並列数はいくつで走っていたのか

ついでに並列数を確認させたら、Nuxtがプリレンダーの同時実行数にCPUスレッド数の4倍を入れていた。 この機は16スレッドなので64、Macは72になる。

6月に「concurrency: 8 にしたら遅くなった」と書いたまま放ってあった件は、これで説明がつく。 Nitro単体の既定である1から8へ増やしたつもりでいたが、実際には64から8へ減らしていた。 自分で書いた過去の記述が、2か月遅れで逆向きの意味になった。

1記事あたりのSSRだけを測るハーネス

11分かかる計測を1回ずつ回して当てずっぽうを続けても進まない。 プリレンダー用バンドルがexportしている localFetch を直接叩いて、記事1本あたりのSSR時間だけを取るハーネスを書かせた。

cd apps/web
NODE_ENV=production node scripts/bench-prerender-render.mjs --sample 300 --seed 11

シードを固定してあるので、両方の機で同じ記事集合を引ける。 NODE_ENV=production を付け忘れるとVueがdevビルドで動き、2倍遅い数字が出る。 付け忘れたときは警告を出させた。

Windowsの実測は、300本の初回描画で平均69.9ms、p50が65ms、p90が94msだった。 同じ40本を5周させると27.8msまで落ちる。 キャッシュとJITが効くので、比較は必ず初回描画で揃える。

CPUプロファイルの内訳は、SQLiteのクエリが19.8%（1記事あたり約6ms）、記事ページのコードが12.3%、vue-routerが9.7%と続いた。 リクエストごとに全ページぶんのルートを組み立て直しているのが9.7%の中身である。 GCは4.7%だった。 --max-semi-space-size を64にすると69.9msが66.3msになり、128では変わらなかった。 GCの調整では決着しない。

残りの5倍が何なのかは、まだ言えない

Windowsの素の1記事SSRが70msだと分かった。 足りないのはMac側の同じ数字である。

Macが15msなら、残る5倍はJS実行速度そのもので、設定では詰められない。 35msなら差の半分は別の要因になり、64並列下のメモリ圧を疑う余地が残る。 翌日期限でMac側の計測タスクを登録して、この日はここで止めた。

ログに並んでいた fatal 50件の正体

run1のログに並んでいた [fatal] 50件は、速度とは別の話だった。 30件は決算ページが相互リンクを無条件に張っていたせいで、JSONの無い30銘柄でリンク切れになっていた。 残り20件はdev限定ページが本番で404を返す仕様どおりの出力で、こちらはノイズである。

判定関数を足してリンクを条件付きにさせ、テストを4件書かせた。 devのSSRを叩かせて、JSONのある銘柄ではリンクが1件、無い銘柄では0件になることまで確認した。

run1が終了コード1で落ちていた理由も判明した。 別セッションがgenerateの実行中に記事を1本足していた。 その記事はビルドがcontentを読んだ時点には無く、末尾の検証の時点にはあった。 記事のコミット時刻はrun1終了の7分後だった。 generate中にcontentを触るセッションがあると再現する、というだけの話である。

積み残しをディスクとAPIで確かめる

セッションの締めに、積み残しが無いかとタスク管理が更新済みかを聞かれた。 記憶で答えず、実物を見させた。

計画書に、run1で実測済みなのに未チェックのまま残っていた項目が3つ見つかった。 その場で閉じさせて、タスクのほうはAPIで取り直して更新済みを確認した。 コミットは3件に分けてpushさせた（学習ゲートはスキップ指定）。

夕方: 全リポジトリのプッシュ漏れを洗う

別件で、git_repo直下のリポジトリを全部見てプッシュ漏れを潰す作業も投げた。 走査対象は約170リポジトリ、直近1か月に活動があったのは34、そのうち未反映が18あった。 これを52コミットに分けてpushさせた。

粒度だけ注文して、分け方は任せた。 機能追加とメモ更新が混ざっているリポジトリでは2件に、変更の種類が4種類あるものは4件に割れて上がってきた。 判断が要ったのは、未コミットのまま放置されていたファイルの扱いである。 ファイルの最終更新日を見させて、今月の変更と何か月も前のゴミを分けさせた。 37MBぶんのランタイムログのように、そもそも追跡させたくないものも混ざっていた。

別のセッションが動いている2リポジトリには触らせず、状態の報告だけに留めさせた。

認証情報が消えた

最後の1リポジトリで止まった。 originのURLに古い認証情報が https://ユーザー名@github.com/... の形で埋め込まれていた。 それに気づかないままfetchして、401が返った。 gitは401を受けると資格情報ヘルパーに削除を投げる。 Credential Managerに保存してあったGitHubの資格情報は、そのタイミングで消えていた。 消したのがこの削除だという確証まではないが、順序としては合う。

以後、全リポジトリでpushとfetchがGUIログインを待って止まるようになった。 gh auth status は正常でトークンも生きているのに、gitからは見えない。 その場はコマンド単位で gh をヘルパーに指定して通し、作業自体は完遂させた。

恒久的な復旧には、こちらが一度ブラウザで再ログインする操作が要る。 今日はそこまでやっていないので、issueに未解決で残した。 リモートURLに ユーザー名@ が埋まっているリポジトリでhttps操作をしない、というのが教訓になった。

明日以降に残っていること

• Macで同じハーネスを打って、1記事あたりのSSR時間を並べる
• 次のgenerateで [fatal] が20件（dev限定ページのみ）に減っているか確認する
• Credential Managerに資格情報を入れ直す
• 記事SSRの2割を占めるSQLiteのコネクタを差し替えた場合の差を測る