渠道統計の詳細ページに1.5秒かかる。管理画面のダッシュボードとしては壊滅的ではないが、更新のたびに1秒半待たされれば、使う人は覚えている。

30日ウィンドウ、24.6万件のクリックという本番規模でのベンチマーク。詳細ページ1.51秒、チャネル横断のサマリー1.49秒、共有ページ0.85秒——共有ページは広告主側に見せるものだから、1秒半の白画面は見栄えが悪い。

問題はデータ量ではない

まず「有効デバイス」という言葉を整理しておく。独立デバイスのうち、クリック後30分以内に実際にランディングしたものだ。判定条件は LANDED というマクロで、中核は EXISTS の一文で、0067 で作った idx_channel_pv_device（デバイス＋時点）を引く。

元の書き方は LANDED を集約の FILTER に押し込むものだった：

count(DISTINCT c.device_id) FILTER (WHERE NOT c.is_bot AND {LANDED}) AS valid_devices

自然に見える——FILTER はまさにそのためのものだ。だが EXISTS はここでは相関サブクエリであり、プランナはそれ用に SubPlan を生成する。つまり実クリック1件ごとに1回実行される。30日ウィンドウで23万回のインデックス探索、これだけで680ミリ秒。

「有効デバイス」全体を独立したサブクエリとして切り出し、LANDED をその WHERE に書く形に変える：

(SELECT count(DISTINCT c.device_id) FROM channel_click c
  WHERE c.channel_code = $1 AND c.clicked_at >= $2 AND c.clicked_at < $3
    AND NOT c.is_bot AND {LANDED})

これでプランナにも分かる。これは「クリックテーブル ⋉ ランディングテーブル」のセミジョインであり、一度にハッシュできる。23万回のプローブではない。この部分は680ms → 300ms。

日別推移とチャネル別リストも同様に、LEFT JOIN のグループ化サブクエリに変える。with_valid = false の呼び出し元（共有ページは有効デバイスを表示しない）はさらに省ける——サブクエリ自体が現れず、定数 0 に置き換わり、クリックテーブルをもう一度スキャンしない。

だがまだ半分の時間が残る

セミジョインに直した後、残る時間の大きな部分はコンパイルのオーバーヘッドだ。

これらのSQLはサブ秒級のOLTPクエリで、JITは決して割に合わない。ところがプランナは誤って発動してしまう。原因は日別のクエリが generate_series で左結合しており、行数が約2億と見積もられ、jit_above_cost をはるかに超えることだ。JITコンパイルは1回150〜550ミリ秒、すでにサブ秒のクエリの半分以上を占める。

そこで統計APIに読み取り専用トランザクションを追加した：

async fn stats_tx(pool: &sqlx::PgPool) -> Result<sqlx::Transaction<'_, sqlx::Postgres>, AppError> {
    let mut tx = pool.begin().await?;
    sqlx::Executor::execute(
        &mut *tx,
        "SET TRANSACTION READ ONLY; SET LOCAL jit = off; SET LOCAL plan_cache_mode = force_custom_plan",
    ).await?;
    Ok(tx)
}

3つのポイント：

  • パラメータなしの &str は簡易クエリプロトコルを使い、3つの文を1往復で送る。
  • sqlx::raw_sql は使わない——その execute が原因で、呼び出し元（axumのハンドラ関数）のfutureが Send チェックを通らなくなる。
  • SET LOCAL はこのトランザクションにのみ作用し、接続がプールに戻れば元に戻る。トランザクションは読み取り専用なので、終了時にそのままdrop（ロールバック）すればよい。

3つ目の命令が一番意外だった

plan_cache_mode = force_custom_plan この一行は最初、追加する必要があるとは思っていなかった。

ことの次第はこうだ。sqlxは接続上でプリペアドステートメントをキャッシュする。同じ文を5回実行すると、Postgresは汎用プランに切り替える——汎用プランは毎回の再計画にかかる1〜3ミリ秒を省けるので、大多数の高頻度で短いクエリには得になる。

だが汎用プランはパラメータの実際の値を知らない。つまりウィンドウの境界も分からず、時間範囲を極小に見積もってしまう。ウィンドウを小さく見積もると、先ほど組み上げたハッシュセミジョインが行ごとのネステッドループに退化する。ファネルは290ms → 600ms、修正後は修正前より倍遅い。しかも遅くなるのは6回目のリクエストからだ。

これは目視では分からず、一時的なテストを書いて、同じ接続上で同じハンドラ関数群を8回ループ実行して、ようやく曲線が見えた。

これらのAPIはもともと頻繁ではないので、毎回1〜3ms余計に計画しても無視できる。だからカスタムプランを強制し、常に計測済みのハッシュセミジョインを通すようにした。

結果が変わっていないことをどう証明するか

性能改善では、ついでに集計の定義を間違えやすい。今回はバイト単位での一致を求め、次の2つを検証した：

  • ファネルの行は、md5 を直接比較する。
  • 日別行とチャネル別行の md5。

30日ウィンドウと7日ウィンドウでそれぞれ検証する。すべて一致して初めて認める。

結果（30日ウィンドウ、ビルドマシン上でのベンチマーク）：

エンドポイント改修前改修後
チャネル詳細1.51 s0.64 s
チャネル横断サマリー1.49 s0.72 s
共有ページ0.85 s0.55 s

いくつか学んだこと

FILTER の中の相関サブクエリはper-rowのSubPlanになる。 中のものを丸ごと外に切り出せるなら、切り出すのがほぼ常に正しい。FILTER は安価なスカラー判定を置くのに向いており、EXISTS を置くのには向かない。

「直したら速くなった」は本当とは限らない。 今回、6回目以降の曲線を見ずに最初のベンチマークだけ見ていたら、結論は正反対になっていた。本番のスロークエリは、接続がしばらく再利用されて初めて姿を現すことが多く、単発のベンチマークでは測れない。

JITは大きなクエリでだけ有効になるわけではない。 推定行数で発動し、その推定は generate_series のようなもので容易にしきい値を超えさせられる。サブ秒クエリでは明示的に切るべきだ。

stats_tx の上にはさらにカバレッジテストが1つある。単一接続プールを使い（トランザクション終了後に取り直した接続が必ず同じものであってこそ、SET LOCAL がプールに漏れていないかが分かる）、トランザクション内で3つの設定が本当にすべて有効になっていることをアサートし、さらにその中に1行挿入してみて失敗することをアサートする。最後にトランザクションを drop し、プール上で SHOW を改めて実行して、jit と plan_cache_mode がデフォルトの on / auto に戻っていることを確認する。SET LOCAL がプールに漏れると、それ以降のすべてのクエリを汚染してしまう。これは多少遅くなるよりもはるかに深刻だ。

これらの知見は今のところ関数のコメントに書いてあり、コードと一緒に置いてある。ブログに書いたら三ヶ月後には自分でも見つけられなくなる…