フロントエンドのパフォーマンス計測は得意なのだが、サーバーサイド node.js のメトリクスの取り方はあまり知らなくて、いつも勘でやりがちだった。最近は業務でこの周辺で困ることが増えたので、勉強しなおした。

また、最近使ってみたかった cloudflare workers の制限で、メモリ 128MB、CPU 時間 50ms という制約があり、このためにも Node.js の CPU のメトリクスを計測できるようになっておく必要があった。

という目的を踏まえて、今回は OS やデータベースの最適化は扱わず、ネットワークとアプリケーション層だけに絞って学習した。あと仕事の Docker イメージのサイズにも悩んでたので、ここも。

(あと ISUCON 参加者が楽しそうだったのもある。 ISUCON のチューニング対象にフロントエンドは含まれないので…)

計測対象

今回実験したリポジトリはここ。

mizchi/nodejs-bench-playground

計測マシン

  • MacBook Pro 16-inch, 2019
  • プロセッサ 2.4GHz 8 コア Intel Core i9
  • メモリ 64GB 2667MHz DDR4

今回主にターゲットにするコード。

src/index.js

import express from "express";
import React from "react";
import ReactDOMServer from "react-dom/server";

const PORT = process.env.PORT ?? 4000;

function Tree(props: { depth: number }) {
  return (
    <div>
      <span>
        {"x".repeat(props.depth)}:{props.depth}
      </span>
      {[...Array(props.depth).keys()].map((n) => {
        return (
          <div key={n}>
            <Tree depth={props.depth - 1} />;
          </div>
        );
      })}
    </div>
  );
}

const index = (_req: any, res: any) => {
  const n = Math.round(1 + Math.random() * 4);
  res.send(ReactDOMServer.renderToString(<Tree depth={n} />));
};

const app = express();
app.get("/", index);
app.listen(Number(PORT), () => {
  console.log("started", PORT);
});

tsconfig.json

{
  "compilerOptions": {
    "rootDir": "src",
    "outDir": "lib",
    "target": "es2019",
    "module": "commonjs",
    "jsx": "react",
    "strict": true,
    "moduleResolution": "node",
    "esModuleInterop": true,
    "skipLibCheck": true,
    "forceConsistentCasingInFileNames": true
  }
}

再帰の SSR で、意図的に CPU に負荷を掛けるようにしている。乱数を使っているが、ベンチマークである程度の数だけ実行して収束するので、問題ないとした。

これを yarn tsc -p . でビルドして、 lib/index.js に吐き出してから node で実行する。ベンチマークの過程で、すこしずつ手を入れるが、基本的にはほぼ変わらない。

次の勉強過程を踏んだ。

  • メトリクスの計測
  • ベンチマークの計測と改善
  • Docker イメージのダイエット

まずツールの使い方を覚えて、ベンチを取り、その後 Docker イメージを小さくした。

メトリクスの計測

まずは各種ツールの使い方を覚えた。

autocannon

ベンチマークツール。

npm install autocannon -g

使い方

autocannon localhost:4000

数あるベンチマークツールの中で、これを選んだ理由は特にない。後述する 0x で一緒に使われていたので、入れただけ。

0x

フレームグラフを生成する。

npm install 0x -g

前述の autocannon と合わせて使った。

0x -P 'autocannon localhost:4000' --open -- node lib/index.js

読み方はあとで覚えるとして、一旦次に進む。

heapdump

メモリリーク検知のために、heapdump の使い方を覚える。

yarn add heapdump --dev

heapdump - npm

こんな感じで実行時のスナップショットが取れる。

heapdump.writeSnapshot(function (err, filename) {
  console.log("dump written to", filename);
});

Chrome の DevTools > Memory で読み込めるので、アプリケーションロジック的にメモリ量を知りたい前後でダンプを保存して、目視で比較するのに使える。

フレームグラフと同じく、ここも正直読み方は理解できてないのだが、とりあえず見える化が大事だとして、次に進む。

ベンチマークの計測と改善

初期状態で計測

$ yarn autocannon localhost:4000

Running 10s test @ http://localhost:4000
10 connections

