Apollo Client と SSR の罠その1 - パフォーマンス改善編

Wantedly でバックエンドエンジニアをしている @izumin5210 です。

この記事は GraphQL Advent Calendar 2020 の11日目の記事として書かれました。が、7割くらいは SSR についての議論のこり3割くらいが Apollo Client の話です。

最近、Apollo Client と SSR(Server Side Rendering) を利用した Web アプリケーションのパフォーマンス改善に取り組みました。この記事では「パフォーマンスの問題にどう立ち向かったか」および「そもそも問題を起こさない構造にするために何ができるか・何をすべきでないか」の考察をしていきます。

TL;DR

パフォーマンス改善は計測・可視化から
ライブラリが用意してくれているフック機構を上手に使って計測していこう
renderToStringWithData では、renderToString 中に useQuery が呼び出されると renderToString が再度実行されてしまう
- `useQuery` 時に「このデータは SSR で必要なのか」を考え、可能であればスキップしよう

パフォーマンス改善の取り組み

開発中のプロダクトで、ページの表示が異様に遅いという問題がありました。リニューアルプロジェクトだったのですが、リニューアル前のものに比べても体感で表示速度に倍くらいの開きがあります。ユーザ体験の観点からも許容できる遅さではなかったので、調査を開始しました。

前提: 利用している技術スタック

登場人物はざっくり以下の3人 + αです。

React, Apollo Client で実装された SPA
Express で実装された SSR サーバ
GraphQL を喋る BFF
gRPC を喋るバックエンドサーバ群

SSR サーバでの render 時に React component 内から BFF に対して GraphQL のクエリを投げられ、BFF は後ろのサーバに gRPC で必要な情報を取りに行きます。

まずは計測・可視化

速度的な意味で「パフォーマンス改善」というと指すものが広いです。バックエンド的に改善する指標としては throughput (req/sec) や latency (sec/req) などが考えられるでしょうか。取り組み開始時点では「そもそも単一のリクエストですら遅い」状態であったため、latency に焦点を当てていきました。

何が起きてるかわからないと何を直せばいいかわかりません。「推測するな、計測せよ」という格言のとおり、最初に計測・可視化をすることで何がネックかを見極める必要があります。とりあえずさっと現状把握するために、Wantedly の他のバックエンドでも利用している New Relic を仕込んでいきます。

HTTP サーバ自体には New Relic Agent がセットアップされていましたが、具体的に「何に時間を使っているか」は可視化できていませんでした。たとえば「HTTP リクエストが飛んでる回数・かかった時間は取れてるが、そのリクエストが何なのかはわからない」といった状況です。

通信の可視化

とりあえずは全体をさくっと把握するために、最もネックになりやすい通信まわりの可視化をしていきました。それぞれのクエリのレイテンシや実行順がわかれば、ネックになっている API が何かを特定する助けになります。Apollo Client には Apollo Link といデータ取得フローに介入する仕組みがあるので、ここで New Relic に情報を送ると良さそうです。
（注: この実現したいことに対して Apollo Link は若干不適格かもしれませんが、ここでは高速な現状理解を優先し最もお手軽な方法として採用しています）

// newrelic-node をブラウザ上で require するとエラーになるので注意
const newrelicLink = new ApolloLink((op, f) =>
  newrelic.startSegment(op.operationName, true, () => f(op))
);

上記の newrelicLink を Apollo Client のコンストラクタに渡すことで、New Relic 上で「どのクエリにどれくらいかかったか」がわかるようになります。

New Relic は閾値を超えて遅い個別トランザクションの詳細を見る機能があり、そこで実際にどのクエリにどれくらい時間をかけているかが可視化されます。以下の画像が実際の Transaction detail です。
（オレンジの線は後から書き込んだものです。書き込み前の画像残ってなかった。）

（単一のリクエストの振る舞いを観察したい場合、OpenCensus + Cloud Trace などによる分散トレーシングのほうが有効な場合もあるかもしれません。）

上記の Transaction detail をぱっと眺めるだけでいくつかわかることがあります。

