Как читать journalctl, когда сервис запущен, но ничего не делает

Обсудить
Как читать journalctl, когда сервис запущен, но ничего не делает
Реклама. АО «ТаймВэб». erid: 2W5zFH2tety

Летом на Хабре разработчик описал случай, в котором узнают себя владельцы небольших проектов на VPS. Одна и та же строка повторялась в логах четыре дня подряд, а бот всё это время исправно отвечал на сообщения. Заметили проблему только потому, что дневной дайджест пришёл пустым.

Вывод из этой истории он сформулировал через свежесть результата – мерить надо последнюю обработанную единицу работы. Живой процесс об этом не говорит ничего. systemctl status в подобной ситуации показывает зелёный active (running) и к диагностике не добавляет почти ничего, а логи journalctl показывают, на чём приложение встало.

Почему systemctl status показывает зелёное

Команда systemctl status отвечает на вопрос о состоянии процесса, тогда как вас интересует состояние работы. Юнит считается активным, пока процесс не завершился, и внутренний цикл, застрявший на повторных попытках к внешнему API, для systemd выглядит нормальной работой.

Второе ограничение практическое. По документации systemctl(1) эта команда показывает десять последних строк журнала и обрезает их по ширине терминала. Флаг --full, он же -l, снимает обрезание строк, но десять строк остаются десятью, поэтому число задаётся отдельно через -n:

systemctl status myapp.service --no-pager -l -n 100
journalctl -u myapp.service -n 200 --no-pager

У journalctl число строк тоже нужно называть явно, потому что без аргумента -n отдаёт те же десять.

Два разных места, где лежат логи

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

Журнал systemd ведёт демон systemd-journald. Он собирает всё, что процессы под управлением systemd пишут в стандартный вывод и в поток ошибок, плюс сообщения ядра. Формат бинарный, читается только утилитой journalctl. Файлы лежат в /var/log/journal/ в подкаталоге с идентификатором машины, когда журнал постоянный, или в /run/log/journal/, и тогда они стираются при перезагрузке.

Рядом живут обычные текстовые файлы в /var/log/, которые приложения пишут сами, мимо journald. Сюда попадают nginx/access.log и nginx/error.log, файлы syslog и auth.log от rsyslog, а также лог самого приложения, если его так настроили.

Отсюда ловушка, на которой спотыкаются чаще всего. Команда journalctl -u nginx почти пуста, потому что nginx пишет ошибки в собственный файл директивой error_log, по умолчанию с уровнем error. В поток ошибок, который перехватывает journald, попадает только то, что nginx успел сказать до ухода в фон, – ошибки конфигурации и старта. Лог ошибок сервера по 502 надо искать в /var/log/nginx/error.log.

Целиком журнал читают root и члены групп systemd-journal, adm и wheel, а без них будет пусто даже при живых логах.

Где лежат логи на VPS: журнал systemd против текстовых файлов nginx и приложения

Команды, которые закрывают большинство случаев

Набор флагов journalctl большой, а в работе постоянно нужны шесть.

journalctl -u myapp.service            # только этот юнит
journalctl -u myapp.service -n 200     # последние 200 строк
journalctl -u myapp.service -f         # хвост в реальном времени
journalctl -u myapp.service --since "1 hour ago"
journalctl -u myapp.service -p warning
journalctl -u myapp.service -b         # только текущая загрузка

Флаг -p фильтрует по важности и принимает имя уровня, число от 0 (emerg) до 7 (debug) или диапазон вида warning..emerg; указанный уровень выводится вместе со всем, что серьёзнее. Значение для --since понимается и как абсолютная дата "2026-08-30 14:00:00", и как относительная – "-30min", "2 h ago", "yesterday". Подробности по каждому флагу разобраны в man-странице journalctl.

Сайт отдаёт 502

Код 502 nginx отдаёт, когда апстрим не ответил как положено: соединение отвергнуто, разорвано на полпути или ответ не разобрался. Первым делом смотрят, к кому именно nginx стучался, потому что адрес в error_log часто и оказывается ошибкой.

