Антипаттерн: логи без ротации

MAATRIX

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

Как это выглядит на практике

Антипаттерн редко возникает как осознанное решение — обычно логирование настраивают в первый день, когда до продакшена ещё далеко, а вопрос «что будет через полгода» никого не занимает.

Вариант первый — приложение пишет в файл напрямую. Типичная конфигурация логирования в самописном сервисе:

import logging

logging.basicConfig(
    filename="/var/log/myapp/app.log",
    level=logging.INFO,
    format="%(asctime)s %(levelname)s %(message)s",
)

Файл /var/log/myapp/app.log создаётся при первом запуске и растёт весь дальнейший срок жизни приложения. Никакой записи в /etc/logrotate.d/ под это приложение не создаётся — про logrotate просто не вспомнили, потому что стандартные системные логи (/var/log/syslog, /var/log/nginx/access.log) в дистрибутиве уже ротируются из коробки, и кажется, что «логи вообще как-то сами ротируются». Самописный путь в /var/log/myapp/ под это правило дистрибутива не подпадает — это не системный лог, а файл конкретного приложения, и о нём система ничего не знает.

Вариант второй — nginx/приложение с 2>&1 >> файл в systemd-юните:

[Service]
ExecStart=/usr/bin/node /opt/myapp/server.js
StandardOutput=append:/var/log/myapp/app.log
StandardError=append:/var/log/myapp/app.log

Здесь тот же результат: один непрерывно растущий файл, в который systemd дописывает вывод процесса построчно, без какого-либо ограничения сверху.

Вариант третий — Docker-контейнер с драйвером json-file по умолчанию. Если при запуске контейнера не указать log-opts, Docker использует драйвер json-file без ограничения размера:

docker run -d --name myapp myapp:latest

Каждая строка stdout/stderr контейнера дописывается в JSON-файл на хосте (обычно /var/lib/docker/containers/<id>/<id>-json.log), и этот файл растёт ровно так же неограниченно, как файл из первого варианта — просто ответственность за него не разработчик приложения, а Docker-демон, и от этого не легче: docker logs в какой-то момент начинает работать заметно медленнее, а место на диске уходит точно так же.

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

Почему это работает и почему это ловушка

Отсутствие ротации не ломает ничего в первый день, в первую неделю и часто в первый месяц — именно поэтому антипаттерн живёт так долго. Файл app.log на молодом сервисе с умеренным трафиком растёт медленно: несколько мегабайт в день, иногда меньше. Диагностировать проблему по логам всё ещё удобно — tail -f быстро показывает последние строки, grep по файлу отрабатывает за доли секунды. Никакого сигнала, что что-то не так, попросту нет.

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

Проблема первая: диск заполняется на 100% и роняет не только логи

Самое опасное следствие — не то, что лог станет большим, а то, что он рано или поздно займёт всё свободное место на разделе. Если /var/log живёт на том же разделе, что и остальная система (типичная ситуация на VPS с одним диском без отдельного раздела под логи), заполнение до 100% не остаётся проблемой одного файла.

Когда на разделе не остаётся свободного места, отказывают операции, которые к логированию отношения не имеют:

• База данных на этом же диске не может записать WAL/transaction log, из-за чего PostgreSQL и MySQL при полном диске обычно переходят в защитный режим только на чтение или падают с ошибкой записи — новые транзакции перестают проходить.
• Временные файлы — сессии PHP, кэш приложения, файлы блокировок — не создаются, потому что /tmp тоже упирается в то же самое свободное место.
• Сам процесс логирования тоже перестаёть писать, и это самое неприятное: именно тогда, когда нужно разобраться, что случилось, свежих записей в логе уже нет, потому что записывать их некуда.
• SSH и системные утилиты могут начать вести себя нестабильно, если демонам не хватает места для собственных временных файлов и сокетов.

