Web リクエストの解剖 基礎

curl https://api.example.com/user/42 は 137 ミリ秒。手で動かせる図で 3 つを示す:12 ステージは直列で合計は和、サーバの取り分は 1.03 ms、101 ms は再利用すれば消える接続の準備。 20 の primer をステージごとにリンクしてある。

01

1 つのコマンド、12 ステージ、137 ミリ秒

およそ 7 分の 1 秒で JSON が stdout に落ちる。その時間のほとんどはサーバのものではない。

コマンドは curl https://api.example.com/user/42、往復 30 ms、DNS はコールド、開いた接続もなし。向こうでは nginx の後ろのプロセスが PostgreSQL で主キー検索を 1 回し、 2 KiB の JSON を返す。珍しいものは何もない。

12 ステージは 1 つずつ順に走る。各段が前段の出力を消費するからだ:解決していないアドレスにソケットは開けない。時計の下のステージは琥珀、その後ろは青緑。時計を横に引いてほしい:

curl を起動。横に引いて動かす。左右の矢印キーで 1 つずつ進み、Home で最初の状態に戻る
curl を起動 — 5 ms

支払い済みのステージが 1 行に積み上がることに注目してほしい。12 本中 5 本が回線レーンにあり、137 ms 中 131 ms を運ぶ。サーバ側 4 段は合わせても幅を持てない。合計が最大値ではなく和なのは、時計の下のステージが常に唯一走っているものだからだ。

これはレーンごとに読む価値がある。スライダで 5 レーンを歩けば、選んだレーンが何ステージを持ち、リクエストの何割を食うかを報告する:

クライアント app

サーバアプリケーション —— 解析、クエリ、直列化 —— で 960 µs。両方のカーネルを足してもマシン側は 1.03 ms、呼び出し側が待った時間の 0.7% だ。ハンドラの中で何をしようと、ユーザが体験する数字の 0.7% を調整しているにすぎない。

理由は工学ではなく算術だ。1 回の 30 ms 往復はマシン内部のすべてが消えるほど大きな単位である —— マーカーをより小さな各レイテンシへ動かし、 1 往復に何個入るかを読んでほしい:

L1 ヒット

1 往復には主記憶アクセスが 375,000 回、 L1 ヒットなら 30,000,000 回入る。 CPU 屋が破滅的と呼ぶキャッシュミスでも、ネットワークができる最も安い操作の 300 万分の 1 に満たない。この比こそ、このページの残りがほぼ往復の話である理由だ。

しかもどの距離でも成り立つ。そこが意外なところだ。往復を同一ラックの 1 ms から大陸横断の 61 ms まで引き、回線とサーバが別々に動く様子を見てほしい:

RTT = 30 ms

サーバのバーは一度も動かない。どの設定でも 1.03 ms で、サーバは距離に依存する仕事を 1 つもしていない。伸びるのは回線のバーだけだ。つまりページ全体は 1 行のコストモデルに畳める:合計 ≈ プロセス起動 5 ms + DNS + 3 × RTT + 2.4 ms。往復 1 ms なら 50.4 ms、61 ms なら 230 ms。以降はすべて、この 4 項のどれを消せるかという議論である。

02

パケットがまだ存在しない時間

137 ms のうち 45 ms は、クライアントが繋ぐ先のアドレスを得る前に消える。犯人はどちらもネットワークではない。

Enter を押すとシェルが fork し、まだメモリにないバイナリを execve する。カーネルはアドレス空間を作り、ELF と 6 つの共有オブジェクトをマップし、動的リンカに制御を渡す ——プロセスとスレッドと仮想メモリへ。

その 5 ms のほとんどは fork ではない。スライダで 5 フェーズを歩き、誰も予期しない 2 つに時計が積み上がり、後ろに済んだ分が残る様子を見てほしい:

fork

質量の位置に注目してほしい。再配置 —— リンカが 6 ライブラリのシンボル参照を埋める作業 —— が 2.1 ms、テキストのデマンドページングがさらに 1.6 ms、マイナーフォルト約 1,340 回。どちらも起動の代金であって仕事の代金ではない。常駐クライアントが毎回起動に勝つ理由はこれで全部だ。アロケータはメモリ割り当てに。