sudo tail -n 50 /var/log/nginx/error.log
sudo systemctl status myapp.service --no-pager -l -n 100
sudo journalctl -u myapp.service -n 200 --no-pager
sudo ss -ltnp | grep 8000

Первая команда покажет адрес и порт, куда nginx не достучался, вторая и третья – что происходило с приложением в этот момент. Четвёртая проверяет, слушает ли кто-нибудь нужный порт вообще. У ss флаг -l оставляет только слушающие сокеты, -t ограничивает вывод протоколом TCP, -n показывает номера портов вместо имён, -p называет процесс, который держит сокет; чужие процессы видны только под root, свои – всегда.

Частая находка на этом шаге не связана с падением приложения. Процесс жив и слушает 127.0.0.1, а nginx настроен ходить на внешний адрес.

Сервис запущен и молчит

Юнит в состоянии active (running), а работа не делается – это ситуация из начала статьи.

journalctl -u telegram-bot.service --since "1 hour ago" -p warning
journalctl -u telegram-bot.service -f

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

Здесь же стоит проверить, не зациклилось ли приложение на повторе одной операции. Одинаковая строка, повторяющаяся с равным интервалом часами, обычно означает цикл повторных попыток, в котором внешний сервис отвечает отказом, а приложение не считает это фатальной ошибкой и продолжает.

Сервис перезапускается по кругу

systemctl status myapp.service --no-pager -l -n 50
journalctl -u myapp.service -b --no-pager | tail -n 80

В выводе будет строка Start request repeated too quickly или Failed with result 'start-limit-hit', и её принимают за причину. Это предохранитель: systemd попытался поднять сервис больше пяти раз за десять секунд и перестал пробовать. Настоящая ошибка лежит выше по журналу, в самом первом падении цикла, поэтому читать надо оттуда, снизу вверх.

Счётчик сбрасывается командой systemctl reset-failed myapp.service, но она ничего не чинит и только разрешает systemd попробовать снова.

Пороги задаются параметрами StartLimitIntervalSec= и StartLimitBurst=, и по документации systemd.unit их место – секция [Unit], а не [Service]. Многие туториалы отправляют их не туда, и правка молча не работает.

Место кончилось, хотя df -h показывает свободное

df -h
df -i
sudo du -xh --max-depth=1 /var | sort -h
journalctl --disk-usage
sudo lsof +L1

Сообщение No space left on device при живом df -h означает одно из двух. Либо кончились иноды, что видно во второй команде, в колонке IUse%, и происходит от миллионов мелких файлов вроде сессий, кэша и логов, которые никто не ротирует. Либо место держит удалённый файл, который какой-то процесс всё ещё не закрыл, и такие показывает lsof +L1; вернуть место получится только перезапуском этого процесса.

Флаг -x у du не даёт обходу уйти на другие файловые системы, иначе на сервере с примонтированными дисками команда будет считать долго и не то.

Четыре строки, которые встречаются чаще остальных

Строку connect() failed (111: Connection refused) while connecting to upstream nginx пишет, когда ядро ответило ему, что на этом адресе и порту никто не слушает. Приложение либо не стартовало, либо слушает другой адрес. Похожая по виду (110: Connection timed out) означает обратное – процесс есть, но не отвечает, а upstream prematurely closed connection говорит, что запрос был принят и приложение умерло на нём.

Когда в dmesg -T попадает Out of memory: Killed process 1234 (python3) total-vm:…kB, anon-rss:…kB, памяти не хватило всей машине, и ядро выбрало жертву само. Полезное поле здесь anon-rss, оно показывает, сколько процесс занимал в момент смерти. Для небольшого VPS за этим почти всегда стоит отсутствие swap в сочетании с утечкой памяти в приложении.

Start request repeated too quickly из предыдущего раздела причиной не бывает никогда, это всегда следствие.

Failed password for root from ... в /var/log/auth.log можно не читать: перебор идёт на любой публичный адрес непрерывно. Смотреть стоит на успешные входы – sudo grep -i "accepted password" /var/log/auth.log – и сверять адреса и время со своими.

