Я достаточно ленивый и рациональный человек. В конце прошлого года у CloudFlare и его клиентов были непростые дни и утро Infra инженеров начиналось не с кофе. Плюс, те, кто много работает с CF знают про 503 и 520 ошибки и, если вы не на Enterprise тарифе, они также могу доставить неприятности. Хочу поделиться подходом и инструментом, которые помогли решить эти проблема и рационализировать/автоматизировать их решение в последствии.

Алерт в три часа ночи: время ответа выросло с 150 ms до 1.2 секунды. Или хуже — пользователи получают 502/503/504. Дежурный инженер открывает дашборд и видит красный график. Что-то тормозит. Но что именно?

Это CDN? Ingress? Приложение? База? Сеть между чем-то из вышеперечисленного? Каждый вариант ведёт к совершенно разному исправлению: перезапуск пода не поможет, если проблема в маршрутизации CDN, а звонок в поддержку хостера бесполезен, если у вас медленный SQL-запрос. Гадать дорого — особенно в три часа ночи.

В этой статье я покажу системный подход к поиску узкого места. Шаг за шагом, с минимумом телодвижений, используя данные, которые у вас скорее всего уже есть (или которые легко начать собирать). Акцент будет на CDN, Hosting Provider, Ingress.

Путь запроса

Прежде чем искать проблему, давайте зафиксируем, через какие этапы проходит типичный HTTP-запрос. Это простая архитектура, характерная для небольшой команды — но знакомая и наглядная(межсерверное взаимодействие в Netflix в качестве примера не будем использовать):

User  →  CDN  →  SLB (Nginx)  →  App(POD)  →  Connection Pooler  →  RDBMS

Шесть слоёв. Каждый может вносить свою задержку, свои ошибки — и каждый дает свои сигналы для диагностики.

Ключевое наблюдение: SLB (балансировщик, Nginx, HAProxy, ALB) сидит в центре и является вашей точкой отсчёта. Его логи подскажут, куда смотреть — налево (сеть, CDN) или направо (приложение, база).

Шаг 1. Точка опоры: логи балансировщика

Это лучший стартовый шаг — особенно если у вас еще нет развитого observability-стека и внешнего мониторинга. Достаточно Nginx access log.

Два ключевых значения:

Переменная Nginx

Что измеряет

$request_time

Полное время обработки запроса — от первого байта клиента до последнего байта ответа

$upstream_response_time

Время ожидания ответа от upstream (вашего приложения)

Если вы ещё не логируете эти значения, добавьте их в log_format:

log_format timing '$remote_addr - $request_uri '
                  'status=$status '
                  'rt=$request_time '
                  'uct=$upstream_connect_time '
                  'urt=$upstream_response_time';

access_log /var/log/nginx/access.log timing;

Теперь у вас есть главный диагностический инструмент.

Как читать

$request_time включает всё, что происходит на стороне балансировщика: медленных клиентов, TLS-хендшейк, маршрутизацию CDN, передачу тела ответа. $upstream_response_time — только то, сколько ваше приложение думало.

Правило:

  • $upstream_response_time большой (близок к $request_time) — узкое место справа от балансировщика: приложение, пул соединений или база. Идём в Шаг 2.

  • $upstream_response_time нормальный, а $request_time значительно больше — узкое место слева: сеть между пользователем и CDN, или сам CDN. Идём в Шаг 3.

Это одно сравнение — и вы уже отсекли половину возможных причин.

Нюанс про $request_time в заголовках. Если вы инжектите $request_time в заголовок ответа через add_header, значение будет неточным: Nginx записывает заголовки до того, как закончит передавать тело ответа клиенту. Реальный $request_time доступен только в access log, где он вычисляется после закрытия соединения.

Шаг 2. Вправо: приложение и база

Вы установили, что балансировщик долго ждал ответа от upstream. Теперь нужно понять, где именно. Для простого WEB App частые варианты со собеседований: в приложении, в пуле соединений или в базе, но в реальном мире их сильно больше: походы в 3rd party service, CPU bound операции внутри App или блокировки, etc. Эта часть пайплайна — территория APM (Application Performance Monitoring). Но если APM у вас пока нет, есть лёгкий способ получить видимость извне: HTTP-заголовок Server-Timing.

Server-Timing: стандарт W3C, по-моему скромному мнению используемый реже чем стоило бы