┌─────────┬──────┬──────┬───────┬───────┬─────────┬─────────┬───────┐
│ Stat    │ 2.5% │ 50%  │ 97.5% │ 99%   │ Avg     │ Stdev   │ Max   │
├─────────┼──────┼──────┼───────┼───────┼─────────┼─────────┼───────┤
│ Latency │ 2 ms │ 8 ms │ 22 ms │ 26 ms │ 9.27 ms │ 5.34 ms │ 60 ms │
└─────────┴──────┴──────┴───────┴───────┴─────────┴─────────┴───────┘
┌───────────┬─────────┬─────────┬─────────┬─────────┬─────────┬────────┬─────────┐
│ Stat      │ 1%      │ 2.5%    │ 50%     │ 97.5%   │ Avg     │ Stdev  │ Min     │
├───────────┼─────────┼─────────┼─────────┼─────────┼─────────┼────────┼─────────┤
│ Req/Sec   │ 869     │ 869     │ 1032    │ 1112    │ 1024    │ 65.8   │ 869     │
├───────────┼─────────┼─────────┼─────────┼─────────┼─────────┼────────┼─────────┤
│ Bytes/Sec │ 2.85 MB │ 2.85 MB │ 3.51 MB │ 3.59 MB │ 3.45 MB │ 214 kB │ 2.84 MB │
└───────────┴─────────┴─────────┴─────────┴─────────┴─────────┴────────┴─────────┘

Req/Bytes counts sampled once per second.

10k requests in 10.01s, 34.5 MB read

process.env.NODE_ENV=production

express や React の SSR は develpment と production で性能が全然違うので、 production モードで実行する。

Running 10s test @ http://localhost:4000
10 connections

┌─────────┬──────┬──────┬───────┬──────┬─────────┬─────────┬───────┐
│ Stat    │ 2.5% │ 50%  │ 97.5% │ 99%  │ Avg     │ Stdev   │ Max   │
├─────────┼──────┼──────┼───────┼──────┼─────────┼─────────┼───────┤
│ Latency │ 1 ms │ 2 ms │ 5 ms  │ 6 ms │ 2.24 ms │ 1.19 ms │ 33 ms │
└─────────┴──────┴──────┴───────┴──────┴─────────┴─────────┴───────┘
┌───────────┬─────────┬─────────┬─────────┬─────────┬─────────┬─────────┬─────────┐
│ Stat      │ 1%      │ 2.5%    │ 50%     │ 97.5%   │ Avg     │ Stdev   │ Min     │
├───────────┼─────────┼─────────┼─────────┼─────────┼─────────┼─────────┼─────────┤
│ Req/Sec   │ 2705    │ 2705    │ 3777    │ 3935    │ 3686.8  │ 347.04  │ 2705    │
├───────────┼─────────┼─────────┼─────────┼─────────┼─────────┼─────────┼─────────┤
│ Bytes/Sec │ 9.33 MB │ 9.33 MB │ 13.3 MB │ 13.6 MB │ 12.9 MB │ 1.26 MB │ 9.33 MB │
└───────────┴─────────┴─────────┴─────────┴─────────┴─────────┴─────────┴─────────┘

Req/Bytes counts sampled once per second.

37k requests in 10.01s, 129 MB read

Avg で約 3.5 倍。

Node Stearm 対応

renderToNodeStream に変えてみる。メモリ効率が良くなるはず。

const index = (_req: any, res: any) => {
  const n = Math.round(1 + Math.random() * 4);
  // res.send(ReactDOMServer.renderToString(<Tree depth={n} />));
  ReactDOMServer.renderToNodeStream(<Tree depth={n} />).pipe(res);
};
Running 10s test @ http://localhost:4000
10 connections

┌─────────┬──────┬──────┬───────┬──────┬─────────┬─────────┬───────┐
│ Stat    │ 2.5% │ 50%  │ 97.5% │ 99%  │ Avg     │ Stdev   │ Max   │
├─────────┼──────┼──────┼───────┼──────┼─────────┼─────────┼───────┤
│ Latency │ 1 ms │ 2 ms │ 5 ms  │ 6 ms │ 2.01 ms │ 1.28 ms │ 41 ms │
└─────────┴──────┴──────┴───────┴──────┴─────────┴─────────┴───────┘
┌───────────┬─────────┬─────────┬─────────┬─────────┬─────────┬─────────┬─────────┐
│ Stat      │ 1%      │ 2.5%    │ 50%     │ 97.5%   │ Avg     │ Stdev   │ Min     │
├───────────┼─────────┼─────────┼─────────┼─────────┼─────────┼─────────┼─────────┤
│ Req/Sec   │ 2783    │ 2783    │ 4159    │ 4371    │ 3997.64 │ 449.52  │ 2782    │
├───────────┼─────────┼─────────┼─────────┼─────────┼─────────┼─────────┼─────────┤
│ Bytes/Sec │ 10.1 MB │ 10.1 MB │ 14.2 MB │ 14.8 MB │ 13.6 MB │ 1.31 MB │ 10.1 MB │
└───────────┴─────────┴─────────┴─────────┴─────────┴─────────┴─────────┴─────────┘