次に getaddrinfo。20 µs のことも 40 ms のこともある ——2,000× の振れ幅は、誰が答えを知っているかだけで決まる。スライダを委任に沿って上げ、答えを返すホップが遠ざかり、その手前のホップを全部歩く様子を見てほしい:

プロセス内 — 20 µs

チェーンは遠い端から空になり、その順序が効く:権威の答えは .com の委任よりずっと早く切れる。後者の NS レコードは 2 日の TTL を持つ。だからよくあるコールドはルートからの 40 ms ではなく、.com から始まる 25.1 ms のほうだ。委任の残りはまだキャッシュされている。レコード型は DNS と HTTP に。

コストより故障モードが悪い。DNS は UDP に乗り、再送するのは呼び出し側だけだ。resolv.conf のタイムアウトとネームサーバ数を動かし、呼び出しスレッドが誰も答えない試行に何秒ブロックされるかを読んでほしい:

4 × 5 s

glibc の既定 ——timeout:5、attempts:2、ネームサーバ 2 つ —— ではブラックホールに落ちたクエリが呼び出し側を20 秒ブロックし、EAI_AGAIN を返す。大声で失敗するのは良い場合だが、その頃には上のタイムアウトは全部発火済みだ。ハンドラ内の同期 DNS は性能問題ではなくバグである。

03

HTTP の 1 バイト前に 2 回のハンドシェイク

名前は解決した。しかし有用なことはまだ一言も言っていない。リクエストとの間に交渉が 2 つ立っている。

socket() はカーネル割り当て 1 回、connect() は TX ディスクリプタ 1 個 —— 2 つ合わせて 60 µs。その後はすべて相手の返事待ちで、相手は 30 ms 先だ。両方のハンドシェイクの詳細はTCP 詳解とTLS とセキュリティにある。

GET /user/42 が出るまでに 6 つのメッセージが往復する。 1 つずつ進めて、飛行中のメッセージが毎回半往復を食い、配達済みのものはその場に留まる様子を見てほしい:

SYN

各往復のどちらの半分が遊んでいるかに注目してほしい。クライアントはACKとClientHelloを背中合わせで送るので、 TLS 1.3 は 1 往復で済む —— 鍵共有は暗号スイートの合意を待たず最初のメッセージに相乗りする。時計は 61.2 ms:2 往復と証明書検証の 1.2 ms だ。

137 ms のリクエストに対して、これは手で動かせる具体的な割合だ。往復時間を引いて、ハンドシェイクが全体の何割を取るかを読んでほしい:

RTT = 30 ms. 横に引いて動かす。左右の矢印キーで 1 つずつ進み、Home で最初の状態に戻る
RTT = 30 ms

30 ms なら2 つのハンドシェイクはリクエストの 45%。太平洋横断の 150 ms なら 61% だ。3 往復のうち 2 往復は純粋な準備で、データを運ぶのは 1 往復だけだからである。これが消す価値のある項であり、しかも消せる:中身のどれ 1 つとしてリクエスト自体に依存していない。

接続の始め方は 4 つある。暗記ではなく比較できるよう 1 つの舞台に描いた。切り替えて、それぞれが何を前払い済みかを読んでほしい:

完全 — 61.2 ms

直感ではなく往復数の列を読んでほしい。セッション再開は前の接続の事前共有鍵を使い回すが、それでも2 往復かかる。完全ハンドシェイクと同じだ。 TLS 1.3 はもともと 1 往復なので、落とせる 2 本目がない。再開が落とすのは証明書のほうで、61.2 ms が 60 ms になる。1.2 ms のチェーン解析と 2 回の署名検証、それが節約のすべてだ。 2 が 1 になるのは TLS 1.2 の算術である。往復を実際に 1 つ落とすのは0-RTT(30 ms)で、アプリケーションデータを最初のフライトに入れて送る —— だから非冪等な操作には安全でない:そのフライトを捕らえた攻撃者は再生でき、サーバにはまだ気づくためのハンドシェイク状態がない。それでも 0 ではなく 1 往復なのは、前段の TCP ハンドシェイクが消えていないからだ。畳み込むのは QUIC だけである。再利用された接続は何も払わない。

