Одна строка лога — десятки килобайт записи: как устроен journald и что настроить

Операционные системы
, , , ,
1

В трекере systemd 13 августа завели issue #40262 с простым наблюдением: виртуалка на Debian 13 пишет около 50 IOPS, при том что в лог уходит две строки в секунду. Автор отчёта считает формат журнала «крайне неэффективным» и ссылается на закрытый без решения баг четырёхлетней давности. Ответов мейнтейнеров в треде на момент публикации нет, независимого подтверждения цифр — тоже, так что относиться к ним стоит как к одному замеру на одной конфигурации.

Но повод хороший: у людей с домашними серверами эта тема всплывает регулярно и в куда более неприятной форме — «SD-карта в Raspberry Pi умерла за полгода», «journal съел 4 ГБ на VPS с диском 20 ГБ». Ниже — четыре типичных симптома, механика за каждым и то, что реально стоит покрутить. Все значения по умолчанию — из man journald.conf.

Симптом 1. Диск постоянно что-то пишет, хотя логов почти нет

Что происходит. Журнал systemd — не текстовый файл, куда дописывается строка. Это индексированная база с хеш-таблицами и массивами смещений, спроектированная под быстрый journalctl -u nginx --since ... по любому полю.

При записи одной строки обновляются: заголовок файла (счётчики записей и объектов, смещение хвоста, sequence number), по объекту DATA на каждую уникальную пару «поле=значение» (а их к вашему сообщению systemd добавляет с десяток: _PID, _UID, _SYSTEMD_UNIT, _BOOT_ID, _HOSTNAME, _MACHINE_ID, PRIORITY и так далее), объекты FIELD на новые имена полей, цепочки в двух хеш-таблицах и массивы ENTRY_ARRAY.

Сверху на это ложится порядок записи, прямо описанный в спецификации формата: сначала все новые объекты дописываются в конец файла, и только потом проставляются ссылки в уже существующие структуры. То есть файл трогается как минимум дважды, в разных местах.

Important:

Это не баг, а осознанный размен: журнал платит записью на диск за то, чтобы поиск по полям был быстрым и не требовал grep по гигабайтам текста. Вопрос только в том, нужен ли вам этот размен на устройстве, где ресурс записи ограничен.

Что делать. Если машина — домашний сервер, где логи нужны «на случай разбора полётов», а не для аналитики, разумно уменьшить объём того, что вообще попадает в журнал: убрать debug-уровни у болтливых юнитов, а для контейнеров переключить драйвер логов Docker с journald на local или json-file с ротацией — иначе всё, что печатают контейнеры, дублируется в системный журнал.

Симптом 2. Журнал занимает гигабайты

Что происходит. По умолчанию SystemMaxUse — это 10% размера файловой системы, но не больше 4 ГБ; SystemKeepFree — 15% свободного места; SystemMaxFileSize — одна восьмая от SystemMaxUse, но не больше 128 МБ; SystemMaxFiles — 100 файлов. То есть на диске в 40 ГБ журнал имеет полное право занять 4 ГБ, и это штатное поведение, а не утечка.

Что делать. Разовая уборка:

journalctl --disk-usage
sudo journalctl --vacuum-size=200M
sudo journalctl --vacuum-time=14d

Постоянное ограничение — в /etc/systemd/journald.conf.d/00-limits.conf (отдельный drop-in лучше правки основного файла: он переживёт обновление пакета):

[Journal]
SystemMaxUse=200M
SystemMaxFileSize=20M
MaxRetentionSec=2week

После правки — sudo systemctl restart systemd-journald.

Симптом 3. SD-карта или дешёвый SSD деградируют

Что происходит. Именно здесь механика из первого симптома превращается в деньги. Постоянный поток мелких записей в разные участки файла — худший из сценариев для флеш-памяти без нормального контроллера, а SD-карта в одноплатнике это ровно такой случай.

Warning:

Мигрировать на Storage=volatile бездумно не стоит: в этом режиме журнал живёт только в /run и полностью исчезает при перезагрузке. Если сервер упал ночью, утром вы не узнаете почему.

Success:

Рабочая схема для одноплатника:

  • Storage=volatile в journald — журнал в RAM, ограниченный RuntimeMaxUse;
  • параллельно ForwardToSyslog=yes и лёгкий syslog-демон, который пишет обычный текстовый файл с ротацией — либо сразу отправка логов на другую машину;
  • если внешнего приёмника нет — компромисс: оставить Storage=persistent, но зажать SystemMaxUse=50M и поднять SyncIntervalSec, чтобы сократить число сбросов на диск.

Симптом 4. После жёсткой перезагрузки журнал битый

Что происходит. SyncIntervalSec по умолчанию — 5 минут. Это таймаут принудительной синхронизации журнальных файлов на диск. Исключение сделано для приоритетов CRIT, ALERT и EMERG: после такого сообщения синхронизация выполняется немедленно.

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

Note:

Уменьшение SyncIntervalSec спасает логи, но увеличивает число операций записи — то есть прямо противоречит лечению симптома 3. Выбирать приходится осознанно: либо ресурс носителя, либо полнота логов при аварии. Третий вариант — отправлять логи на другую машину и не решать эту дилемму локально.

Ещё две настройки, о которых редко вспоминают

Compress включён по умолчанию, порог — 512 байт: всё, что крупнее, сжимается. Для типичных однострочных сообщений это означает, что сжатие не срабатывает вообще.

Seal (Forward Secure Sealing, HMAC-SHA-256 поверх журнала для защиты от подделки задним числом) в man описан как включённый по умолчанию, но реально печать появляется только после того, как вы сгенерируете ключи через journalctl --setup-keys. Без этого шага TAG-объекты в файл не пишутся, и «включено по умолчанию» на практике не означает «работает».

Что проверить прямо сейчас

journalctl --disk-usage                 # сколько занято
systemd-analyze cat-config systemd/journald.conf   # какие значения реально применились
journalctl --verify                     # цел ли журнал

Если --disk-usage показывает сотни мегабайт на машине, где вы никогда не читали логи старше недели, — это и есть ответ на вопрос, куда девался ресурс диска.

Источники

Question:

Кто как решил вопрос с логами на одноплатниках: log2ram, вынос журнала в RAM, отправка на отдельную машину или просто «поставил SSD и не думаю»? И сталкивался ли кто-нибудь с реально битым журналом после отключения питания?