Контейнер жил, а приложение внутри было мертво: healthcheck проверял не то

MAATRIX

Утром в понедельник в поддержку посыпались жалобы: сайт открывается, но кнопка «Оформить заказ» крутится и через полминуты падает с ошибкой. При этом docker ps показывал контейнер API в статусе healthy, зелёным горел Uptime Kuma, зелёной была и панель Prometheus. По всем формальным признакам сервис был жив — а по факту не мог обработать ни одного платного запроса. Разбор этого случая — хороший повод посмотреть, что на самом деле проверяет healthcheck, и почему «отвечает на HTTP» и «выполняет свою работу» — это два разных утверждения.

Что видели сначала

Стек был обычный для среднего проекта на VPS: Node.js API на Express, PostgreSQL как основная база, nginx как реверс-прокси перед контейнером, всё поднято через docker compose с restart: unless-stopped. В docker-compose.yml был healthcheck:

services:
  api:
    build: .
    restart: unless-stopped
    healthcheck:
      test: ["CMD", "curl", "-f", "http://localhost:3000/health"]
      interval: 30s
      timeout: 5s
      retries: 3
    depends_on:
      - db

Эндпоинт /health был в коде с первого дня проекта:

app.get('/health', (req, res) => {
  res.status(200).send('ok');
});

Простой, быстрый, ничего не делает — просто подтверждает, что процесс Node.js жив и слушает порт. Именно на него ходил и Docker healthcheck, и внешний монитор Uptime Kuma, и синтетический чек в Prometheus blackbox exporter.

Первые сигналы: nginx в логах начал писать upstream timed out (110: Connection timed out) while reading response header from upstream, то есть классический 504 Gateway Timeout. Но не по всем маршрутам — статические страницы и GET-запросы к каталогу отвечали нормально. Зависали именно запросы, которые писали в базу: оформление заказа, обновление профиля, добавление отзыва.

При этом docker stats показывал у контейнера API низкую загрузку CPU и обычное потребление памяти — процесс не был перегружен, не свопился, не убивался OOM killer. Он просто не отвечал на часть запросов, будто заснул только для некоторых типов работы.

Как разбирали инцидент по шагам

Первым делом прочитали логи приложения за последний час. Логи показывали, что запросы на /orders приходили («incoming POST /orders»), а строчки об ответе для части из них не было вообще — ни успеха, ни ошибки, просто тишина. Это отличало проблему от обычного падения: приложение не крашилось и не отдавало 500, оно зависало на середине обработки запроса и просто никогда не отвечало.

Дальше зашли в контейнер и посмотрели на процесс изнутри:

docker exec -it api sh
ps aux
# node процесс, один PID, CPU в норме
netstat -tnp 2>/dev/null | grep 3000
# видно много established соединений в LISTEN/ESTABLISHED, ничего экстремального

Ничего подозрительного на уровне сети или процесса. Значит, дело было не в самом HTTP-сервере — он прекрасно принимал соединения и на порт 3000, и отвечал на /health. Проблема была где-то дальше по цепочке обработки запроса.

Следующий шаг — посмотреть на базу. Зашли на PostgreSQL и подняли активность:

select pid, state, wait_event_type, wait_event, query, now() - query_start as duration
from pg_stat_activity
where datname = 'shop'
order by duration desc
limit 20;

Картина стала проясняться: несколько соединений от приложения висели в состоянии idle in transaction уже по несколько минут, а ещё десяток запросов ожидал wait_event_type = Client — то есть сами запросы к базе не выполнялись подолгу, они просто не могли начаться.

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

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

• Проблема сети между приложением и базой. Если бы рвались или деградировали TCP-соединения к PostgreSQL, здоровые запросы тоже бы страдали, а не только пишущие. Пинг и pg_isready с хоста приложения отрабатывали мгновенно и стабильно, так что сеть отпала быстро.
• OOM или рестарт контейнера. Посмотрели docker inspect api --format '{{json .State}}' — RestartCount был 0, OOMKilled — false. Контейнер работал непрерывно с момента последнего деплоя, никакого скрытого перезапуска не происходило.
• Троттлинг CPU по лимитам cgroup. Загрузка CPU в docker stats была далека от лимита, throttling-счётчики в /sys/fs/cgroup/cpu.stat тоже не росли — ресурсов контейнеру хватало с запасом.
• Медленный диск или высокая нагрузка на саму базу в целом. Обычные SELECT-запросы к каталогу товаров выполнялись с нормальной скоростью в это же самое время — проблема была локализована именно вокруг конкретных «пишущих» маршрутов, а не базы данных целиком.

Все эти версии были правдоподобны на бумаге, но конкретные данные — из pg_stat_activity, из docker inspect, из cgroup-счётчиков — последовательно их закрывали. Оставалось разобраться, что объединяет именно зависшие запросы.

Реальная причина: пул соединений съеден одним медленным маршрутом

Общим для зависших запросов был путь кода. Маршрут /orders при создании заказа делал так: открывал транзакцию в PostgreSQL, писал строку заказа, а затем — не закрывая транзакцию — синхронно дёргал внешний сервис уведомлений (webhook в Telegram-бота поддержки) и только после его ответа коммитил транзакцию. В коде это выглядело примерно так:

async function createOrder(req, res) {
  const client = await pool.connect();
  try {
    await client.query('BEGIN');
    await client.query('INSERT INTO orders ...', [...]);
    await notifySupportBot(orderPayload); // внешний HTTP-запрос без таймаута
    await client.query('COMMIT');
    res.json({ ok: true });
  } finally {
    client.release();
  }
}

