Пользователи видят 504. Как доказать, что портал ни при чем

В 14:14 пошли жалобы: портал не открывается, браузер показывает 504 Gateway Timeout. Через пятнадцать минут все заработало само. Накануне было то же самое, только короче.

При этом портал открывался у меня по VPN, без единой задержки. Значит, вопрос был не «что сломалось», а «где именно». И ответ на него нужен с цифрами: иначе разговор с сетевиками превращается в обмен мнениями, а следующий эпизод будет длиннее.

Почему 504 не значит «портал лег»

Между человеком и порталом на этом проекте стоит несколько звеньев: интернет пользователя, сервис защиты от DDoS, канал до сервера, nginx на самом сервере и уже за ним Битрикс24. Ошибку 504 отдает звено, которое не дождалось ответа от следующего. Ее может отдать nginx, если завис PHP. Но точно так же ее отдает защита от DDoS, если до сервера не дошел запрос.

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

Ниже пять проверок по порядку. Все делаются по журналу nginx на сервере портала, вместе занимают около 15 минут.

Пять проверок по логам nginx

1. Отдавал ли 504 наш nginx. Самый быстрый ответ на главный вопрос.

sudo awk '$8==504' /var/log/nginx/access.log | tail -5

Фильтровать надо по полю статуса, а не через grep "504". Grep найдет эти три цифры в именах временных файлов, в токенах, в адресах и даст ложную тревогу. Пустой вывод значит, что 504 отдал кто-то выше по цепочке.

2. Время ответа в минуты инцидента. Даже если nginx не отдавал 504, портал мог отвечать медленно.

sudo awk 'substr($4,14,5)>="14:14" && substr($4,14,5)<="14:28" {gsub("]","",$7); print $7}' \
  /var/log/nginx/access.log | sort -rn | head -5

Здесь в седьмом поле лог-формата записано время ответа, у вас поле может быть другим. Секунда-две значит, что портал работал нормально. Десятки секунд значат, что виноват он.

3. Поминутный трафик. Видно, был ли провал и когда начался.

sudo awk '{print substr($4,14,5)}' /var/log/nginx/access.log | uniq -c | tail -20

4. Внешний трафик отдельно от внутреннего. Это ключевая проверка.

sudo awk '$1 ~ /^203\.0\.113\./ {print substr($4,14,5)}' /var/log/nginx/access.log | uniq -c | tail -20

Вместо 203.0.113. подставьте адреса, с которых к вам приходит внешний трафик: защиты от DDoS, балансировщика или прокси. Все пользователи снаружи приходят на сервер с этих адресов. Офис и VPN идут мимо, со своих внутренних адресов.

Если внешние запросы в минуты инцидента пропали, а внутренние идут как обычно, рвется канал, а не портал. Так и выглядит обрыв канала: админ по VPN работает спокойно, а люди снаружи видят 504.

5. Ресурсы и потолки сервера. Последняя проверка снимает версию «сервер не принимал соединения».

uptime ; free -m | head -2
nstat -az | grep -E "ListenOverflows|ListenDrops"
cat /proc/sys/net/netfilter/nf_conntrack_count /proc/sys/net/netfilter/nf_conntrack_max
sudo ss -tn state established | wc -l

Главная цифра здесь ListenOverflows. Ноль значит, что очередь входящих соединений ни разу не переполнялась: сервер принимал все, что до него доходило. Если счетчик ненулевой и растет, виноваты уже мы.

Один эпизод или система

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

sudo zcat -f /var/log/nginx/access.log-2026031[3-8].gz \
 | awk '$1 ~ /^203\.0\.113\./ {print substr($4,2,11), substr($4,14,5)}' \
 | uniq -c | awk '$3 >= "08:00" && $3 <= "20:00" && $1 < 20'

Здесь легко ошибиться с порогом. Первый вариант, «меньше сотни запросов в минуту», в субботу и по вечерам ловил обычную тишину, а не обрывы. Рабочий порог вышел около 20 запросов в минуту при обычной тысяче, и только в рабочие часы.

Нашлось пять эпизодов:

Дата	Время	Длительность
12.03, чт	08:52–08:53	2 мин
12.03, чт	09:33–09:34	2 мин
12.03, чт	15:58–15:59	2 мин
18.03, ср	14:18–14:21	3–4 мин
19.03, чт	14:14–14:28	15 мин

Два последних начались около 14:15, и сначала это походило на задачу по расписанию. Остальные даты версию не подтвердили: время каждый раз разное. Зато длительность росла от двух минут до пятнадцати. Значит, ждать, что само пройдет, нельзя.

Портал во всех пяти случаях был исправен. Нагрузка 0.4, ответы за секунду, ни одного 504 в его журнале, потолки не тронуты.

Что написать сетевикам

Письмо «у нас 504, посмотрите» обычно возвращается с ответом «у нас все работает». Письмо с цифрами из проверок выше спорить не дает:

Пользователи получали 504 с 14:14 до 14:28. На стороне портала ошибок нет: nginx ни одного 504 не отдавал, время ответа около секунды, нагрузка 0.44, службы не перезапускались, очередь входящих соединений не переполнялась. Внешний трафик в эти минуты падал примерно с 1000 запросов в минуту до единиц, по VPN напрямую портал был доступен. За неделю таких эпизодов пять, длительность растет. Прошу проверить защиту от DDoS и канал до сервера.

В письме нет ни одной догадки: только то, что портал видел сам, и вывод, какой участок проверить. После него проблему нашли и устранили на стороне канала.

Чего не видно изнутри

У разбора по логам есть предел. Логи сервера показывают, что трафик исчез, но не показывают, где он потерялся. Пока сеть до сервера чужая, доказательство остается косвенным: «у нас все чисто, значит, у вас».

Прямое доказательство дает проба снаружи: машина вне контура компании, которая раз в 10 секунд открывает портал и пишет код ответа и время.

while true; do date +%H:%M:%S; curl -s -o /dev/null -w "%{http_code} %{time_total}\n" \
  --max-time 10 https://portal.example.ru/ ; sleep 10; done | tee ~/portal-probe.log

Если на портале уже были такие жалобы, такую пробу стоит запустить заранее, до следующего эпизода. Тогда в письме сетевикам будет не только «у нас чисто», но и точная минута, когда запросы снаружи перестали доходить.