Скрипт мониторинга сам положил сервер: разбор

MAATRIX

В четыре часа дня сайт начал отвечать через раз, потом перестал отвечать вовсе. Первая мысль — «опять приложение», вторая — «может, атака». А виноват оказался скрипт, который два года честно писали «на всякий случай» и который должен был сервер защищать. Разбираем по шагам, как мониторинг стал причиной отказа, почему это не сразу заметили и что сделать, чтобы у вас так не вышло.

Симптомы: что видел администратор

VPS на 4 CPU / 8 ГБ RAM, Ubuntu 24.04, PostgreSQL 16 и веб-приложение на Node.js за nginx. Внутренний магазин с каталогом заказов, около 12 миллионов строк в таблице orders. В 15:40 Uptime Kuma присылает алерт: отклик главной страницы вырос с 150-200 мс до нескольких секунд. В 15:52 — второй алерт, страница отдаёт 502. Администратор заходит по SSH (само подключение открывается с задержкой) и видит: load average 18-22 при 4 ядрах, память почти вся занята со свопом, Node.js жив, но не успевает отвечать за таймаут nginx, а PostgreSQL тормозит даже на простых запросах.

Логичный первый вывод — приложение утекает по памяти или поймало всплеск трафика. С этой гипотезы началась диагностика — и она увела в сторону на добрых сорок минут.

Первая гипотеза увела не туда

Трафик в логах nginx — обычный. В логах приложения — ошибки too many clients already при обращении к базе: это следствие, а не причина. Администратор перезапустил приложение на всякий случай — нагрузка ненадолго спала, но через 3-4 минуты вернулась. Стало ясно: лечили симптом, а причина возникает заново каждые несколько секунд.

Только после этого открыли pg_stat_activity:

SELECT pid, now() - query_start AS duration, state, query
FROM pg_stat_activity
WHERE state != 'idle'
ORDER BY duration DESC
LIMIT 20;

В выдаче — не один тяжёлый отчёт, а 34 почти одинаковых запроса вида SELECT count(*) FROM orders WHERE status='pending' AND created_at > now() - interval '1 day', все от одного пользователя БД — monitor_ro. Дальше уже было ясно, куда смотреть.

Как обнаружили настоящую причину

monitor_ro — учётка для скрипта мониторинга бизнес-метрик: сколько заказов в очереди, нет ли просроченных. Crontab выглядел безобидно:

* * * * * /opt/scripts/check_orders.sh >> /var/log/monitor/check_orders.log 2>&1

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

#!/bin/bash
# check_orders.sh
while true; do
  psql -U monitor_ro -d shop -t -c \
    "SELECT count(*) FROM orders WHERE status='pending' AND created_at > now() - interval '1 day';" \
    >> /var/log/monitor/pending.log
  psql -U monitor_ro -d shop -t -c \
    "SELECT count(*) FROM orders WHERE status='overdue';" \
    >> /var/log/monitor/overdue.log
  sleep 5
done

Cron запускает обёртку с бесконечным циклом внутри и sleep 5 — реальный интервал проверки раз в 5 секунд, а не раз в минуту, как думали полтора года. При этом ни на одном из запросов нет индекса по (status, created_at) — оба уходят в полное сканирование 12-миллионной таблицы. Полгода назад, при вдвое-втрое меньшей таблице, запрос укладывался в 200-300 мс и был незаметен. Сейчас — 1,5-2 секунды в спокойное время и до минуты под нагрузкой на диск.

Новый запрос стартует каждые 5 секунд независимо от того, завершился ли предыдущий. При замедлении до 20-30+ секунд копии накапливаются снежным комом: чем больше параллельных psql, тем медленнее выполняется каждый, тем быстрее плодятся новые. За 15-20 минут число процессов monitor_ro доходит до 30-40 и занимает почти весь пул соединений PostgreSQL — приложению не хватает свободного слота, отсюда too many clients already, из-за чего изначально подумали на приложение.

Хронология: как дошло до такого

Каждое изменение по отдельности выглядело безобидным. Никто не пересчитал совокупный эффект: интервал 5 секунд плюс рост таблицы в 6 раз плюс отсутствие индекса — бомба с фитилём, который поджёг обычный рабочий пик.

Что изменили: конкретные меры

Сначала убили процессы monitor_ro и переименовали скрипт — сервер пришёл в норму за 2-3 минуты без перезапуска приложения или базы. Дальше — четыре изменения по сути, а не по симптому.