В ту ночь у сервиса уведомлений начались собственные проблемы — он отвечал не ошибкой, а просто не отвечал вовсе, без таймаута на глобальном HTTP-клиенте. Каждый вызов notifySupportBot подвисал на неопределённое время. Пока он висел, соединение с базой, взятое из пула (client = await pool.connect()), не освобождалось — транзакция оставалась открытой, а клиент — занятым.

Пул соединений был настроен так:

const pool = new Pool({
  host: 'db',
  database: 'shop',
  max: 10,
});

Максимум 10 соединений, без connectionTimeoutMillis. Как только десятый одновременный запрос на создание заказа занял десятое соединение и завис на вызове к внешнему боту, пул оказался полностью исчерпан. Одиннадцатый запрос, ожидающий свободного соединения, вставал в очередь pool.connect() — и ждал бы бесконечно, потому что таймаут ожидания не был задан вовсе. Про устройство пула соединений и зачем он вообще нужен стоит почитать отдельно, если работаете с любой SQL-базой из приложения — почти все похожие инциденты растут из одной и той же непонятой детали: пул конечен, и то, что происходит при его исчерпании, целиком зависит от настроек таймаутов.

При этом маршрут /health был написан отдельно от всей этой логики — он ничего не спрашивал у базы и ни от какого пула соединений не зависел. Поэтому он продолжал мгновенно отвечать 200 OK, пока десятки реальных пользовательских запросов бесконечно ждали свободного соединения к PostgreSQL. Healthcheck исправно докладывал: «процесс жив, порт слушает» — и был в этом полностью прав. Просто это было не то утверждение, которое имело значение для пользователей.

Что изменили: разделили «жив» и «может работать»

Первое и главное исправление — переписали /health в два разных эндпоинта, по модели liveness/readiness, которую в контейнерном мире принято использовать даже без полноценного Kubernetes:

// живость процесса — быстро, ничего не проверяет по существу
app.get('/healthz/live', (req, res) => {
  res.status(200).send('ok');
});

// готовность обслуживать реальный трафик
app.get('/healthz/ready', async (req, res) => {
  try {
    const client = await pool.connect();
    try {
      await client.query('SELECT 1');
    } finally {
      client.release();
    }
    res.status(200).send('ready');
  } catch (err) {
    res.status(503).send('not ready');
  }
});

Важный нюанс: /healthz/ready тоже берёт соединение из общего пула, а не создаёт отдельное. Это специально — если пул исчерпан, проверка готовности тоже должна встать в очередь и в итоге упереться в свой собственный таймаут, честно показав проблему, а не обойти её через служебное подключение мимо основного пула.

Docker Compose healthcheck переключили на новый эндпоинт с явным лимитом времени на сам вызов curl:

healthcheck:
  test: ["CMD", "curl", "--max-time", "3", "-f", "http://localhost:3000/healthz/ready"]
  interval: 15s
  timeout: 5s
  retries: 3
  start_period: 20s

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

Второе исправление — задали таймаут ожидания свободного соединения в самом пуле, чтобы вместо бесконечного ожидания приложение быстро отдавало понятную ошибку:

const pool = new Pool({
  host: 'db',
  database: 'shop',
  max: 10,
  connectionTimeoutMillis: 3000, // не ждать пул дольше 3 секунд
  idleTimeoutMillis: 30000,
});

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

async function createOrder(req, res) {
  const client = await pool.connect();
  try {
    await client.query('BEGIN');
    await client.query('INSERT INTO orders ...', [...]);
    await client.query('COMMIT');
  } finally {
    client.release();
  }
  // соединение уже освобождено — внешний вызов больше не держит пул
  notifySupportBot(orderPayload).catch(err => log.warn('notify failed', err));
  res.json({ ok: true });
}

И на клиенте HTTP для внешних вызовов появился жёсткий таймаут (в данном случае через AbortController), чтобы «зависший навсегда» внешний сервис больше не мог превратиться в зависший навсегда обработчик внутри приложения.

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

Как проверить, что ваш healthcheck не наступит на те же грабли

Стоит честно ответить на несколько вопросов про каждый сервис в проекте:

• Что именно проверяет ваш /health — просто ответ HTTP-сервера или реальную способность выполнить запрос пользователя (сходить в базу, в кеш, во внешнюю зависимость, от которой реально зависит основной сценарий)?
• Есть ли у похода в базу/кеш/очередь из этого эндпоинта собственный короткий таймаут, отдельный от общего таймаута запроса?
• Что случится с контейнером, если healthcheck начнёт стабильно отдавать не-200: он перезапустится (restart: on-failure плюс дополнительная оркестрация) или просто продолжит числиться нездоровым, но никто не отреагирует?
• Совпадает ли эндпоинт, на который смотрит внешний мониторинг (Uptime Kuma, Prometheus blackbox, любой аптайм-сервис), с эндпоинтом Docker healthcheck — или это два независимых, по-разному написанных чека, которые могут расходиться в показаниях?

Таблица ниже — короткая шпаргалка по уровням проверки, которые стоит различать в одном сервисе:

Если в вашем стеке liveness и readiness исторически смешаны в один эндпоинт — это не катастрофа сама по себе, но именно тут стоит держать в голове: чем меньше проверка касается реальной работы сервиса, тем меньше она защищает от инцидентов вроде описанного.

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