Разница в 40 мс между дата-центрами удвоила время оформления заказа

MAATRIX

Оформление заказа вдруг стало ощутимо медленнее — без деплоя, без роста нагрузки, без видимых причин. Команда две недели искала «тормозящий SQL-запрос», хотя на самом деле проблема была не в коде и не в базе, а в географии: сервер приложения и база данных с кешем физически разъехались по разным дата-центрам, а транзакция оформления заказа делала к базе не один запрос, а полтора десятка последовательных. Это разбор того инцидента — что видели, какие версии отбросили и почему в итоге всё упёрлось в скорость света.

Что сломалось: заказ стал оформляться вдвое дольше

Первый сигнал пришёл не от мониторинга, а от поддержки: клиенты жаловались, что кнопка «Оформить заказ» «висит». Дашборд APM подтвердил — среднее время обработки запроса POST /checkout выросло примерно в два раза относительно недельной давности, и рост держался стабильно, а не скачками. Ключевая деталь, которая сначала всех запутала: остальные ручки API — каталог, карточка товара, поиск — работали как обычно. Просадка была локализована именно в checkout.

Второй сигнал — рост числа открытых соединений к базе и лёгкое, но заметное увеличение очереди в пуле приложения. Ошибок при этом почти не было: запросы не падали по таймауту, они просто выполнялись дольше, чем раньше. Это сразу отсекло версию про «база легла» — база отвечала, просто с задержкой, которой раньше не было.

Что видели в логах и метриках

Начали с трассировки одного запроса через APM (в духе Jaeger или встроенного трейсинга фреймворка). Трейс checkout раскладывался на десяток с лишним последовательных спанов к базе и кешу: проверить наличие товара на складе, получить актуальную цену, проверить купон, зарезервировать позицию, посчитать доставку, записать заказ, обновить счётчик остатков, инвалидировать кеш карточки товара, записать событие в очередь аналитики — и так далее. Каждый спан по отдельности выглядел безобидно: 40-50 мс. Проблема была в том, что раньше эти же спаны занимали единицы миллисекунд, а не десятки.

Дальше смотрели метрики самой базы: pg_stat_statements не показывал ни одного запроса с аномальным mean_exec_time — время выполнения запросов *на стороне базы* было прежним. Загрузка CPU и I/O на сервере БД — в норме. Blocking locks — пусто, pg_locks чистый. Это был важный поворотный момент: если база выполняет запрос быстро, а клиент видит его медленным, разница — это не выполнение, а путь запроса туда и обратно.

Проверили это напрямую — сняли тайминг сетевого round-trip между app-сервером и базой:

# грубая, но показательная проверка через psql \timing
psql -h db-primary.internal -U app -d shop -c '\timing' -c 'SELECT 1;'
# Time: 41.732 ms

# то же самое локально на сервере с базой
psql -h localhost -U app -d shop -c '\timing' -c 'SELECT 1;'
# Time: 0.412 ms

Разница почти в сто раз на пустейшем SELECT 1 — красноречивый признак того, что дело не в базе, а в сети между ней и приложением.

Гипотезы, которые отбросили

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

• Медленный SQL из-за деградировавшего индекса. Прогнали EXPLAIN (ANALYZE, BUFFERS) по всем запросам из трейса checkout — планы не изменились, индексы использовались, Execution Time в плане был низким. Версию закрыли.
• Раздутие таблиц и autovacuum не успевает. Проверили pg_stat_user_tables, n_dead_tup — в пределах нормы, autovacuum отрабатывал по расписанию. Не подтвердилось.
• Голодание пула соединений. Подозревали, что пул приложения слишком мал и запросы стоят в очереди на получение коннекшена. Метрика pool_wait_time действительно чуть выросла, но это оказалось следствием, а не причиной: каждое соединение просто дольше «занято» из-за задержки round-trip, поэтому очередь на пул и выросла — но её причина лежала на уровень ниже. О том, как устроен пул и что он лечит, а что нет, — в отдельном материале про connection pool и зачем он нужен.
• Проблема на стороне CDN или балансировщика перед приложением. Проверили тайминги на входе — время до app-сервера было стабильным, рост появлялся именно между app и базой.
• «Кто-то поменял конфиг базы». Проверили историю изменений postgresql.conf, shared_buffers, work_mem — ничего не трогали уже месяц.