それが数える前に、もう 1 つ成り立たねばならないことがある:証明書がクライアントの信頼するルートまで連鎖することだ。 1 本ずつ壊して、検証器が実際に何を報告するかを読んでほしい:

チェーン検証成功

つまずくのは 3 番目だ。unable to get local issuer certificate は未知のルートに読めるが、ほぼ決してそうではない —— サーバが中間証明書を送らず、手元に正しいリーフと正しいルートがあってつなぐものだけがない、という意味だ。しかも client 次第で出たり出なかったりする。

04

スタックを下り、また上る

リクエストは 312 バイトのテキストだ。それを線に載せ、また降ろすところで各層は働きを見せる —— そして物を落とす。

どの層も上から渡されたものを包み、自分のヘッダを足す: TLS レコード、TCP セグメント、IP パケット、イーサネットフレーム、そしてその全部の前に PHY が打ち出すプリアンブル。これはネットワークスタックの主題で、バイト配置は2 進数と数の表現にある。

下のバーは常に 1 フレームで、中身が何であれ同じ幅で描かれる。ペイロードを縮め、112 バイトの枠が絵を占領する様子を見てほしい:

1426 B → 1538 B

ペイロードが満杯の 1,426 バイトなら枠は 7.28% で誰も気にしない。 1 バイトなら —— ACK、キープアライブ、フィールドを 1 つずつ送る RPC —— 実効は 0.9%、 1 バイト運ぶのに113 バイト払う。 Nagle アルゴリズムが存在する理由も、それを切るのが最適化ではなく決断である理由も、これで全部だ。

1 セグメント分を超えると TCP は分割する。最大セグメント長は 1,500 バイトの MTU から IP と TCP のヘッダ 40 バイト、さらにタイムスタンプオプション 12 バイトを引いた値 ——レスポンス本体を引いて本数が段を上がるのを見てほしい:

2 セグメント

最後のセグメントの代価に注目してほしい。この 2 KiB の JSON は 2 本:満杯の 1 本と、1,426 バイト用の枠に入った622 バイトの余りだ。それでも両方が半往復で渡る。背中合わせで出るうえ、ウィンドウは 2 本よりずっと広い —— セグメント数が食うのは帯域であって遅延ではない。損失が起きて 2 本目が 1 本目を待つまでは。

サーバ側では NIC が各フレームを DMA でリングバッファに直接書き、割り込みを 1 回上げる。その後 softirq が 64 個ずつリングを抜く。到着レートを1 コアの処理限界より上げてほしい:

600 kpps 到着。横に引いて動かす。左右の矢印キーで 1 つずつ進み、Home で最初の状態に戻る
600 kpps 到着

処理レートを越えるとリングが埋まり、 NIC は次のフレームを置く場所を失う。そこで rx_missed_errors を 1 増やして捨てる。かけるべき背圧はない —— 送信側は聞いていない。この破棄は普通のサービスから見えるどの層でも静かだ:TCP が再送し、リクエストはやがて成功する。遅く。そのレートを決める softirq 予算はシステムコールと割り込みにある。

バイトがソケットバッファに入ったら、epoll_wait で止まっている worker が実行中スレッドにならねばならない。そのコアに実行可能なスレッドを足し、6 つの段のどれが伸びるかを見てほしい:

このコアに 0 個

最初の 4 段はリスト操作にすぎず、アイドルなコアでの起床は 22 µs だ —— 負荷に関わる段はランキューだけである。前に 6 つ並べば 22 µs の起床が 9 ms になる。自分のコードを指すプロファイラが説明できない p99 がこれだ。I/O モデル、CPU スケジューリング、並行プリミティブへ。

05

サーバが実際にしていること

ハンドラ全体で 1.03 ミリ秒。それでもどこへ消えるかは知る価値がある —— そのうち 2 項には上限がないからだ。

リクエスト行と 8 つのヘッダの解析は、 L1 を出ないバッファ上での 60 µs のポインタ演算だ —— なぜそれが効くかは記憶階層、接続テーブルが複数コアから書かれたら何が起きるかはキャッシュコヒーレンスへ。そして SELECT * FROM users WHERE id = 42。