Server-Timing — это стандартный HTTP-заголовок, через который приложение может сообщить клиенту, сколько времени заняла каждая внутренняя операция:

Server-Timing: app;dur=120, db;dur=95, pool-wait;dur=18

Здесь приложение говорит: всего 120 ms, из них 95 ms — запрос к базе, 18 ms — ожидание свободного соединения в пуле. Любой внешний мониторинг (или даже curl -v) увидит эти значения. Современные WEb browsers так же рисуют красивые диаграммы дополняя стандартный Break Down времени запроса значениями от сервера. Смотреть вот тут DevTools -> Network -> <выбрать request> -> Timing.

Как добавить Server-Timing в ваше приложение

Go (net/http):

start := time.Now()
rows, err := db.QueryContext(ctx, query)
dbDur := time.Since(start)

w.Header().Set("Server-Timing",
    fmt.Sprintf("db;dur=%.2f", float64(dbDur.Microseconds())/1000))

Python (Django middleware):

class ServerTimingMiddleware:
    def __init__(self, get_response):
        self.get_response = get_response

    def __call__(self, request):
        start = time.monotonic()
        response = self.get_response(request)
        dur = (time.monotonic() - start) * 1000
        response["Server-Timing"] = f"app;dur={dur:.2f}"
        return response

Node.js (Express):

app.use((req, res, next) => {
  const start = process.hrtime.bigint();
  res.on('finish', () => {
    const ms = Number(process.hrtime.bigint() - start) / 1e6;
    // уже отправлено, но для логирования:
    console.log(`Server-Timing: app;dur=${ms.toFixed(2)}`);
  });
  // для заголовка — засекаем до ответа:
  const origEnd = res.end;
  res.end = function(...args) {
    const ms = Number(process.hrtime.bigint() - start) / 1e6;
    res.setHeader('Server-Timing', `app;dur=${ms.toFixed(2)}`);
    origEnd.apply(this, args);
  };
  next();
});

Тут чуть сложнее, чем одна строка. Нельзя просто поместить $upstream_header_time в add_header — если upstream нет (статика, ошибка), переменная будет -, и заголовок сломается. Используем map:

Nginx (upstream timing как Server-Timing):

      # В http {} блоке nginx.conf:
      map $upstream_header_time $server_timing_upstream {
      "-"     "";
       default "ngx-upstream;dur=$upstream_header_time;desc=\"NgxUpstream\"";
      }

      # В location {} блоке вашего сервера:
      add_header Server-Timing-Ngx "ngx-total;dur=$request_time;desc=\"NgxTotal\"" always;
      add_header Server-Timing-Ngx $server_timing_upstream always;

Обратите внимание: мы используем Server-Timing-Ngx, а не Server-Timing — тк nginx вщзвращает время в секундах, в WEB browser требует в миллисекундах. Также используем $upstream_header_time (время до получения заголовков от upstream), а не $upstream_response_time (время до конца всего ответа) - это связано с тек как nginx заполняет значения в переменных, в противном случае значение будет нулевым.

Это несколько строк конфига — и у вас есть видимость внутренних таймингов Nginx через стандартный HTTP-заголовок. Без агентов, без vendor lock-in, без APM.

Что искать

Сигнал

Вероятная причина

db;dur доминирует

Медленный запрос, отсутствующий индекс, блокировка таблицы

pool-wait;dur большой

Пул соединений исчерпан — все соединения заняты, новые запросы ждут в очереди. Проверьте размер пула в PgBouncer или лимиты соединений в приложении

app;dur большой, db;dur маленький

Проблема в самом приложении — CPU-intensive вычисление, блокирующий I/O, нехватка памяти

502 или 504 от балансировщика

Upstream упал (502 Bad Gateway) или не ответил вовремя (504 Gateway Timeout). Смотрите логи приложения

Если приложение пока не отдаёт Server-Timing, сам факт большого $upstream_response_time в логах Nginx уже говорит, что проблема за балансировщиком. Используйте логи приложения, slow query log базы или — если есть — APM для дальнейшей диагностики.

Шаг 3. Влево: HTTP breakdown

Балансировщик рапортует нормальный upstream time — значит, проблема между пользователем и балансировщиком. Теперь нужно понять, где именно.

6 фаз HTTP-запроса