Типовые строки в логах сервера: 502 от nginx, OOM killer, цикл перезапусков systemd

Чтобы журнал был, когда он понадобится

Первым делом стоит проверить, постоянный ли у вас журнал:

ls -d /var/log/journal
journalctl --list-boots

Если каталог существует, всё уже в порядке. На Ubuntu пакет systemd создаёт его сам начиная с версии 18.04, и на типовом VPS ничего доделывать не нужно. Параметр Storage= в /etc/systemd/journald.conf в версиях systemd, которые несут актуальные LTS-выпуски, имеет значение auto – журнал пишется на диск при наличии каталога и живёт в памяти без него. В свежих версиях systemd умолчание изменили на постоянное хранение, так что проверять точное значение стоит на своей машине командой systemd-analyze cat-config systemd/journald.conf.

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

sudo mkdir -p /var/log/journal
sudo systemd-tmpfiles --create --prefix /var/log/journal
sudo systemctl restart systemd-journald

После этого journalctl -b -1 отдаст журнал прошлой загрузки. На временном журнале --list-boots показывает одну текущую загрузку, а -b -1 не даёт ничего.

Размер журнала ограничен настройками из того же файла. SystemMaxUse= по умолчанию берёт 10% размера файловой системы, но не больше 4 ГБ, SystemMaxFileSize= берёт одну восьмую от этого объёма и не больше 128 МБ, а SystemMaxFiles= держит сотню файлов. Все значения задокументированы в man-странице journald.conf.

journalctl --disk-usage
sudo journalctl --rotate
sudo journalctl --vacuum-time=14d

Ротация в середине нужна потому, что --vacuum-time и --vacuum-size трогают только архивные файлы и активный не уменьшают. Без предварительного --rotate результат чистки окажется меньше ожидаемого, и это регулярно принимают за неработающую команду.

Текстовые логи живут по своим правилам, через logrotate. Глобальный конфиг лежит в /etc/logrotate.conf, правила по приложениям – в /etc/logrotate.d/. Проверить правило без выполнения можно командой logrotate -d /etc/logrotate.d/nginx. На Ubuntu 20.04 и новее logrotate запускается таймером systemd, а не из cron.daily, – если ротация не срабатывает, смотреть надо systemctl status logrotate.timer.

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

Почему journalctl -u nginx пустой, хотя сайт не работает? Nginx пишет ошибки в свой файл /var/log/nginx/error.log. В журнал systemd попадает только то, что случилось до ухода процесса в фон.

Как посмотреть логи journalctl за прошлую загрузку? Командой journalctl -b -1. Она сработает только при постоянном журнале – если каталога /var/log/journal нет, прошлые загрузки не сохранялись.

Журнал занял десятки гигабайт, как уменьшить? Сначала sudo journalctl --rotate, затем sudo journalctl --vacuum-time=14d. Постоянное ограничение задаётся параметром SystemMaxUse= в /etc/systemd/journald.conf.

Чем journalctl -f лучше tail -f? Тем, что видит все юниты systemd сразу и умеет фильтровать по важности и времени. Для текстовых логов приложений tail -f остаётся удобнее.

Сервис active (running), но не работает – с чего начинать? С journalctl -u имя-юнита -f и параллельного запуска того действия, которое должно сработать. Если журнал молчит в ответ, приложение до этого места не доходит.

Коротко

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

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

echo -e "Все про серверы, сети, хостинг и еще раз серверы" >/dev/pts/0

Комментарии

С помощью соцсетей
У меня нет аккаунта Зарегистрироваться
С помощью соцсетей
У меня уже есть аккаунт Войти
Инструкции по восстановлению пароля высланы на Ваш адрес электронной почты.
Пожалуйста, укажите email вашего аккаунта
Ваш баланс 10 ТК
1 ТК = 1 ₽
О том, как заработать и потратить Таймкарму, читайте в этой статье
Чтобы потратить Таймкарму, зарегистрируйтесь на нашем сайте