- ブラウザURL入力今ここ
- DNS名前→IP
- ルータ経路選択
- ロードバランサ振り分け
- Nginx受け口
- アプリ処理今ここ
- DB保存
ここまでは1つの数字の読み方を見てきました。今回は端から端までの時間を、経路上の段ごとに切り分けます。
まず結論
所要時間は段ごとに分けないと「どこで消えたか」が分かりません。ただし段ごとの数字を出す道具は、区間ではなく開始からの累積を返すことがあります。
curl の時間変数がそれです。区間に直しても読み違えは残ります。境界の内側に別の段が入ること、最初の1バイトより後ろに時間が隠れること、サーバの申告とクライアントの時計を突き合わせられないこと。この3つが主題です。
curl が出す time_namelookup / time_connect / time_starttransfer の3つを足すと、何に近い値になるでしょうか。
当てることが目的ではありません。外した予測ほど記憶に残るので、直感で選んでください。
段ごとの数字は、たいてい「そこまでの累積」で出てくる
端から端までの1つの数字は「遅い」としか教えません。段に分けて測ります。問題は、道具が返す数字の形が2通りあることです。
- 区間値 — 「ここからここまで」の長さ。そのまま足せる
- 累積値 — 「計測開始から、ここまで」の合計。短いものが長いものに含まれる
curl の --write-out が返す時間変数は後者です。man は5変数を同じ言い回しで定義しています。
time_namelookup — The time, in seconds, it took from the start until the name resolving was completed. time_starttransfer — The time, in seconds, it took from the start until the first byte was received. This includes time_pretransfer and also the time the server needed to calculate the result.
from the start until。名指しで累積と書くのは time_starttransfer だけですが、他も同じ構造です。したがって区間を得るには隣どうしの差を取る必要があります。これは定義からの帰結で、man の指示ではありません。
- ・矢印はすべて「計測開始から」伸びている。段から段ではない
- ・time_total だけは累積の系列ではなく、操作全体の長さとして定義されている
引き算すれば、和はぴたりと合う
50ミリ秒眠るだけのアプリへリクエストし、累積値を引き算で区間に直しました(Docker Desktop の Linux VM 内、平文HTTP、1回)。
raw (cumulative): namelookup=0.000009 connect=0.000063 appconnect=0.000000pretransfer=0.000077 starttransfer=0.054112 total=0.054134intervals (by subtraction):DNS = namelookup - 0 = 0.000009TCP connect = connect - namelookup = 0.000054TLS handshake = appconnect - connect = 0.000000 (no TLS)pre-transfer = pretransfer - connect = 0.000014server wait = starttransfer - pretransfer = 0.054035body transfer = total - starttransfer = 0.000022SUM of intervals = 0.054134 ; time_total = 0.054134 ; residual = 0.000000000
残差は 0 ですが、実測で確かめた性質ではありません。隣り合う累積値の差を全部足すと途中が打ち消し合い(望遠鏡和)、定義上 time_total に戻ります。curl の出力は小数以下6桁で、9桁の 0.000000000 は表示の桁にすぎません。
合わないのは引き算をせず素朴に足したときです。同環境の別の測定では、5つの累積値をそのまま足すと time_total を 10〜14% 上回りました。超過率は段の比で決まるので目安になりません。 分かるのは「二重に数えている」ことだけです。
なお appconnect は平文HTTPでは 0.000000。TLS が速いのではなく、使っていないという意味です。
curl の time_connect から time_namelookup を引くと、何が得られますか。
区間に直しても、まだ2つの読み違えが残る
区間が出ても、それが何を囲っているかは別の問題です。読み違えは2方向で起きます。
境界の内側に、別の段が入っている。 「サーバの待ち時間」と読んだ区間に、別のサーバへの往復が入っていることがあります。名前は中身を保証しません。
境界の外側に、見ていない区間が残る。 TTFB は「最初の1バイトまで」なので本文の転送は範囲外です。TTFB が正常なのに遅い、が成立します。
さらに深いところに、その数字を誰が測ったのかがあります。サーバが自分の処理時間を応答ヘッダで申告する仕組みが Server-Timing です。W3C の Working Draft(2026年4月7日版)が定義していますが、勧告ではなく、仕様自身が策定中のものとしてしか引用できないと断っています。その草案が、意図的に諦めたものを明記しています。
Because there can be no guarantee of clock synchronization between client, server, and intermediaries, it is impossible to map a meaningful startTime onto the clients timeline. For that reason, any startTime attribution is purposely omitted from this specification.
つまり Server-Timing は「長さ」しか運ばず、「いつ」は運びません。 クライアントの時間軸の上にサーバの申告した区間を置くことは原理的にできない、と仕様の側が認めています。分散編『見えるのは遅れた信号だけ — 他ノードの状態は直接には測れない』と同じ理由です。
単位も固定ではありません。草案は「Since this is not enforceable in practice, duration can represent any unit of time, and having it represent a duration in milliseconds is a recommendation」と書いています。dur=53 の 53 が何かは、送り手を信じるしかありません。
嘘をついている数字は1つも無いのに、時間が消える
同じ 50ms のアプリに、遅い中継を1段はさみました。中継は応答を 24 バイトずつ、間に 0.12 秒の休みを入れて送ります(狭い帯域を模した人工的な仕込みです)。
回 アプリ自身のログ time_starttransfer time_total1 58.1 ms 61.2 ms 1.072 s2 60.5 ms 62.3 ms 1.040 s3 51.4 ms 53.4 ms 1.052 s
どの数字も正しい。 アプリは本当に 50ms 程度しか働かず、最初の1バイトも本当にすぐ届き、全体も本当に1秒かかっています。消えた1秒は total - starttransfer、最初の1バイトより後ろに全部あります。
もう1つ、境界の内側に別の段が入る例。30ms かけて 302 を返す入口と、その先の 50ms のアプリを -L 付きで取りました。
redirects=1 time_redirect=0.035523 time_starttransfer=0.093974 time_total=0.094041redirects=1 time_redirect=0.033342 time_starttransfer=0.085910 time_total=0.086051redirects=1 time_redirect=0.036668 time_starttransfer=0.092157 time_total=0.092423
最終段のアプリは 50ms しか働いていないのに time_starttransfer は 86〜94ms。このうち 33〜37ms が time_redirect、捨てられた1回目のリクエストで、残る 53〜58ms が最終段にあたります。段ごとに測ったつもりで、1つの数字に2つの段が入っていました。
リダイレクトを追って取得したとき、time_starttransfer をそのまま「最終的なサーバの待ち時間」と読んでよいですか。
1リクエストの所要時間(今回)
名前解決・接続・サーバ待ち・本文転送が順に並び、その和が全体です。curl は境界ごとの累積を返すので引き算すれば区間が出ます。境界の定義から外れた段は隣の区間に吸収されます。
数字 含むもの 含まないものtime_starttransfer 接続・待ち・リダイレクト 本文の転送time_total 上のすべて + 本文転送 ブラウザの描画
台数が増えるまでの遅れ(仮想化編)
仮想化編『オートスケールは何を見て増やすか — 測定・判断・起動の遅れ』は、台数が増えるまでを3段に分けます。全体の遅れはこの和で、どれが長いかは分けて測るまで分かりません。
段 何をする 長さの決まり方測定 値を集めて届ける 収集の間隔判断 規則に照らして決める 評価の条件起動 実体を立ち上げる 起動の手順
HTTPの1リクエストと、オートスケールの台数追加。仕組みは違いますが、「遅い」と言われたときに同じ形の問いが立ちます。それは何でしょうか。
全体の数字だけを見ているとき、両方で同じことが分からなくなります。それが何かを考えてみてください。
この章のまとめ
- curl の時間変数は
time_queueを除いて累積値。区間にするには引き算が要る。 - 正しく引き算すれば和は
time_totalに一致する(定義上そうなる。実測で確かめる性質ではない)。合わないのは素朴に足したとき。超過率は段の比で決まるため目安にならない。 - 境界の内側に別の段が入る(リダイレクトが
time_starttransferに混ざる)、外側に時間が残る(TTFB は本文転送を含まない)。 Server-Timingは草案が startTime を意図的に外している。時計同期が保証できないため、クライアントの時間軸に並べられない。- だから測る前に段の境界を決めておく。決めずに取った数字は、あとから分解できない。
自分の現場で確かめる
読んだだけでは身につきません。手元の環境で実際に見てみてください。
理解度チェック
読んだ直後は「分かった」と感じやすいものです。実際に解いて確かめてください。
curl 公式の man が time_starttransfer について明示的に書いていることはどれですか。
用語集(4語)
- 累積値 / 区間値
- 累積値は「計測開始から、ある地点まで」の合計。区間値は「ある地点から次の地点まで」の長さ。curl の時間変数は time_queue を除き累積値。
- TTFB(最初の1バイトまでの時間)
- リクエスト開始から応答の最初の1バイトが届くまで。curl では time_starttransfer。本文の転送はこの後なので、本文が遅い障害は現れない。
- Server-Timing
- サーバや中継が、処理時間を応答ヘッダで申告する仕組み。W3C の Working Draft(2026年4月7日版)が定義。名前と長さ(dur)と説明(desc)を運び、開始時刻は運ばない。
- time_redirect
- curl の変数。最終的なやり取りが始まる前の、すべてのリダイレクト段に要した時間。リダイレクトを追うのは -L を付けたときだけ。