Каждый HTTP-запрос можно разложить на шесть последовательных фаз:

Фаза

Что измеряет

На что указывает большое значение

DNS

Резолвинг имени

Медленный или нестабильный DNS-резолвер

Connect

TCP-хендшейк

Высокая сетевая задержка до ближайшего edge (CDN PoP)

TLS

TLS-хендшейк

Проблемы с цепочкой сертификатов, отсутствие TLS session resumption, задержка усиленная несколькими round trip’ами

Send

Отправка запроса

Обычно пренебрежимо мало

Wait (TTFB)

Время до первого байта ответа

Если Connect и TLS маленькие — это время обработки на CDN edge или origin fetch

Receive

Получение тела ответа

Медленная передача данных, маленький congestion window

Вот как это выглядит на практике. Три реальных примера:

Проблема с TLS (278 ms, из них TLS — 229 ms): Хендшейк занял 82% времени. Сервер за StormWall без CDN, чекер в Амстердаме. TLS 229 ms при Connect 7 ms — это не сеть, а именно TLS: вероятно, нет session resumption, длинная цепочка сертификатов, или дополнительные round trip’ы из-за TLS 1.2.

https://oack.io/ screenshot: waterfall с TLS 229 ms
https://oack.io/ screenshot: waterfall с TLS 229 ms

Проблема с DNS (360 ms, из них DNS — 331 ms): DNS-резолвинг занял 92% времени. Connect 1 ms, TLS 6 ms — сеть быстрая. Проблема в DNS-резолвере или в долгой цепочке CNAME/NS.

https://oack.io/ screenshot: waterfall с DNS 331 ms
https://oack.io/ screenshot: waterfall с DNS 331 ms

Здоровый запрос (59 ms): DNS 3 ms, Connect 1 ms, TLS 7 ms, Wait 47 ms. Все фазы в норме, основное время — ожидание ответа от origin.

https://oack.io/ screenshot: waterfall 59 ms
https://oack.io/ screenshot: waterfall 59 ms

Как читать breakdown

  • Connect и TLS большие → проблема между пользователем и CDN edge. Смотрите сетевые метрики (Шаг 4).

  • Connect и TLS маленькие, Wait большой → проблема на CDN edge (WAF, Workers, bot detection) или между CDN и origin. Смотрите CDN-слой (Шаг 5).

Шаг 4. TCP_INFO: что знает ядро

HTTP breakdown говорит, что медленно. TCP-метрики говорят, почему.

На Linux каждое TCP-соединение отслеживается ядром. Через системный вызов getsockopt(TCP_INFO) можно получить десятки метрик прямо из ядра: RTT, ретрансмиты, congestion window, RTO, и многое другое.

Четыре ключевых метрики:

Метрика

Что показывает

RTT

Реальное время round trip, измеренное ядром. Точнее, чем HTTP timing, потому что не включает время обработки на сервере

Retransmits

Количество повторно отправленных сегментов. Даже один ретрансмит добавляет полный RTO (часто 200+ ms) задержки

Cwnd (congestion window)

Сколько данных ядро готово отправить без подтверждения. Маленький cwnd = ядро обнаружило потери и тормозит отправку

RTO (retransmission timeout)

Таймаут для ретрансмита. Растет при нестабильной сети

Почему RTT из ядра важнее, чем TTFB

Когда ответ сервера достаточно маленький (вмещается в один TCP-сегмент), HTTP timing не может отличить сетевую задержку от времени обработки — фазы Wait и Receive сливаются в одну. Но ядро знает точный RTT. Вычтите RTT из Wait — и получите реальное время обработки на стороне сервера.

Три реальных примера

Высокий RTT (2589 ms, total 7.4s): RTT 2589 ms, RTO 9534 ms, Total Retrans 3. Connect 3318 ms, TLS 1321 ms. Трассировка — 24 хопа. Сеть сама по себе медленная: географическое расстояние, перегруженный пиринг или плохая маршрутизация.

https://oack.io/ screenshot: TCP Statistics — RTT 2589 ms
https://oack.io/ screenshot: TCP Statistics — RTT 2589 ms

Ретрансмиты (total 8.4s, но RTT всего 9.4 ms): RTT 9.4 ms — сеть быстрая! Но Total Retrans 12, cwnd обрушился до 2. Connect 4087 ms, TLS 3459 ms. Парадокс: RTT маленький, а всё тормозит. Причина — потеря пакетов. Каждый ретрансмит добавляет полный RTO. Cwnd 2 означает, что ядро почти перестало отправлять данные.