Каждая гипотеза стоила времени, но именно их последовательное исключение и привело к правильному вопросу: а где физически находятся сервер приложения и сервер базы друг относительно друга?

Реальная причина: приложение и база оказались в разных дата-центрах

Ответ нашёлся в истории миграций инфраструктуры. Несколько недель назад часть read-реплик и Redis-кеш были перенесены на более свежее железо в другой дата-центр — формально «для балансировки нагрузки и подготовки к росту». Основная база оставалась на месте, но приложение по факту начало чаще резолвить внутренний DNS-алиас кеша на инстанс в новом ДЦ, а часть трафика к БД тоже мигрировала туда постепенно, по мере переключения зон. В итоге сложилась топология, которую никто не спроектировал целиком и никто не увидел на одной схеме: app-сервер остался в дата-центре A, а часть его зависимостей — в дата-центре B.

Проверили это traceroute/mtr и сравнением с картой локаций:

mtr -rw -c 20 db-primary.internal
# ...
# 6.|-- core-b.dc-transit.example        0.0%    20  38.9  39.4  38.2  41.1   0.6
# 7.|-- db-primary.dc-b.internal         0.0%    20  40.2  40.7  39.8  42.0   0.5

Физическая задержка между дата-центрами в этой паре была в районе 40 мс в одну сторону — это укладывается в типичные ориентиры для межрегиональных соединений (условно, для сравнения RTT между разными локациями есть удобная таблица ориентиров по latency между локациями). Внутри одного дата-центра тот же round-trip укладывается в доли миллисекунды. Сама по себе такая задержка не выглядит катастрофой — 40 мс на один запрос почти никто не заметит. Проблема была не в одном запросе, а в их количестве внутри одной транзакции.

Как посчитали множитель: latency × число последовательных запросов

Транзакция checkout в коде приложения была написана как последовательная цепочка await-вызовов к базе и кешу — каждый следующий шаг ждал завершения предыдущего, потому что логически зависел от его результата (нельзя зарезервировать товар, не проверив остаток; нельзя посчитать доставку, не зная итоговую цену после купона). Упрощённо это выглядело так:

async def checkout(order):
    stock = await db.check_stock(order.sku)          # round-trip 1
    price = await db.get_price(order.sku)             # round-trip 2
    coupon = await db.validate_coupon(order.coupon)   # round-trip 3
    await db.reserve_stock(order.sku, order.qty)       # round-trip 4
    shipping = await shipping.calc(order.address)      # round-trip 5
    order_id = await db.insert_order(order)             # round-trip 6
    await db.update_stock_counter(order.sku)            # round-trip 7
    await cache.invalidate(f"product:{order.sku}")      # round-trip 8
    await queue.publish("order.created", order_id)      # round-trip 9
    return order_id

Пока приложение и база сидели в одном дата-центре, round-trip каждого шага стоил меньше миллисекунды, и вся цепочка из девяти последовательных обращений почти не была заметна на фоне остального времени обработки запроса. Как только часть этих обращений стала уходить в соседний ДЦ с задержкой около 40 мс на одну сторону, каждый такой шаг начал добавлять к общему времени запроса заметную фиксированную «дань» — независимо от того, насколько быстро сама база или кеш выполняли запрос по существу.