Req/Bytes counts sampled once per second.

44k requests in 11.01s, 150 MB read

ちょっとだけ伸びた。

cluster の採用

cluster 化してマルチコアを使うようにした。

// src/with-cluster.ts
import cluster from "cluster";
import os from "os";

const NUM_CPUS = os.cpus().length;

if (cluster.isMaster) {
  [...Array(NUM_CPUS).keys()].forEach(() => {
    cluster.fork();
  });
} else {
  import("./index");
}
Running 10s test @ http://localhost:4000
10 connections

┌─────────┬──────┬──────┬───────┬──────┬─────────┬─────────┬───────┐
│ Stat    │ 2.5% │ 50%  │ 97.5% │ 99%  │ Avg     │ Stdev   │ Max   │
├─────────┼──────┼──────┼───────┼──────┼─────────┼─────────┼───────┤
│ Latency │ 0 ms │ 0 ms │ 1 ms  │ 2 ms │ 0.16 ms │ 0.47 ms │ 33 ms │
└─────────┴──────┴──────┴───────┴──────┴─────────┴─────────┴───────┘
┌───────────┬───────┬───────┬─────────┬─────────┬──────────┬─────────┬───────┐
│ Stat      │ 1%    │ 2.5%  │ 50%     │ 97.5%   │ Avg      │ Stdev   │ Min   │
├───────────┼───────┼───────┼─────────┼─────────┼──────────┼─────────┼───────┤
│ Req/Sec   │ 12031 │ 12031 │ 19087   │ 19871   │ 18251.28 │ 2163.25 │ 12027 │
├───────────┼───────┼───────┼─────────┼─────────┼──────────┼─────────┼───────┤
│ Bytes/Sec │ 42 MB │ 42 MB │ 65.4 MB │ 68.8 MB │ 62.6 MB  │ 7.22 MB │ 42 MB │
└───────────┴───────┴───────┴─────────┴─────────┴──────────┴─────────┴───────┘

Req/Bytes counts sampled once per second.

201k requests in 11.01s, 688 MB read

さらに 4.5 倍ぐらい。

fastify

express はそこそこに遅いらしいので、とりあえず最速のベンチが出てる fastify に変えてみた。

fastify/fastify: Fast and low overhead web framework, for Node.js

// const app = express();
const app = require("fastify")();
app.get("/", index);
app.listen(Number(PORT), () => {
  console.log("started", PORT);
});
Running 10s test @ http://localhost:4000
10 connections

┌─────────┬──────┬──────┬───────┬──────┬─────────┬─────────┬───────┐
│ Stat    │ 2.5% │ 50%  │ 97.5% │ 99%  │ Avg     │ Stdev   │ Max   │
├─────────┼──────┼──────┼───────┼──────┼─────────┼─────────┼───────┤
│ Latency │ 0 ms │ 0 ms │ 0 ms  │ 0 ms │ 0.01 ms │ 0.13 ms │ 18 ms │
└─────────┴──────┴──────┴───────┴──────┴─────────┴─────────┴───────┘
┌───────────┬─────────┬─────────┬─────────┬─────────┬──────────┬─────────┬─────────┐
│ Stat      │ 1%      │ 2.5%    │ 50%     │ 97.5%   │ Avg      │ Stdev   │ Min     │
├───────────┼─────────┼─────────┼─────────┼─────────┼──────────┼─────────┼─────────┤
│ Req/Sec   │ 22111   │ 22111   │ 35039   │ 36319   │ 32951.28 │ 4404.52 │ 22102   │
├───────────┼─────────┼─────────┼─────────┼─────────┼──────────┼─────────┼─────────┤
│ Bytes/Sec │ 6.12 MB │ 6.12 MB │ 9.71 MB │ 10.1 MB │ 9.13 MB  │ 1.22 MB │ 6.12 MB │
└───────────┴─────────┴─────────┴─────────┴─────────┴──────────┴─────────┴─────────┘

このケースでは express 比で 1.8 ぐらい。

高速化の感想

16 コアなので 16 スレッドで伸びたが、最近主流な仮想化環境ではコア数は割り当てられる仮想マシンに依存して、仮想マシン自体が横並びになるので、実際にはこれほどは伸びなさそう。