1. Убрали лишний вес самой проверки. Точный count(*) заменили индексом:

CREATE INDEX CONCURRENTLY idx_orders_status_created
  ON orders (status, created_at);

Для метрики «сколько всего просрочено», где точность до единицы не нужна, взяли оценку из статистики планировщика вместо полного пересчёта:

SELECT reltuples::bigint AS approx_count
FROM pg_class WHERE relname = 'orders';

Индекс сократил время выполнения запроса pending-заказов с десятков секунд до нескольких десятков миллисекунд даже на полной таблице.

2. Добавили блокировку от параллельных копий. Убрали while true со sleep 5, вернули обычный интервал через cron и обернули запуск в flock, чтобы новый прогон не мог стартовать, пока не закончился предыдущий:

* * * * * /usr/bin/flock -n /tmp/check_orders.lock -c /opt/scripts/check_orders.sh

Флаг -n (--nonblock) значит: если предыдущий экземпляр держит лок, новый запуск тихо выходит, а не встаёт в очередь поверх старого.

3. Добавили таймаут, чтобы зависший процесс не держал соединение бесконечно:

* * * * * /usr/bin/flock -n /tmp/check_orders.lock -c "/usr/bin/timeout 20 /opt/scripts/check_orders.sh"

4. Сам мониторинг стал сам за собой следить. Скрипт пишет время старта и финиша в лог, а отдельная задача раз в час считает 95-й перцентиль длительности за сутки и шлёт алерт при росте вдвое относительно недели назад — сигнал именно о постепенной деградации, том самом эффекте, что копился пять месяцев незаметно.

Аудит совокупной нагрузки: чек-лист на будущее

Каждую проверку оценивали по отдельности («это же просто один count»), но никто не смотрел на сумму. Раз в месяц стоит делать простой аудит:

for u in $(cut -f1 -d: /etc/passwd); do
  crontab -l -u "$u" 2>/dev/null | grep -v '^#'
done

Для каждой задачи фиксируют три числа: интервал запуска, реальную длительность выполнения (замерить time в рабочие часы, а не ночью на пустом сервере) и что она читает — лёгкий вызов ОС (uptime, df -h) или тяжёлую операцию (запрос без индекса, обход файловой системы). Если длительность хотя бы одной проверки приближается к её интервалу — это кандидат на будущее наложение копий, даже если сегодня всё работает штатно. Отдельно стоит проверять полные обходы диска вроде find /var/www/uploads -type f | wc -l или du -sh на большом каталоге — на растущих данных такие вызовы незаметно превращаются из долей секунды в десятки секунд, та же ловушка, что и с count(*) без индекса, только на файловой системе.

Про поиск источника высокой загрузки, если картина неочевидна с первого взгляда, — в разборах высокая нагрузка на процессор: как найти причину и как узнать, кто нагружает сервер: те же ps aux --sort=-%cpu, iostat -x, pg_stat_activity полезны и когда виновато приложение, и когда виноват сам мониторинг. Если самописный мониторинг регулярно требует такого разбора граблей, сравнение затрат со сторонним сервисом — в статье цена мониторинга: платить за сервис или поднять своё.

Уроки: как не наступить на эти грабли

• Минимальный оверхед по умолчанию. Новая проверка проектируется как лёгкая: индексный запрос вместо полного сканирования, du --max-depth=1 вместо рекурсивного обхода миллионов файлов, кэшированные метрики вместо запроса «в лоб» к боевой базе на каждый тик. Тяжёлую операцию выносят в отдельный редкий прогон — раз в час или в сутки, а не в тот же цикл, что и лёгкий health-check.
• Обязательная защита от наложения. Любая периодическая проверка, обращающаяся к диску, БД или сети, оборачивается в flock -n (или lock-файл с PID). Без этого правила асимметрия «интервал короче реальной длительности» рано или поздно случится на растущем сервисе.
• Периодический пересмотр совокупной нагрузки. Не «настроили и забыли» — раз в месяц-квартал сверять весь список задач мониторинга с фактической длительностью, особенно после роста данных или трафика.
• Мониторинг мониторинга. Длительность и потребление ресурсов самих проверок — тоже метрика для алерта. «Это же просто мониторинг, он не может быть проблемой» — именно это допущение стоило серверу нескольких часов простоя.

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