こんにちは、バックエンドエンジニアの片山です。
ISUCON 11の予選に参加したのですが、まだまだできることがあると思い、同じ問題に再挑戦しました！

問題のソースコード: https://github.com/isucon/isucon11-qualify
マニュアル: https://github.com/isucon/isucon11-qualify/blob/main/docs/manual.md
アプリケーションについて: https://github.com/isucon/isucon11-qualify/blob/main/docs/isucondition.md

Part-1 はこちら。 part と書いていますが前後関係は特にありません。
https://tech.curama.jp/entry/2021/09/22/182212

改善前の状態（1124点）

まずは何もしてない状態でベンチマークを走らせ、そのスコアと、part1 で紹介していました Elastic APM で各エンドポイントのパフォーマンスを測定します。
初期スコアは 1124点でした。平均 1,000ms 超えのエンドポイントもいくつかありますね。この状態からどこまで行けるかに挑戦します！

改善した項目に括弧書きでベンチマークのスコアを書いていきます。

なお、今回は以下のスペックのPCで実行しています。実行環境は Node.js（TypeScript）です。

OS:  Ubuntu 20.04.1 LTS
RAM: DDR4 64GB
CPU: AMD® Ryzen 5 3600 6-core processor × 12

f:id:curama-tech:20211019163054p:plain

やったこと

1. Index を貼る（1347点）

椅子を管理するテーブルの isu と、椅子の状態を管理している isu_condition では頻繁に絞り込みや集計、ソートの含まれるクエリが発行されるのですが、以下のカラムにインデックスがなかったので貼りました。スコア的には小さな改善ですが、全体的に速度が上がりました。

jia_isu_uuid
timestamp
jia_user_id
character

2. `POST /api/condition/:jia_isu_uuid` の改善（3155点）

Elastic APM で見たとき、impact（レイテンシが大きく、高い頻度でリクエストされるほど大きくなります）の値が一番大きい POST /api/condition/:jia_isu_uuid を改善します。この API では受け取った複数のコンディション情報を以下のようにループで1つずつ INSERT していました。これを、まとめて一度 INSERT が実行されるようにしました。

また、約40,000tpm（1分間のトランザクション数）とこの API はリクエスト頻度が非常に高いのですが、ベンチマーカーの仕様としてレスポンスまでに 100ms 以上かかるとタイムアウトします。INSERT をまとめて実行するだけでは、未だに多くのリクエストが失敗してしまっていました。そこで、bull という非同期にジョブを実行できるライブラリを使用し、データの書き込みを非同期的に実行することで API のレイテンシを改善しました。

	Avg. duration	95th percentile
改善前	851 ms	10,813 ms
改善後	54 ms	84 ms

改善前

// INSERT 処理の一部
for (const cond of request) {
    const timestamp = new Date(cond.timestamp * 1000);

    if (!isValidConditionFormat(cond.condition)) {
        await db.rollback();
        return res.status(400).type("text").send("bad request body");
    }

    await db.query(
        "INSERT INTO `isu_condition`" +
        "    (`jia_isu_uuid`, `timestamp`, `is_sitting`, `condition`, `message`)" +
        "    VALUES (?, ?, ?, ?, ?)",
        [jiaIsuUUID, timestamp, cond.is_sitting, cond.condition, cond.message]
    );
}

改善後

// 非同期で SQL を実行する queue, worker を用意
const queue = new Queue("worker_execute_eql", redisUrl);
queue.process(WORKERS, __dirname + "/worker_execute_eql.ts");

let values = [];
for (const cond of request) {
    const timestamp = new Date(cond.timestamp * 1000);

    if (!isValidConditionFormat(cond.condition)) {
        return res.status(400).type("text").send("bad request body");
    }

    values.push([jiaIsuUUID, timestamp, cond.is_sitting, cond.condition, cond.message])
}

// enqueue するだけで、リクエスト中は DB への書き込みは行わない
await queue.add({ 
    sql: "INSERT INTO `isu_condition` (`jia_isu_uuid`, `timestamp`, `is_sitting`, `condition`, `message`) VALUES ?",
    values: [values]
});

3. `isu_condition` を MongoDB にリプレイスする +α （8916点）

2の改善ではリクエスト頻度の高い API を改善するために insert の実行を非同期にしましたが、実はできるだけ同期的に insert を行いたいです。（理由は5で後述します）大量に送られるデータを同期的に insert できるような、書き込みの性能の高い DB を調べていると、どうやら MongoDB が良さそうでした。

同じような条件で MySQL と MongoDB でベンチマークを回してみました。確かに MySQL よりも MongoDB のほうが insert が高速でした。MongoDB では insert が同時に4つ走っていますが（全てのトランザクションではありません）、MySQL ではすべて単一だったことが高速化に寄与しているのかもしれません。いくつかトランザクションを見てみると、MongoDB は数ms ~ 100ms 程度、MySQL は数ms ~ 6,300ms 程度でした。同様に、読み込みも比較してみると、全体的には少し MySQL の方が速いようでした。

isu_condition テーブルを MongoDB にリプレイスする以外には、以下のような事を行いスコアを改善しました。

GET /api/trend の N+1 問題の解消
最新のコンディション情報を別の collection（MongoDB のテーブルのようなもの）に入れる
クエリの発行回数を減らすために、グローバルで宣言した Map を用いてキャッシュをする

Write

API	DB	Avg. duration	95th percentile
POST /api/condition/:jia_isu_uuid	MySQL	161 ms	672 ms
POST /api/condition/:jia_isu_uuid	MongoDB	19 ms	48 ms

MySQL f:id:curama-tech:20211019163252p:plain

MongoDB f:id:curama-tech:20211019163303p:plain

Read

