タグ: パフォーマンス

サイトの表示が遅い、という話から始まった作業です。結果として最初の1バイトが返るまでの時間は約1.7秒から0.03秒になりました。50倍以上です。

ただしこの記事の本題は、その数字ではありません。速くしたことで、別の場所が壊れたという話です。デプロイが失敗し、画像がぼやけ、一覧が読めなくなりました。どれも高速化そのものが引き起こしたものです。

まず測る

「遅い気がする」から始まる改善は、たいてい見当違いの場所を触って終わります。数字が無いと、直したかどうかも判断できません。

使ったのは curl だけです。

curl -s -o /dev/null \
  -w "合計:%{time_total}s  最初の1バイト:%{time_starttransfer}s\n" \
  https://www.kisaku.site/

見るべきは time_starttransfer、最初の1バイトが返るまでの時間です。体感の遅さはほぼここで決まります。この値が大きいと、画面が真っ白なまま待たされます。逆にここが小さければ、多少ファイルが大きくても「表示され始めた」感覚は得られます。

フロントとCMSの両方を測りました。

3回繰り返しているのには理由があります。1回目は暗号化通信の確立が含まれるので必ず遅くなります。1回だけ測って「3.2秒だ」と判断すると、実力値を1.5秒以上見誤ります。

この表から読み取れることは明確でした。フロントの実力値が約1.7秒、CMSが約2.3秒。つまりフロントの待ち時間は、ほぼそのままCMSの応答時間です。Vercel自体の処理はごくわずかで、大半は共用サーバーのWordPressがPHPとMySQLを動かし終わるのを待っている時間でした。

犯人は自分が書いた3文字だった

原因はGraphQLクライアントのこの指定でした。

export const graphqlClient = new GraphQLClient(endpoint, {
  fetch: (input, init) =>
    fetch(input, {
      ...init,
      cache: "no-store",   // ← これ
    }),
});

cache: "no-store" は「結果を一切キャッシュしない」という指定です。Next.jsはこれを見つけると、そのページを事前に生成できないと判断します。訪問者が来るたびに、その場でCMSへ問い合わせて組み立てる方式になります。

ビルド結果にも、はっきり出ていました。

Route (app)
┌ ƒ /
├ ƒ /blog
├ ƒ /blog/[slug]
├ ƒ /profile
├ ƒ /projects
└ ƒ /skills

ƒ  (Dynamic)  server-rendered on demand

全ページに ƒ の印。すべてが「訪問時に組み立てる」状態でした。この情報は毎回のビルドで表示されていたのに、意味を確認していませんでした。

この指定を入れたのは「記事を公開したらすぐ反映されるように」という意図でした。狙い自体は正しかったのですが、その代償として全ページが毎回CMS待ちになることを見落としていました。

キャッシュは、思ったところに効かない

直し方は単純に見えました。no-store を外して、代わりに「5分間キャッシュする」と書けばいい。

ところが、ここで一段深い問題に当たりました。

気づかずに進めていたら、「設定したのに速くならない」という状態で長く悩んだはずです。

解決には unstable_cache を使いました。これは fetch に限らず、関数の戻り値そのものをキャッシュできる仕組みです。

import { unstable_cache } from "next/cache";

export const getPosts = unstable_cache(
  async () => {
    const data = await graphqlClient.request(GET_POSTS);
    return data.posts?.nodes ?? [];
  },
  ["posts"],                                    // キャッシュキーの一部
  { revalidate: 300, tags: ["wordpress"] },     // 300秒保持
);

引数も自動的にキャッシュキーに含まれるので、getPostBySlug("a") と getPostBySlug("b") は別物として扱われます。

名前に unstable_ と付いていますが、これは「将来APIが変わるかもしれない」という意味で、動作が不安定という意味ではありません。

tags を付けているのは将来のためです。WordPressで記事を公開したときにVercelへ通知を送る仕組みを足せば、5分待たずに反映できます。今は使っていませんが、後から足せるように印だけ置いています。

ページ自体も事前に作る

あわせて、各ページに1行足しました。

export const revalidate = 300;

これでNext.jsはページを事前に生成し、300秒ごとに裏側で作り直します。訪問者はCMSの応答を待ちません。

ただし記事ページは、これだけでは足りませんでした。/blog/[slug] は「どんなスラッグが存在するか」をNext.jsが知らないため、事前に作りようがないからです。そこで一覧を教えます。

export async function generateStaticParams() {
  const posts = await getPosts();

  return posts
    .map((post) => post.slug)
    .filter((slug): slug is string => Boolean(slug))
    .map((slug) => ({ slug }));
}

結果

ブログ一覧だけが動的なままです。?category= で内容が変わるページは事前に作れません。それでも1.7秒から242msになりました。CMSへの問い合わせが消え、残っているのは画面を組み立てる時間だけだからです。

自分の計測を、自分で壊した

ここで恥ずかしい失敗をしました。

デプロイ後に測り直したところ、全ページが1.4〜2.6秒。しかも配信網の状態を示すヘッダが、どれも MISS（キャッシュに無い）でした。一瞬「効いていないのか」と思いました。

原因は私が測り方に入れたキャッシュ除けのパラメータでした。

// 毎回ちがうURLになる
await fetch('/blog?nc=' + Date.now());

ブラウザのキャッシュを避けるつもりで付けたものですが、配信網から見れば毎回まったく新しいURLです。キャッシュに無いのは当たり前でした。パラメータを外して測り直したのが、上の表の数字です。