https://oack.io/ screenshot: TCP Statistics — 12 retrans, cwnd 2
https://oack.io/ screenshot: TCP Statistics — 12 retrans, cwnd 2

Здоровое соединение (64 ms total): RTT 1.1 ms, 0 ретрансмитов, cwnd 10. Всё в норме.

https://oack.io/ screenshot: TCP Statistics — RTT 1.1 ms, cwnd 10
https://oack.io/ screenshot: TCP Statistics — RTT 1.1 ms, cwnd 10

Как получить TCP_INFO

Стандартные мониторинг-инструменты обычно не собирают TCP_INFO — они либо оборачивают curl, либо используют готовые HTTP-библиотеки, которые не дают доступа к сокету.

Мы в oack.io / ru.oack.io написали сетевые тестеры с нуля — не обёртки вокруг curl или libcurl, а собственная реализация, контролирующая весь жизненный цикл запроса: от DNS-резолвинга и TCP-хендшейка через TLS-негоциацию до парсинга ответа. Это позволяет инструментировать каждый слой и вытаскивать полную tcp_info структуру из ядра на каждом запросе.

Если вы хотите делать это самостоятельно, базовый подход на Go:

conn, _ := net.Dial("tcp", "example.com:443")
tcpConn := conn.(*net.TCPConn)
rawConn, _ := tcpConn.SyscallConn()

rawConn.Control(func(fd uintptr) {
    info, _ := syscall.GetsockoptTCPInfo(int(fd), syscall.IPPROTO_TCP, syscall.TCP_INFO)
    fmt.Printf("RTT: %d us, Retransmits: %d, Cwnd: %d\n",
        info.Rtt, info.Retransmits, info.Snd_cwnd)
})

Шаг 5. CDN: кеш, PoP-маршрутизация, edge-логи

Если Connect и TLS маленькие, а Wait большой — и при этом балансировщик рапортует быстрый upstream — время тратится на CDN edge.

Кеш: HIT vs MISS

Заголовок Cf-Cache-Status (для Cloudflare) сразу говорит, откуда пришёл ответ:

  • HIT — ответ из кеша edge-ноды. Быстро, origin не трогали.

  • MISS — edge пошёл на origin за данными. CDN-to-origin путь может быть значительно медленнее, чем user-to-CDN.

  • DYNAMIC — контент не кешируется.

Пример: Cache HIT

Server-Timing: cfCacheStatus;desc="HIT", cfEdge;dur=5, cfOrigin;dur=0
Cf-Cache-Status: HIT
Age: 30

cfEdge 5 ms, cfOrigin 0 ms. Ответ из кеша, origin не вовлечён.

Пример: Cache MISS

Server-Timing: cfCacheStatus;desc="MISS", cfEdge;dur=7, cfOrigin;dur=215
Cf-Cache-Status: MISS

cfEdge 7 ms, но cfOrigin 215 ms — edge ходил на origin. Если ваш $upstream_response_time на Nginx был 2 ms, значит 213 ms потерялись между CDN edge и вашим origin. Это может быть: географическое расстояние между PoP и origin, или CDN устанавливал новое TLS-соединение к origin вместо реюза из пула.

Cloudflare Server-Timing

Cloudflare автоматически добавляет Server-Timing заголовок с cfEdge и cfOrigin. Это бесплатно и доступно на всех тарифах. Сравните cfEdge;dur с wait_ms вашего HTTP breakdown:

  • cfEdge маленький, wait_ms большой → время тратится до CDN (сеть) или CDN doing extra work (WAF, Workers)

  • cfEdge большой → сам CDN edge медленный

PoP-маршрутизация

CDN использует anycast: запрос идёт на ближайшую edge-ноду. Но “ближайшая” определяется BGP-маршрутизацией, а не географией. Иногда запрос из Франкфурта улетает в Вирджинию.

Сравните CDN PoP на “хорошем” запросе и на “плохом”:

Хороший запрос

Плохой запрос

CDN PoP

FRA (Франкфурт)

IAD (Вирджиния)

Traceroute

5 хопов, RTT ~8 ms

12 хопов, RTT ~120 ms