遅い！！！！
1ページの描画にクエリが5回も投げられている
- 本当に SSR で全部必要なのか？
- 1回のリクエストにまとめられないのか？
なぜか1個だけ普通の JSON / HTTP のリクエストがある
- 本当に SSR で必要なのか？
謎の空間（オレンジの矢印をひいてるところ）
- なんだ？
すごい遅いクエリがある
- これは BFF 側の transaction trace などを見つつ、バックエンドの方を改善していけば良い

飛んでるリクエストの回数が多すぎる問題に関しては、単純に取捨選択と統合を考えると良さそうです。不要なリクエストが減り、依存関係がないものが並列化できるだけでかなり良くなりそうです。

問題は謎のオレンジの領域。ぱっと見で50% くらいの時間を消費しています。これの正体を見極めない限り我々の勝利は無いでしょう。

謎の領域の可視化

さて、このオレンジの領域は何なんでしょうか。上記 Transactions detail の画像から、前後の Segment は GraphQL のクエリであることがわかります。ということは、renderToString の内部で何かが起きている？ SSR サーバの実装を見てみると、react-dom の renderToString ではなく apollo-client の renderToStringWithData が使われていました。この関数自体は Apollo Client の公式ドキュメントで、SSR をするときに使うものとして紹介されています。

Server-side rendering

Apollo provides two techniques to allow your applications to load quickly, avoiding unnecessary delays to users: Store rehydration, which allows your initial set of queries to return data immediately without a server roundtrip. Server side rendering, whic

https://www.apollographql.com/docs/react/performance/server-side-rendering/

renderToStringWithData の実装は以下のようになっています。getMarkupFromTree という別の関数を呼び出しているだけですね。ただ、よく見ると react-dom の renderToString 関数自体を getMarkupFromTree に渡していることがわかります。

// https://github.com/apollographql/apollo-client/blob/v3.3.5/src/react/ssr/renderToStringWithData.ts#L4-L11

export function renderToStringWithData(
component: ReactElement<any>
): Promise<string> {
return getMarkupFromTree({
tree: component,
renderFunction: require('react-dom/server').renderToString
});
}

renderToString を別の実装に差し替えられる、ということは renderToString の wrapper を作って計測コードを仕込めば、謎のオレンジの領域でなにがおきているかがわかるかもしれません。例のごとく New Relic の計測コードを仕込んでいきましょう。

const renderTtoStringWithNewRelic: typeof renderToString = (el) => {
  return newrelic.startSegment("renderToString", true, () => renderToString(el));
};

// const body = await renderToStringWithData(<App />)
const body = await getMarkupFromTree({
  tree: <App />,
  renderFunction: renderToStringWithNewRelic,
});

これで、全体の中で renderToString にどれくらいの時間を使っているかが可視化できるはずです。このコードをデプロイした後に New Relic で Transaction detail を見てみるとこんな感じでした。

すごい重い renderToString が2回も実行されていますね？このつらい感じの箇所をちょっとだけ詳しく見てみます。

みたところ、なにかクエリが投げられているようです。もしかして、全部 render した後にクエリが投げられ、それによって renderToString をやり直している…？

何が起きているかが見えてきました。せっかくなので Apollo Client と renderToStringWithData が何をしているかをもうちょっと潜って理解してみましょう。

renderToStringWithData と useQuery の内部実装

まずは renderToStringWithData 。といっても、前節で getMarkupFromTree を呼んでいるだけだったので、そちらを見てみましょう。

// https://github.com/apollographql/apollo-client/blob/v3.3.5/src/react/ssr/getDataFromTree.ts
// 元のコメントを消して、日本語で解説コメントを足しています

