docker logs и events: ротация, съедающая улики, и поток демона, который их сохранил
docker logs воспроизводит то, что захватил драйвер из stdout/stderr — у json-file по умолчанию max-size и max-file тихо ротируют старые строки. docker events — поток демона в реальном времени: OOM-kill и рестарт, которые не записал ни один лог приложения.
Разбор инцидента требовал логи с 02:00, когда воркер начал терять задачи. Инженер запустил docker logs worker --since 02:00 --until 02:30 и получил ровно ничего за это окно — старейшая строка была 02:47. Это не проблема часов: воркер логировал по стектрейсу на каждую потерянную задачу, тысячи строк в секунду, а драйвер json-file по умолчанию был настроен с max-size=10m, max-file=3. Тридцать мегабайт кольцевого буфера при таком объёме держат около девяноста секунд. К моменту, когда кто-то посмотрел, ротация уже сжевала улики и заменила их свежим шумом. Строка с корневой причиной существовала, была захвачена и была удалена драйвером логирования, делавшим ровно то, что ему велели. А вот что уцелело — было в месте, куда никто не заглянул: docker events --since 02:00 всё ещё держал собственную запись демона — oom, затем die, затем start — ядро убивает воркер, restart-политика его оживляет, история, которую логи приложения рассказать не могли, потому что приложение умерло прежде, чем успело её записать.
logs — это воспроизведение буфера драйвера, а не ваш файл
Почему это важно в два часа ночи на инциденте? Потому что если ожидаешь файл, а получаешь кольцевой буфер — перестаёшь смотреть в нужный период времени. docker logs не читает файл логов вашего приложения. Он воспроизводит то, что драйвер логирования контейнера захватил из stdout и stderr процесса PID 1. С драйвером по умолчанию json-file каждая строка оборачивается в JSON на диске под /var/lib/docker/containers/<id>/<id>-json.log, и — критично — этот файл ротируется собственными настройками драйвера, которые большинство команд никогда не трогает:
# Драйвер по умолчанию: json-file. Ротация ВЫКЛЮЧЕНА, пока не зададите,
# но прод-образы и daemon.json обычно ставят небольшой лимит:
docker run --log-driver json-file \
--log-opt max-size=10m --log-opt max-file=3 worker
# => максимум 3 файла × 10m = 30m истории. Болтливое приложение
# прожигает это за секунды, и docker logs не покажет больше.
docker logs worker --since 02:00 --until 02:30 --timestamps
docker logs worker --tail 200 -f # следить за живым хвостомЛовушка в том, что ротация невидима со стороны docker logs: нет ошибки, нет маркера разрыва — старейшая строка это просто то, что уцелело, и --since для окна, которое драйвер уже выбросил, возвращает пустоту, будто ничего не было. Ещё два факта, кусающих сеньоров: (1) захватывается только stdout/stderr — приложение, логирующее в файл внутри контейнера, не даёт docker logs вообще ничего; и (2) некоторые драйверы вовсе не воспроизводимы — под journald или syslog вы запрашиваете журнал хоста, а под splunk/gelf docker logs может вовсе отказать, потому что байты покинули хост. Урок: считайте docker logs маленьким, теряющим данные кольцевым буфером для живого хвоста, и отправляйте логи с узла (драйвер → агрегатор) для всего, что нужно хранить.
docker logs worker --since 02:00 --until 02:30 возвращает ничего, но воркер точно много логировал тогда. Драйвер json-file с max-size=10m, max-file=3. Что случилось с уликами?
events — демон рассказывает о себе в реальном времени
Когда приложение не смогло залогировать то, что его убило — потому что действовал движок или ядро — история живёт в docker events. Это живой поток каждого перехода состояния, который демон совершает над контейнерами, образами, томами и сетями, с --since/--until для воспроизведения по удержанному демоном окну:
docker events --since 02:00 --until 02:30 \
--filter container=worker --filter event=oom --filter event=die
# 02:14:09 container oom worker
# 02:14:09 container die worker (exitCode=137)
# 02:14:11 container start workerТройка oom → die(137) → start — сигнатура краш-лупа по памяти, и ничего из этого нет в docker logs — приложение убито SIGKILL на полуслове, без шанса написать прощание. Events вскрывают невидимое иначе: OOM-kill’ы, смены health-статуса (health_status: unhealthy), действия restart-политики, kill/stop/destroy и маунты томов. Соедините это с docker stats для живой памяти/CPU из cgroup — и можно наблюдать, как контейнер взбирается к лимиту и его жнут в реальном времени. Ментальная модель: logs — что сказала нагрузка; events — что движок с ней сделал — и в худшие ночи записан был только второй.
Контейнер в краш-лупе по памяти, но docker logs показывает лишь чистый стартовый баннер каждый цикл — ни ошибки, ни стектрейса. Где записан реальный отказ?
▸Почему это работает
Почему Docker разделяет историю на два потока, а не один лог? Потому что у них разные авторы и разные гарантии выживания. logs — нагрузка рассказывает о себе: богато, но долговечно лишь как кольцевой буфер драйвера и пишется лишь пока процесс жив. events — демон рассказывает о своих действиях над контейнером: скудно, но захватывает моменты, недоступные нагрузке: SIGKILL, рестарт, смену health. Разделение и есть суть: когда приложение умирает на полуслове, перо демона продолжает писать.
- 01Почему docker logs может вернуть пустоту за окно, когда приложение точно тогда логировало, и что этим управляет?
- 02Что захватывает docker events, чего docker logs структурно не может, и почему это важно в краш-лупе?
docker logs — это не окно в файл логов вашего приложения: он воспроизводит то, что драйвер логирования контейнера захватил из stdout и stderr процесса PID 1. С драйвером по умолчанию json-file эти строки живут в /var/lib/docker/containers/<id>/ и ротируются по max-size и max-file, поэтому вся история, которую вы вообще можете получить, — это max-file × max-size; болтливое приложение прожигает буфер на 30m за секунды, и —since для уже отротированного окна возвращает пустоту без ошибки и без маркера разрыва — улики исчезли, и ничто вам об этом не скажет. Ещё две ловушки: приложение, логирующее в файл внутри контейнера, не даёт docker logs ничего, ведь захватывается только stdout/stderr, а драйверы вроде journald, syslog, splunk и gelf шлют байты за пределы хоста, поэтому docker logs запрашивает в другом месте или прямо отказывает. Поэтому считайте docker logs маленьким теряющим кольцевым буфером для живого хвоста и шлите всё долговечное в агрегатор. Когда то, что убило контейнер, было движком или ядром, приложение не смогло это залогировать — и для этого есть docker events: поток демона в реальном времени, воспроизводимый через —since, о переходах состояния, где краш-луп по памяти показывает тройку oom → die(137) → start, которая никогда не доходит до docker logs, потому что убитое SIGKILL приложение не написало финала. logs — что сказала нагрузка; events — что движок с ней сделал. Свяжите events с docker stats, чтобы наблюдать, как контейнер взбирается к лимиту и его жнут в реальном времени. Теперь, когда —since вернул пустоту, вы сначала проверите настройки ротации, а не решите, что приложение тогда ничего не писало — а краш-луп без ошибок в логах отправит вас прямо в docker events.
Практика
Начни сверху. Задачи идут от простого к сложному: вспомнить факт, применить к случаю, затем senior-уровень. Открой, попробуй, потом открой ответ.
Что-то непонятно?
Задай вопрос по этому уроку. Вопросы анонимны и попадают напрямую автору — урок станет лучше.