fastify は噂通りスコアが出るのだが、実際には ミドルウェアが少ないので、採用するかどうかは微妙な気がする。本当に単目的な場合ぐらいしか使わなさそう。

Docker イメージのダイエット

次にこれを Docker 化する。開発時のメモリに優しくしつつ、本番でのデプロイを高速にするのが目的。

Docker 内では cluster と fastify がうまく動かなかったので、 このフェーズでは シングルコアを前提とした express を採用した。あとで fastify を動かす方法を調べる。

Dockerfile を置くだけ

node.js の公式のガイド を参考に、 dockerfile を書く

FROM node:14

WORKDIR /usr/src/app

COPY package*.json ./

RUN npm install

COPY . .

EXPOSE 4000
CMD [ "node", "lib/index.js" ]

=> 1.4GB

Dockerignore

COPY . . で全部転送されてる気がしたので、node_modules と lib を除く

node_modules
lib

(でもたしか .gitignore もみてるんだっけ？)

ついでにイメージを node:slim にした

=> 390MB

マルチステージビルド

  • 事前に TypeScript をビルドする
  • ビルドにまつわるものは devDependencies に移し dependencies を最小限にする
  • yarn install --production する
FROM node:14 as builder
WORKDIR /app

COPY package.json yarn.lock ./
RUN npm install

COPY src src
COPY tsconfig.json tsconfig.json
RUN npm run build

# ------------------
FROM node:slim as release

ENV NODE_ENV production
WORKDIR /app

COPY --from=builder /app/package.json /app/yarn.lock ./
RUN yarn install --production
COPY --from=builder /app/lib ./lib

EXPOSE 4000
CMD ["node", "lib/index.js"]

=> 343MB

node:alpine

release のイメージを node:alpine にしてみた

=> 293MB

alpine

  • node:alpine はまだ大きい気がするので、alpine にする
  • alpine に yarn を入れたくないので、 yarn から npm にした
FROM alpine:latest
RUN apk add --no-cache nodejs npm

=> 108MB

webpack でシングルファイル化

  • express の依存が多いので、本当に必要なランタイムだけでビルドすることにした。
  • npm install が不要になったので、 npm も削った
module.exports = {
  target: "node",
  entry: __dirname + "/src/index.tsx",
  resolve: {
    extensions: [".ts", ".tsx", ".js", ".json", ".wasm"],
  },
  module: {
    rules: [
      {
        test: /\.tsx?$/,
        use: [
          {
            loader: "ts-loader",
            options: {
              transpileOnly: true,
            },
          },
        ],
      },
    ],
  },
};

=> 39MB

dockerfile 最適化の感想

1.4GB => 34MB で 約 2.5 % のサイズになった。

最終的な dockerfile

FROM node:14 as builder
WORKDIR /app

COPY package*.json ./
RUN npm install

COPY src ./src
COPY tsconfig.json ./tsconfig.json
COPY webpack.config.js ./webpack.config.js

RUN npm run build

# ------------------
FROM alpine:latest as release
RUN apk add --no-cache nodejs
ENV NODE_ENV production
WORKDIR /app
COPY --from=builder /app/dist/ ./dist
EXPOSE 4000
CMD ["node", "dist/main.js"]

node:slim ~ alpine 化まではまだ現実的な範疇だが、 シングルファイル化は現実的なアプリでは厳しい気がする。ファイルの相対パスが崩れて、他の設定を読む系のものが動かないし、エラーのスタックトレースを追うのが難しくなる。あくまで可能な場合の最終手段という感じ。

やってみた感想

今回はアプリケーション自体がシンプル過ぎて、fastify や webpack などで過激な最適化ができたが、実際のプロダクションでは厳しいような気がする。できてその前段までぐらい。次はもうちょっと複雑な環境に適用してみようと思う。

調べてる過程で受けた印象だが、ここ数年の仮想化のおかげか、ハイパーバイザの役割が k8s や docker コンテナのマネージャーに移っていて、 pm2 やデーモン化ツールがほとんど使われなくなってそうな印象を受けた。

数値を取れるようにすることが大事で、というか数値が取れるようにした段階でチューニングは半分終わっているとも言える。これを CI 等で継続的に見ていくような仕組みを用意したい。しかし問題が起こってるコンテナでないとメトリクスをとってもあまり意味がない印象を受けたので、 ISUCON のお題とかでやってみるといいのだろうか。

参考

0 から始める Node.js パフォーマンスチューニング | kohsweblog

Node.js Performance 改善ガイド - from scratch

History