export function getMarkupFromTree({
tree,
context = {},
renderFunction = require('react-dom/server').renderToStaticMarkup
}: GetMarkupFromTreeOptions): Promise<string> {
const renderPromises = new RenderPromises();

function process(): Promise<string> {
const ApolloContext = getApolloContext();

return new Promise<string>(resolve => {
// ApolloContext.Provider をルートにして React Element をつくっている
// 第2引数が ApolloContext.Provider にわたす props
// 第3引数が ApolloContext.Provider の children で、ここにユーザのコンポーネントが入っている
const element = React.createElement(
ApolloContext.Provider,
{ value: { ...context, renderPromises }},
tree,
);
// renderFunction は大体のケースで renderToString
// renderToString の結果を Promise を解決する
resolve(renderFunction(element));
}).then(html => {
// renderToString が完了後、renderPromises が空でなければ
// consumeAndAwaitPromises を実行後、再度 process 関数を実行する
// renderPromises が空になっていれば HTML を返して終了
return renderPromises.hasPromises()
? renderPromises.consumeAndAwaitPromises().then(process)
: html;
});
}

return Promise.resolve().then(process);
}

Promise を交えた再帰チックなコードで難しいですが、一言でいうと「renderPromises が空になるまで renderToString をやり直し続ける」です。ヤバそうですね。consumeAndAwaitPromises の方はほんとに Promise たちを consume して await してるだけ（厳密にはもうちょっとなにかしてるけど、今追いたい内容ではない）なので、つぎは「どういうときに renderPromises が増えるのか」を追っていきましょう。

なんとなく察すると、renderPromises は useQuery の内部で増えそうな気がしますね？ useQuery に潜っていきます。

// https://github.com/apollographql/apollo-client/blob/v3.3.5/src/react/hooks/useQuery.ts#L8-L16

export function useQuery<TData = any, TVariables = OperationVariables>(
  query: DocumentNode | TypedDocumentNode<TData, TVariables>,
  options?: QueryHookOptions<TData, TVariables>
) {
  return useBaseQuery<TData, TVariables>(query, options, false) as QueryResult<
    TData,
    TVariables
  >;
}

useBaseQuery を呼んでいるだけでした。そちらを見てみましょう。長いので SSR に関係しそうなところだけピックアップします。

// https://github.com/apollographql/apollo-client/blob/v3.3.5/src/react/hooks/utils/useBaseQuery.ts#L16-L96

export function useBaseQuery<TData = any, TVariables = OperationVariables>(
  query: DocumentNode | TypedDocumentNode<TData, TVariables>,
  options?: QueryHookOptions<TData, TVariables>,
  lazy = false
) {
  const context = useContext(getApolloContext());
  const [tick, forceUpdate] = useReducer(x => x + 1, 0);
  const updatedOptions = options ? { ...options, query } : { query };

  const queryDataRef = useRef<QueryData<TData, TVariables>>();
  const queryData =
    queryDataRef.current ||
    new QueryData<TData, TVariables>({
      options: updatedOptions as QueryDataOptions<TData, TVariables>,
      context,
      onNewData() {
        // いろいろしている
      }
    });

  // いろいろしている

  const result = useDeepMemo(
    () => (lazy ? queryData.executeLazy() : queryData.execute()),
    memo
  );

  // いろいろしている

  return result;
}

QueryData というオブジェクトを作り、それを execute() しています。execute() 、いかにもという感じがしますね。見てみましょう。

// https://github.com/apollographql/apollo-client/blob/v3.3.5/src/react/data/QueryData.ts#L60-L75

public execute(): QueryResult<TData, TVariables> {
this.refreshClient();

const { skip, query } = this.getOptions();
if (skip || query !== this.previous.query) {
this.removeQuerySubscription();
this.removeObservable(!skip);
this.previous.query = query;
}

this.updateObservableQuery();

if (this.isMounted) this.startQuerySubscription();

return this.getExecuteSsrResult() || this.getExecuteResult();
}

Observable なんとかも気になりますが、最後に getExecuteSsrResult というこれまたいかにもという感じの関数が呼ばれています。こちらを見てみましょう。

// https://github.com/apollographql/apollo-client/blob/v3.3.5/src/react/data/QueryData.ts#L154-L186

private getExecuteSsrResult() {
const { ssr, skip } = this.getOptions();
const ssrDisabled = ssr === false || skip;
const fetchDisabled = this.refreshClient().client.disableNetworkFetches;

const ssrLoading = {
// いろいろ
} as QueryResult<TData, TVariables>;

// If SSR has been explicitly disabled, and this function has been called
// on the server side, return the default loading state.
if (ssrDisabled && (this.ssrInitiated() || fetchDisabled)) {
this.previous.result = ssrLoading;
return ssrLoading;
}

let result;
if (this.ssrInitiated()) {
result =
this.context.renderPromises!.addQueryPromise(
this,
this.getQueryResult
) || ssrLoading;
}

return result;
}