インデックスは B+tree で、その高さが検索の触るページ数を決める。行数を 7 桁ぶん引いて、ファンアウトが尽きたときだけ木が 1 段伸びる様子を見てほしい:

100 行。横に引いて動かす。左右の矢印キーで 1 つずつ進み、Home で最初の状態に戻る
100 行

伸びる回数の少なさに注目してほしい。8 KiB のページには bigint のエントリが約 367 個入るので、1 億行には4 段が要る: 367³ は 4,900 万、367⁴ は 180 億 ——1 千万行の表より 1 段多い。表に 0 を 1 つ足してもたいていは検索に何も足さない —— この平坦さこそ B+tree が二分木でなくこの形である理由のすべてだ。ノード配置はデータベースストレージに。

つまりインデックス 4 ページとヒープ 1 ページ。それが 550 µs か 5.55 ms かは、5 ページのうち何ページをバッファプールが持っているかだけで決まる。ページをプールから抜き、デバイスを替えてほしい:

5 ページ中 0 ページがミス — 550 µs

完全にコールドな下降は NVMe で 1 ms —— 4 KiB 読みが 5 回、1 回あたり約 90 µs。その下のページキャッシュがほとんど問題にならない理由 (ファイルシステム)であり、ディスクストレージがキュー深度に紙幅を割く理由でもある。同じ実行計画でも、クラウドブロックストレージでは同じ下降が 5.55 ms、1 桁違う。

上限のない項はまだ出ていない。プールされた接続は有限の資源で、需要がそれを越えた瞬間、待ちはもうサービス時間ではない。実行中のリクエスト数をプールサイズより上げ、 1 件がスロットを握る時間も伸ばしてほしい:

キュー待ち 0

需要がプールサイズを越えた途端、キューがレイテンシのすべてになる —— それ以下では待ちはきっかり 0 で、絵は退屈だ。実行中 200、プール 20、1 件 5 ms なら、550 µs のクエリに 45 ms の待ちが乗る。上限は Little の法則そのものだ ——20 スロット ÷ 5 ms で毎秒 4,000 件。それ以上流し込んでも増えるのはスループットではなくキューである。

書き込みなら最後の項は永続性だ。COMMIT は先行書き込みログのレコードが電源断に耐える媒体に載るまで返らず、レバーはバッチ化しかない。1 回のフラッシュを共有するトランザクション数を上げてほしい:

グループコミット 1 件

1 コミット 1 フラッシュではデバイスがそのままスループットだ:NVMe で毎秒 1,538 件(1 件 650 µs)、クラウドボリュームで 124 件。グループコミットは 1 回のフラッシュを 16 件で割り、各件に数ミリ秒の遅延を足す代わりに 1 桁を取り戻す。fsync を切ればもう 2 桁取り戻せるが、ACID の D を黙って手放すことになる —— COMMIT が本当は何を約束しているのかはトランザクションへ。

06

137 ms はどこへ行くのか

全ステージを測り終えた。同じ 12 個の数をコスト順に並べると、トレースが言わないことを言う。

§01 のウォーターフォールは起きた順に描いてある。機構の理解には正しい順序だが、何を直すか決めるには誤った順序だ。同じ 12 ステージをコスト順に並べ替えると、議論の形が変わる。

今度はコスト順にステージをスライダで下り、それぞれが全体の何割かを読んでほしい。上位 3 つは残りと分けて描いてある:

コスト順 1 位

その 3 つ —— DNS、TLS、TCP —— で 101 ms、リクエストの 74% だ。どれも準備であり、 1 つとしてどのユーザを尋ねたかに依存していない。最も安い 6 つは合わせて 1.09 ms。フレームグラフが何も映さないプロファイルがこれだ。この時間はどれも CPU 上にない。

ステージが直列である以上、1 つ削ればちょうどその長さだけ減るはずだ —— それは信じる話ではなく試せる話である。削るステージを選び、その後ろのすべてが空いた分だけ左へ詰まる様子を見てほしい:

何も削らない

どれを選んでも、終点は消えたバーの長さだけ正確に動く。不変条件を算術に書き直すとこうなる:どのステージも他と重ならない。だから合計は和であり、払わずに済ませた 1 ミリ秒は末尾から丸ごと消える。どの削除を追うべきかも同時に分かる —— 大きい 3 つはすべて準備だ。