教訓としては、測定の道具が測定対象に影響していないかを疑うということになります。結果がおかしいとき、まずシステムを疑いたくなりますが、測り方のほうが壊れていることは珍しくありません。

速くした代償で、デプロイが止まった

ここからが本題です。

サムネイル画像を記事に紐づけ、一覧のクエリに画像の情報を足して本番に送ったところ、デプロイが失敗しました。

GraphQL Error (Code: 500)
<title>500 Internal Server Error</title>
<p>Please contact the server administrator,
 webmaster@gmoserver.jp ...</p>

> Build error occurred
Error: Failed to collect page data for /blog/[slug]

エラーの中身は、共用サーバーが返したApacheの標準エラーページでした。WordPressが処理しきれず、サーバー側で落ちていました。

ここで重要なのは、なぜ今回から落ちるようになったのかです。

以前は全ページが動的だったので、ビルド中にCMSへ問い合わせることはありませんでした。CMSが500を返しても、影響は「その1回の表示が失敗する」だけです。

事前生成に切り替えたことで、ビルド時にCMSへ問い合わせる経路が生まれました。そこへ画像の情報を足したため処理が重くなり、共用サーバーが応答しきれなくなりました。

2つの対策

ひとつは、5xxエラーのときに自動で投げ直すことです。

const MAX_ATTEMPTS = 3;
const RETRY_DELAY_MS = [1000, 3000];   // 1秒後、3秒後

async function fetchWithRetry(input, init) {
  for (let attempt = 0; attempt < MAX_ATTEMPTS; attempt++) {
    if (attempt > 0) await wait(RETRY_DELAY_MS[attempt - 1]);

    const response = await fetch(input, init);

    // 5xx はサーバー側の一時的な不調の可能性が高いので投げ直す。
    // 4xx はこちらの要求が間違っているので、何度試しても同じ。
    if (response.status >= 500 && attempt < MAX_ATTEMPTS - 1) continue;

    return response;
  }
}

すぐ投げ直さず間隔を空けているのは、混んでいる相手にすぐ投げ直しても意味がないからです。むしろ負荷を増やします。また、再試行するのは5xxだけにしました。4xxを何度試しても結果は変わらず、ただの遅延になります。

もうひとつは、事前生成の失敗でビルドを止めないことです。

export async function generateStaticParams() {
  try {
    const posts = await getPosts();
    return posts.map(/* ... */);
  } catch (error) {
    console.warn("記事一覧を取得できなかったため、事前生成をスキップします", error);
    return [];   // 空を返す = 訪問時に生成する方式へ切り替わる
  }
}

判断の根拠は、この処理の役割が「どのページを先に作っておくか」を決めることでしかないという点です。失敗しても致命的ではありません。最初の1人が待つ代わりに、デプロイは通ります。

なお、デプロイが失敗しても本番サイトは無事でした。Vercelは失敗時に切り替えを行わず、前回成功した内容を配信し続けます。失敗したデプロイは「何も起きない」で済むという設計です。

画像を足したら、今度は画像が壊れた

デプロイが通り、サムネイルが表示されるようになりました。しかし画面を見ると、2つ問題がありました。

1. 画像が大きすぎた

ブログ一覧は1列なので、カード幅いっぱいに1200×630の画像を置くと高さが454pxになり、1件で画面の半分近くを占めていました。

一覧の役割は「複数の記事を見比べて選ぶ」ことです。1件ずつしか見えない一覧は、一覧として機能していません。画像を左、文字を右の横並びに変え、画像の幅を256pxに収めました。

2. 画像がぼやけていた

調べると、配信されていた画像は450px幅なのに、864pxに引き伸ばして表示されていました。原因は自分が書いた指定です。

<Image
  src={...}
  fill
  sizes="(min-width: 768px) 720px, 100vw"   // 実際は864pxだった
/>

sizes は「この画像は画面上でどれくらいの幅で表示されるか」をブラウザに伝えるものです。ブラウザはこの申告を信じて、取ってくる画像の大きさを決めます。申告が小さすぎれば拡大されてぼやけ、大きすぎれば無駄に重い画像を取ります。

横並びに変更して表示幅が256pxで確定したので、申告もそれに合わせました。実寸と申告が一致していることが重要です。

今回の学び

まず、測ってから直す。今回は最初に測ったおかげで、原因が「Vercelの処理」ではなく「CMSの応答待ち」だと即座に分かりました。測らずに始めていたら、画像の圧縮やJavaScriptの削減といった、効果のない場所を触っていたはずです。

次に、キャッシュは「効いているつもり」が最も危ない。POSTには fetch キャッシュが効かない、という一点を知らなければ、設定したのに変わらない状態で長く悩んでいました。仕組みがどこに効いてどこに効かないかは、思い込みではなく確認する必要があります。

そして、最適化は依存関係を増やす。事前生成は「ビルド時にデータが取れる」という前提の上に成り立っています。前提が増えれば壊れる条件も増えます。速くするときは、同時に「壊れたときにどうなるか」を決めておくべきでした。今回は壊れてから決めることになりました。

最後に、ブラウザに嘘をつかない。sizes の件は、こちらの申告をブラウザが信じて動く仕組みでした。人間が見て分かる間違いではなく、画面がぼやけるという形でしか現れません。自動で最適化してくれる仕組みほど、渡す情報の正しさが結果を決めます。