API	DB	Avg. duration	95th percentile
GET /api/condition/:jia_isu_uuid	MySQL	45 ms	100 ms
GET /api/condition/:jia_isu_uuid	MongoDB	68 ms	147 ms

MySQL f:id:curama-tech:20211019163313p:plain

MongoDB f:id:curama-tech:20211019163325p:plain

4. Node.js のクラスタ化（19,207点）

Node.js はシングルスレッドで動作するため、マルチコアCPUを十分使えていません。 3 ノードで動作させるようにしたことで、スコアが大きく伸びました。以下を参考に簡単にクラスタ化を行うことができました。
https://nodejs.org/api/cluster.html#cluster_cluster

5. `POST /api/condition/:jia_isu_uuid` のチューニング（最大 24,619点）

ベンチマーカーのログを見ていると「ユーザーが増えませんでした」と表示されていました。ユーザーが増えるようになればスコアも改善されそうですね。色々試していると、GET /api/trend の API が最新のコンディションを返すようにしないとユーザーが増えない事がわかりました。また、ベンチマーカーの仕様から POST /api/condition/:jia_isu_uuid の API のレスポンスに 100ms 以上時間がかかるとタイムアウトし、100回以上タイムアウトするとベンチマークが強制停止する事がわかっています。

API は非同期にデータ投入するように修正しましたが、なるべく同期的に行うとスコアが伸ばせそうです。また、100ms を超えないようにする必要もあります。

そこで、はじめは insert を同期的に行い、タイムアウトが増えると徐々に非同期的に行う確率を上げていくようにしてみます。これによりベンチマークの序盤〜中盤まではユーザーが増える様になり、スコアが改善しました。

ちなみに確率的な処理にしたためか、実行ごとに 16,000~24,000点位のブレがあります。

// リクエスト数と、タイムアウトせず失敗した数を持っている
const okRate = okCount / reqCount;
let asyncInsertProbability = 1 - okRate * 0.7;

// タイムアウト100回を超えそうになったら完全に非同期にする（ノード全体で超えないように MAX_THREADS で割ってます）
if (reqCount - okCount >= 98 / MAX_THREADS) {
    asyncInsertProbability = 1;
}

if (Math.random() <= asyncInsertProbability) {
    // 非同期的に insert する
    await queue.add({ insert_data: data, latest_data: latestData });
} else {
    // 同期的に insert する
    const [collection1, collection2] = await Promise.all([
        getIsuconditionCollection(),
        getLatestIsuconditionCollection(),
    ]);

    await Promise.all([
        collection1.insertMany(data),
        collection2.updateOne(
        { jia_isu_uuid: latestData.jia_isu_uuid },
        {
            $set: {
            jia_isu_uuid: jiaIsuUUID,
            timestamp: latestData.timestamp,
            is_sitting: latestData.is_sitting,
            condition: latestData.condition,
            message: latestData.message,
            },
        },
        { upsert: true }
        ),
    ]);
}

6 ログを消す（43,013点）

最後に、Node.js のログや Elastic APM を無効にしたところ、かなり大きくスコアが改善しました。 Elastic APM やログを使用するために追加した以下のコードをコメントアウトしました。

アプリケーションと APM は同じ PC 上で動いているため、効果が大きくなったと考えられます。

// Elastic APM の設定
// const apm = require("elastic-apm-node").start({
//   // Override the service name from package.json
//   // Allowed characters: a-z, A-Z, 0-9, -, _, and space
//   serviceName: "",

//   // Use if APM Server requires a secret token
//   secretToken: "",

//   // Set the custom APM Server URL (default: http://localhost:8200)
//   serverUrl: "http://apm-server:8200",
// });

// Node.js のログ表示用
// app.use(morgan("short"));

最終的なパフォーマンス

f:id:curama-tech:20211019163405p:plain

まとめ

思いつく範囲のことを試し、スコアを伸ばすことができましたが、まだまだできることはありそうです。今回初めて触ったのですが、エンドポイントごとのサマリーや、サンプルのトランザクションのタイムラインを簡単に眺めることができる Elastic APM がすごく便利でした。また、MongoDB も十分理解できていないまま使用したので、ほとんど本領発揮できていない状態だと思います。MongoDB （NoSQL）に興味が出てきたのでもう少し勉強してみたいと思いました！

とにかく、ISUCON はいい刺激になったので、次回も参加したいです！

くらしのマーケット開発ブログ

「くらしのマーケット」を運営する、みんなのマーケット株式会社のテックブログ。積極採用中です。

ISUCONの過去問にチャレンジしてみた: Part-2

改善前の状態（1124点）

やったこと

1. Index を貼る（1347点）

2. `POST /api/condition/:jia_isu_uuid` の改善（3155点）

改善前

改善後

3. `isu_condition` を MongoDB にリプレイスする +α （8916点）

Write

Read

4. Node.js のクラスタ化（19,207点）

5. `POST /api/condition/:jia_isu_uuid` のチューニング（最大 24,619点）

6 ログを消す（43,013点）

最終的なパフォーマンス

まとめ

改善前の状態（1124点）

やったこと

1. Index を貼る（1347点）

2. POST /api/condition/:jia_isu_uuid の改善（3155点）

改善前

改善後

3. isu_condition を MongoDB にリプレイスする +α （8916点）

Write

Read

4. Node.js のクラスタ化（19,207点）

5. POST /api/condition/:jia_isu_uuid のチューニング（最大 24,619点）

6 ログを消す（43,013点）

最終的なパフォーマンス

まとめ

2. `POST /api/condition/:jia_isu_uuid` の改善（3155点）

3. `isu_condition` を MongoDB にリプレイスする +α （8916点）

5. `POST /api/condition/:jia_isu_uuid` のチューニング（最大 24,619点）