Итог типичный: сервер перестаёт отвечать на запросы, при этом видимой причины на первый взгляд нет — приложение вроде бы не менялось, трафик не рос кратно. Диагностика обычно начинается с df -h, показывающего 100% на корневом разделе, и только потом — с поиска виновника через du -sh /var/log/* | sort -rh. Полный простой сервера из-за забытой ротации логов — не редкий крайний случай, а один из самых частых сценариев непредсказуемого падения продакшена именно потому, что ничего в конфигурации приложения формально не менялось: файл просто рос сам по себе, пока не кончилось место.

Проблема вторая: огромный файл лога невозможно нормально анализировать

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

grep и tail не индексируют файл — это построчный последовательный проход, и на файле в 5-10 ГБ он занимает секунды-десятки секунд вместо мгновенного отклика на файле в несколько мегабайт. grep -n "ERROR" app.log на большом файле не просто работает медленнее — сам процесс поиска начинает конкурировать за дисковый I/O с рабочей нагрузкой приложения, которое пишет в тот же файл в это же время. tail -f app.log, оставленный открытым в терминале для наблюдения за живыми логами, при высокой частоте записи на большом файле тоже ощутимо тяжелее для системы, чем то же самое на файле, который ротируется раз в сутки.

Практическое следствие: чем сильнее нужна быстрая диагностика (сервис ведёт себя странно прямо сейчас, нужно понять, что происходило последние 10 минут), тем менее удобным оказывается инструмент. Разбитый на суточные файлы лог решает это тривиально — grep "ERROR" /var/log/myapp/app.log без ротации ищет по всей истории сразу, тогда как с ротацией достаточно grep "ERROR" /var/log/myapp/app.log (текущий файл, всегда компактный) или, если нужен конкретный день, zgrep "ERROR" /var/log/myapp/app.log-20260815.gz — быстро и по делу.

Проблема третья: постоянно растущий файл мешает бэкапу и архивации

Третья проблема менее очевидна, но регулярно всплывает при настройке резервного копирования диска целиком (снапшот тома, rsync всей файловой системы, образ диска на облачном провайдере). Пока идёт снятие бэкапа, приложение продолжает работать и дописывает данные в открытый файловый дескриптор лога.

Для инструментов, которые копируют файл целиком за один проход (не использующих снапшоты на уровне файловой системы или LVM), это создаёт несогласованность: размер файла на момент начала копирования и на момент окончания — разный, и в бэкап может попасть частично записанная последняя строка или сам процесс копирования большого постоянно меняющегося файла занимает существенно больше времени, чем архивация того же объёма данных, разбитого на неизменяемые ротированные куски. Уже сжатые и закрытые файлы вида app.log-20260815.gz бэкапятся предсказуемо быстро, потому что они больше не меняются — а вот с активным app.log, который в момент снятия снапшота может весить гигабайты и продолжает расти, инструменты бэкапа иногда либо ощутимо тормозят на нём, либо (в зависимости от инструмента) пропускают несогласованный кусок. Отдельно стоит проблема места под сам бэкап: копия гигабайтного лога занимает место в хранилище резервных копий так же, как любые другие данные, только пользы от неё для восстановления обычно не больше, чем от последних нескольких дней записей.

Как сделать правильно: logrotate и лимиты Docker

Решение для файлового логирования — logrotate, стандартный демон почти во всех дистрибутивах Linux (уже установлен на Ubuntu/Debian/AlmaLinux по умолчанию, запускается по cron/systemd-timer раз в сутки). Задача сводится к одному конфигу.

Конфиг для приложения, пишущего в /var/log/myapp/app.log:

# /etc/logrotate.d/myapp
/var/log/myapp/app.log {
    daily
    rotate 14
    compress
    delaycompress
    missingok
    notifempty
    copytruncate
}

Разбор директив:

• daily — ротация раз в сутки (для более активных логов уместнее size 100M, чтобы ротация срабатывала по размеру, а не только по времени).
• rotate 14 — хранить 14 предыдущих ротированных файлов, более старые удаляются автоматически; итоговый объём предсказуем: 14 дней вместо неограниченного роста.
• compress — сжимать ротированные файлы в .gz, экономия обычно в 5-10 раз для текстовых логов.
• delaycompress — не сжимать файл сразу при ротации, а только следующим циклом; это оставляет предыдущий файл (app.log.1) несжатым один цикл, что удобно, если какой-то процесс ещё читает его.
• missingok — не считать ошибкой отсутствие файла (например, если сервис ещё не создал лог).
• notifempty — не ротировать пустой файл, чтобы не плодить бессмысленные пустые архивы.
• copytruncate — ключевая директива для приложений, которые держат файловый дескриптор открытым и не умеют переоткрывать его по сигналу: logrotate копирует текущее содержимое в app.log.1, а затем обнуляет (truncate) исходный файл, не трогая сам дескриптор приложения. Альтернатива — postrotate/endscript с сигналом приложению переоткрыть файл (kill -USR1 или аналог, если приложение это поддерживает), что чище, но требует поддержки на стороне приложения:

/var/log/myapp/app.log {
    daily
    rotate 14
    compress
    notifempty
    postrotate
        systemctl reload myapp >/dev/null 2>&1 || true
    endscript
}

Проверить конфиг без ожидания суток: logrotate -d /etc/logrotate.d/myapp (dry-run, покажет, что будет сделано) и logrotate -f /etc/logrotate.d/myapp (принудительный прогон прямо сейчас).

Для Docker — ограничение через log-opts. Проблема с драйвером json-file по умолчанию решается либо глобально для демона, либо точечно для контейнера.

Глобально — в /etc/docker/daemon.json (применится ко всем новым контейнерам после systemctl restart docker, на уже существующие не подействует без пересоздания):

{
  "log-driver": "json-file",
  "log-opts": {
    "max-size": "10m",
    "max-file": "3"
  }
}

max-size: 10m ограничивает один файл лога 10 мегабайтами, max-file: 3 — хранит максимум 3 таких файла на контейнер (итого до 30 МБ на контейнер вместо неограниченного роста).

Точечно, для конкретного контейнера в docker-compose.yml:

services:
  myapp:
    image: myapp:latest
    logging:
      driver: json-file
      options:
        max-size: "10m"
        max-file: "3"

Это уместно, если разным сервисам в одном compose-файле нужны разные лимиты (например, у сервиса с высокой частотой логов — max-size: "50m", у фонового воркера — "5m"). Оговорка: изменение log-opts для уже запущенного контейнера требует пересоздания контейнера (docker compose up -d --force-recreate или аналог), на лету параметры драйвера логов не применяются.

Регулярная проверка и алерт на заполнение диска

Ротация снижает риск, но не отменяет необходимость следить за диском в целом — логи не единственное, что может его заполнить (растущая база данных, кэш, временные файлы загрузок). Практический минимум — регулярно смотреть df -h и понимать, какой раздел за что отвечает:

df -h
# Filesystem      Size  Used Avail Use% Mounted on
# /dev/sda1        40G   34G  4.3G  89% /

89% — тревожный порог, с которого стоит начинать разбираться, а не ждать 100%. Ручная проверка раз в неделю работает, пока серверов немного, но не масштабируется и не срабатывает ночью, когда диск заполняется резко из-за всплеска логов на фоне инцидента. Практичнее — настроить автоматический алерт на пороге заполнения (например, 85% и 95%) через мониторинг, а не полагаться на то, что кто-то вспомнит зайти и проверить.

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