Математика здесь простая и в этом весь эффект: суммарная сетевая составляющая транзакции — это не latency одного запроса, а latency, умноженная на число последовательных шагов, которые физически пересекают границу между ДЦ. Девять шагов вместо одного — это не +40 мс, а кратно больше, и именно эта сумма легла поверх времени, которое раньше почти не было видно на графиках. Отсюда и наблюдаемое удвоение времени оформления заказа: часть шагов транзакции продолжала выполняться локально (расчёт доставки, часть кеша), а часть — с задержкой между ДЦ, и на графике p95 это дало кумулятивный, а не одиночный скачок.

Отдельно стоит отметить: если бы эти девять запросов выполнялись параллельно, а не последовательно, множитель бы не сработал — задержка добавилась бы один раз, а не девять. Но по бизнес-логике часть шагов действительно зависела от результата предыдущих, так что распараллелить можно было не всё.

Что изменили

Правки разделили на немедленные и системные — по опыту это правильный порядок: сначала снять боль, потом убрать причину, чтобы она не вернулась через месяц в другом виде.

Сразу. Вернули читающий трафик и Redis-кеш checkout-пути в тот же дата-центр, что и сервер приложения — это была временная, но самая быстрая мера, снявшая проблему за один релиз конфигурации без изменения кода.

После этого — по коду. Пересмотрели цепочку checkout на предмет того, что действительно обязано быть последовательным, а что можно объединить или распараллелить:

• Проверку остатка, получение цены и валидацию купона объединили в один запрос через SELECT ... FOR UPDATE с несколькими условиями вместо трёх отдельных обращений.
• Обновление счётчика остатка и инвалидацию кеша карточки товара, которые не блокируют ответ пользователю, вынесли за пределы синхронной транзакции — в фоновую очередь после insert_order, по паттерну «сначала подтвердить заказ, потом донастроить побочные эффекты асинхронно».
• Публикацию события в очередь аналитики сделали fire-and-forget без ожидания ack на критическом пути.

В итоге в синхронной части транзакции осталось четыре-пять действительно необходимых последовательных обращений вместо девяти — и множитель latency стал меньше сам по себе, независимо от топологии дата-центров.

Системно. Договорились, что зависимости одного сервиса — приложение, его основная БД и горячий кеш — по умолчанию живут в одном дата-центре, а межрегиональная репликация используется только для отказоустойчивости и чтения нечувствительных к latency данных (аналитика, отчёты, холодные реплики для DR), а не для обслуживания синхронного пути транзакции. Также договорились не переносить компоненты инфраструктуры по частям без карты зависимостей — тот перенос кеша делали «постепенно», и именно постепенность скрыла проблему до момента, пока она не накопилась целиком.

Как теперь ловим такое заранее

После разбора добавили несколько простых, но конкретных механизмов, которые не требуют новой инфраструктуры:

• Метрика latency между дата-центрами как отдельная панель в Grafana, с алертом, если p95 round-trip между app-нодами и БД/кешем превышает пороговое значение для «локального» трафика (условно — единицы миллисекунд). Это не заменяет мониторинг самой базы, а закрывает слепую зону между ними.
• Чек в код-ревью для новых эндпоинтов с несколькими последовательными обращениями к БД: если в одной синхронной цепочке больше трёх-четырёх round-trip, ревьюер обязан спросить, можно ли их объединить или распараллелить, и явно указать, в каком ДЦ ожидается выполняться каждая зависимость.
• Трассировка (в духе Jaeger) включена по умолчанию на checkout-пути — именно она в итоге дала первую зацепку, и теперь по ней раз в неделю смотрят, не появилась ли новая длинная цепочка последовательных спанов.
• Явная схема топологии сервисов и их зависимостей — какой компонент в каком дата-центре — обновляется при любом переносе инфраструктуры, а не только «в голове» у того, кто делал перенос.

Для тех, кто переносит базу данных между площадками, полезно заранее прикинуть похожий сценарий — есть отдельный разбор о том, как перенос базы обернулся тормозами, где причины отчасти пересекаются с этим кейсом, но добавляются свои нюансы.

Частые вопросы