最後、renderPromises!.addQueryPromise(...) という関数が呼ばれていますね！これで、「useQuery を実行すると renderPromises が追加される」ということが実装レベルで裏付けられました。

ここまでで renderToStringWithData の挙動をまとめると、

1️⃣ `renderToString` が実行される
2️⃣ rendering 中に `useQuery` が呼ばれると、そのクエリが `renderPromises` に追加される
- このとき、クエリはまだ実行されない
3️⃣ `renderToString` 完了後、`renderPromises` に待ちクエリが存在していれば、それをすべて解決する
4️⃣ `renderPromises` をすべて解決すると 1️⃣ に戻る（`renderToString` を再実行する）
- `renderPromises` で解決したクエリの結果は Apollo Client のキャッシュにあるので、`renderToString` 内ではクエリ実行されない

という感じで、未解決の useQuery がなくなるまで renderToString を実行していきます。当たり前ですが、クエリの重要性や renderToString の深さに関わらず再実行を繰り返します。大変ですね！

この問題の対処はかんたんで、そのクエリで取得したいデータの重要さ（コンテンツの描画に不可欠なのか etc.）を考えて、可能であれば SSR ではスキップしてしまうのがいいでしょう。さっき見た getExecuteSsrResult でもシレッと出ていますが、 ssr オプションや skip オプションを渡すことで renderPromises への追加を止めることができます。

（ちなみに、自分がこのコードを最初に読んだときは skip: true しても renderPromises に追加されてしまっていました。その問題自体は apoll-client に PR を出したらマージしてもらえました。褒めてほしい。）

あとは、必要なデータはなるべく1回のクエリで取得してしまうのもいいですね！

実際に「コンポーネントツリーの端の useQuery をスキップする」「レンダリングするコンポーネントを減らす」をいくつか行なった結果がこんな感じです。さっきのより3倍くらい早くなっていますね。あとは「普通に API が遅いのでなんとかする」「renderToString を速くできないか試す」を繰り返していくことになるんじゃないでしょうか。最後はキャッシュを効かせたり CDN に乗せたりといった最後の切り札はしばらく温存できそうです。

まとめ: レイテンシ改善のためのアクションプラン

ここまでの調査から、だいたい以下のような順で取り組んでいけばボトルネックを上から潰していくと良さそうだとわかりました。

1️⃣ renderToString の回数を減らすために、SSR で実行されるクエリの数を減らす
- 不要なデータを取捨選択する
- 依存関係のないクエリは1回にまとめる（もしくは依存関係がなくなるように再設計する）
2️⃣ renderToString の対象になるコンポーネントを減らせないか検討する
- たとえばファーストビューに不要なコンポーネントは描画しなくていいはず
- コンポーネントを減らせれば、それにあわせて SSR で実行するクエリも小さくできる可能性がある
- Node.js の Inspector を有効化し Chrome DevTools 等で CPU 利用が多いコンポーネントを探していくのも有効です
3️⃣ バックエンドの API の高速化

1️⃣ と2️⃣ がある程度解決すれば、あとは従来どおり ISUCON 的なチューニングを進めていくことが可能になるでしょう。実際には 2️⃣ と 3️⃣ のどちらがボトルネックなのかは移り変わっていくはずなので、ある程度改善サイクルを回すことになるでしょう。

さて、最初にこんなことを書きました。

「そもそも問題を起こさない構造にするために何ができるか・何をすべきでないか」の考察をしていきます

この話を書き出すと記事が長くなりすぎたので、来週改めて公開することにしました。「Next.js をつかえばいいじゃん！？」「SSR じゃなくて ISR(Incremental Static Regeneration) 使おうよ！」「そもそも useQuery の使い方はどうなの？」みたいな議論が気になった方は、来週を楽しみにしておいてください。