準備こそ実際に消せる部分だ。 4 つの接続戦略を切り替え、消えるバーを見てほしい:

コールド — 137 ms

どのバーが残るかを見てほしい。DNS の答えをキャッシュするだけで 137 ms が 97.5 ms になる。さらに接続を開いたままにすれば 36.2 ms。プロセス起動まで省いた常駐クライアント —— サーバ間呼び出しはこれだ —— は 31.2 ms、4.4× の削減で、そのうち 30 ms はリクエストと返答を運ぶ 1 往復だ。 5 つ目の戦略はない。そこが床である。

節約はリクエストごとなので積み上がる。何回のリクエストを走らせるかを引き、プールした 1 接続と毎回新しい接続を比べてほしい:

1 リクエスト

50 回の逐次呼び出しはプールありで 1.67 s、なしで 6.87 s —— 同じ仕事で実時間は 4.1×、差はすべてデータを運ばなかったハンドシェイクだ。CPU 体系構造とアセンブリと ISAがレバーでなくなるのもここである:解析ループで勝てる定数因子はマイクロ秒、相手は往復で測る項だ。

07

何が、どこで壊れるか

症状は層を上っていく。原因はちょうど 1 つの層に住み、トレースは前者から後者への地図だ。

500 が話の全部であることはまずないし、「API が遅い」もそうだ。以下の10 個の障害はそれぞれ、上の層には残せない署名を残す。この地図を暗記する価値はそこにある。

スライダで一通り歩き、それぞれの障害が実際どこに住み、起きたとき呼び出し側に何が見えるかを読んでほしい:

リゾルバに届かない — 10 秒後に EAI_AGAIN

10 個のうち 2 個は同じステージに乗る。混同される一対だ:遅いクエリと枯渇したプールはどちらも「DB が遅い」として現れる。見分けるのは形だ —— 遅いクエリは一部のリクエストを伸ばし、飢えたプールは DB に触れないものまで含めすべてのリクエストを等しく伸ばす。

その一覧の 2 番目には専用の図の価値がある。症状が、出典を知らないまま皆が口にする数字だからだ。誰も答えない SYN の再送を 1 段ずつ進めてほしい:

0 s

再送タイマが倍になるので、経過時間は 1、3、7、15 秒と進む —— ログの「3 秒のハング」は落とされた SYN 1 個であって、それ以外ではない。 Linux は tcp_syn_retries 回の倍加で諦める。既定は 127 秒:上のあらゆるタイムアウトが先に発火するほど長い。状態機械は TCP 詳解に。

では、そのタイムアウトはいくつにすべきか。クライアントの予算をコールドなリクエストのコストより下まで引き、再試行方針が与える負荷に何をするかを見てほしい:

タイムアウト = 500 ms

137 ms を下回ると初回呼び出しは必ずタイムアウトして再試行され、サービスは 3 倍の負荷を受けて 1 件も完了しない —— 典型的な再試行の嵐だ。原因は、タイムアウトをコールドではなくウォームの数字で決めたことにある。予算は呼び出し側が正当に通りうる最も遅い経路を覆わねばならない。さもなくば遅い依存が死んだ依存に変わる。

最後の故障モードは、実は何も壊れていない。規模でだけ姿を現す算術だ。 1 つのユーザリクエストが何個のバックエンドに広がるかを上げてほしい:

1.0%

積み上がる速さに注目してほしい。10 回なら 9.6%、100 回なら 63% が p99 を含む。自分の p99 が 20 ms でも合成された p50は健全でなくなり、どのサービスにも非はない:Dean と Barroso の「the tail at scale」(CACM 56:2, 2013)だ。

まとめ:ステージは直列、ゆえに合計は和。障害は見ている層で静かに、2 つ下で騒がしい。つまずきは見える 0.7% の最適化だ。コストは 3 行に収まる:

ms   spawn 5.00   DNS 0.02-40.00
     TCP  1xRTT   TLS 1xRTT   data 1xRTT
     server 1.03  =  5 + DNS + 3xRTT + 2.4