connect_ms

12 ms

180 ms

Если PoP сменился — проверьте статус CDN-провайдера для этого PoP. Outage или maintenance на edge-ноде может перенаправить трафик на дальний PoP.

Диагностика: два монитора через разные CDN

Если вы подозреваете проблему между CDN и origin, но CDN для вас — чёрный ящик:

  1. Создайте второй HTTP-монитор, который ходит на тот же origin через другой CDN (или напрямую). Используйте CDN с оплатой по трафику(PAYG) — это копейки для диагностического пайплайна.

  2. Оба монитора показывают проблему → проблема на стороне хостинга. Открывайте тикет.

  3. Только основной CDN показывает проблему → проблема в CDN. Звоните в их поддержку с PoP-кодами и трассировками. Если нужно открывать тикет в саппорте хостера, тут как карта ляжет. Честь и хвала тем support engineers на стороне CDN и хостеров, которые выходят за рамки дефолтного скрипта, находят и шарят advanced телеметрию. Но я часто сталкивался с тем, что саппорт выкручивает соски клиенту - сразу требуют тучу телеметрии: traceroute до PoP в момент проблемы, MTR/iperf и тд Тут сильно помогают внешние мониторинги с богатой телеметрией.

Шаг 6. Перцентили: а точно ли это аномалия?

Прежде чем бросаться чинить, стоит убедиться, что текущие значения действительно аномальные. Wait 200 ms может быть катастрофой для одного эндпоинта и нормой для другого.

Идея простая: для каждой фазы (DNS, Connect, TLS, Send, Wait, Receive) посчитайте перцентили(score rank) текущего значения относительно исторических данных. Ранг показывает, какой процент запросов имел меньшее значение.

Фаза

Значение

1d

7d

30d

DNS

3 ms

42%

38%

38%

Connect

180 ms

96%

97%

97%

TLS

420 ms

94%

95%

95%

Wait

85 ms

55%

52%

52%

Total

690 ms

88%

91%

91%

Connect на 97-м перцентиле — 97% запросов за последние 7 дней были быстрее. Это явная аномалия. Wait на 52-м — абсолютная норма, не нужно его трогать.

Правило: ниже ~70% — норма, можно скипать. Выше ~90% — что-то изменилось, копайте. Стабильный ранг по всем временным окнам (как 97% по Connect здесь) указывает на структурную проблему, а не разовый всплеск.

Итоговая таблица: дерево решений

#

Проверка

Да

Нет

1

$upstream_response_time большой?

Проблема справа → App/DB (Шаг 2)

Проблема слева → сеть/CDN (Шаг 3)

2

connect_ms или tls_ms повышены?

Сетевая проблема User ↔ CDN → TCP_INFO (Шаг 4)

CDN или CDN ↔ origin (Шаг 5)

3

CDN PoP сменился по сравнению с нормой?

Проблема маршрутизации → статус-страница CDN

CDN-to-origin проблема

4

Оба CDN-монитора показывают проблему?

Проблема хостинга → тикет провайдеру

Проблема конкретного CDN → звонок в поддержку

5

Server-Timing показывает большой db;dur?

Проблема в базе → slow query log

Проблема в приложении → логи / APM

Я слышал чтение коллективом в слух дает еще одну девятку в uptime, но на время.

Вместо заключения

Все сигналы, описанные в этой статье — HTTP breakdown, TCP_INFO, Server-Timing, CDN-логи, трассировку, перцентили — мы собрали на одном экране в oack.io / ru.oack.io. Каждая проба автоматически захватывает полный набор данных, и вы можете пройти по этому дереву решений за пару кликов.

Но подход работает и без нас. Nginx логи с $request_time и $upstream_response_time + заголовок Server-Timing в приложении + голова — это уже 80% диагностики. Начните с логов балансировщика, добавьте Server-Timing в приложение (это 5 строк кода), и у вас будет фундамент, на который можно наращивать observability.


А как вы диагностируете латенси на проде? Какие сигналы смотрите в первую очередь? Используете ли Server-Timing? Делитесь в комментариях — интересно послушать о реальных кейсах.

Если я со страниц этой статьи разговаривал не сам с собой и это представляет интерес - накидайте плюсов. Тогда сделаю еще статью, как упростить и ускорить поиск root cause при помощи code agent и MCP.

Комментарии (0)