Давным-давно, когда были дебаты о том, стоит ли принимать в качестве init-системы systemd (с одной стороны удобно, с другой стороны, довольно токсичный автор...), вместе с systemd приехал и journald. В целом, он ощущался как аппендикс к systemd, и вместе с ForwardToSyslog, он мирно жил на серверах. Дефолтная конфигурация в целом устраивала, а всё нужное можно было по-старинке накрутить в syslog'е.

В одном из проектов у нас образовалась потребность в обработке большого числа логов, и мы решили попробовать journald вместо (r)syslog(d|-ng). Оказалось, что:

1. journald решает все наши проблемы

2. документации по нему подозрительно мало (особенно, в сравнении с systemd)

3. при том, что его поведение более-менее разумно, интуиция о том, как он работает, практически отсутствует и её надо набирать.

Так что в рамках этого поста я рассказываю про journald. Не про journalctl, а именно про systemd-journald, т.е. про демон, который логи собирает, хранит и ротирует.

Архитектура

journald принимает сообщения через специальный протокол. Есть библиотека для отправки туда логов (и большинство языко-специфичных фреймворков логгирования её поддерживают, на одном уровне с syslog, stderr, elastic и т.д.). Базовая функция этой библиотеки sd_journal_send. Ещё journald может "выковыривать" логи из kmsg (его выводит команда dmesg), и всё. В отличие от многих других систем (logstash, graylog) journald не умеет бегать за файлами на файловой системе и "забирать" их.

systemd использует сервисы journald для отправки туда всевозможных вариантов логов от приложения, например, вывод в stdout и stderr. "запись stdout" - это функция именно systemd, а journald ждёт уже аккуратно подготовленных данных в свой сокет.

Полученные данные хранятся частично в оперативной памяти, и могут сохраняться в постоянное хранилище на диске с настраиваемым уровнем надёжности (flush, криптографическая целостность и т.д.). Файлы на диске - бинарные, индексированные. journald сам их ротирует, хотя, если вы "грохнете" архив, ничего страшного с точки зрения journald не случится. Главным клиентом к journald является journalctl, хотя есть и альтернативные клиенты (включая веб-интерфейсы). Ещё есть systemd-journald-remote, но в рамках нашей задачи это было не нужно, так что всё что я могу про него сказать, что "оно там есть".

В системе может быть больше одного journald, что позволяет разделить "обычную ОС" (то, что предоставляет мейнтейнер дистрибутива) и "логи важного приложения". Реализуется это через концепцию journal namespaces и шаблонов systemd (подробнее про это будет дальше).

Структура журнала

journald может писать журналы как "per uid" (+системный), так и единый "моноблоб". Место записи содержит в себе machine id, так что если у вас machine id сбрасывается при перезагрузке, старые логи будут становиться недоступными. Структура журнала важна при ротации, потому что у journald есть общий лимит на число файлов; если это число превышено, какие-то архивы могут быть удалены раньше, чем предполагалось. Особенно это заметно при записи per uid, когда на сервер логинятся несколько пользователей. namespace'ы записываются в формате machine_id.namespace/.

Так как журнал содержит в себе индексы (для быстрой выборки по полям, например, за интервал времени), то места он занимает в разы больше, чем текстовая информация внутри. Первичные замеры показали величину порядка 4 (при использовании Compress=64) или 5.9 (без сжатия на синтетике). Спасибо apmucm за указание на эту особенность journald.

RateLimit, он же "притормаживание"

Это восхитительный набор опций в journald, решающий конкретные проблемы сисадминов (за счёт интересов программистов, но в этой ситуации оправдано)

journald может пропускать часть сообщений в лог, если они приходят слишком часто, причём скорость "пропуска" может быть функцией свободного места. Чем ближе к no free space available, тем больше journald пропускает логов (оттягивая неминуемое).

Опции в systemd.unit позволяют изменить эти настройки на per-unit основе (и имеют приоритет над настройками journald).

Сами опции: RateLimitIntervalSec, RateLimitBurst (который и меняется в зависимости от доступного места).

Ротация

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

В отличие от logrotate и многих библиотек логгирования, systemd сжимает логи (в зависимости от опций) в момент записи, так что ротация - это просто переименование одного файла и начало нового, т.е. операция предельно дешёвая.

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

• SystemMaxFileSize указывает при каком размере надо начинать новый журнал.

• MaxFileSec указывает как долго вести основной файл журнала.

Как только эти цифры превышены (по размеру или по месту), старый файл закрывается, переименовывается, создаётся новый. (Ещё может выполняться seal, т.е. подпись файла для защиты от модификации).

Старые файлы хранятся до превышения одного из событий:

• SystemMaxUse- общее место, которое должно быть занято всеми журналами. Самый старый файл - кандидат на стирание, если эта величина превышена.

• SystemKeepFree - свободное место, которое должно оставаться на файловой системе с журналами. Если осталось меньше, чем этот объём, самые старые из архивов журналов стираются.

• MaxRetentionSec - максимальный возраст файлов в архиве.

• SystemMaxFiles - максимальное число файлов, которые сохраняются. Если число превышено, самые старые архивы удаляются.

Все лимиты применяются per namespace, т.е. если у вас три namespace'а, каждый из них определяет политику ротации самостоятельно.

SystemMaxFiles может доставить некоторое количество WTF'а, потому что если у вас SystemMaxFileSize, например, 128Мб, а, SystemMaxFiles 100, то это не гарантирует сохранение 1.2Гб логов. Файлы могут ротироваться по возрасту, а их число определяется числом разных пользователей (если включен режим per uid). Каждому из них выдадут отдельный файл журнала, плюс будут ротировать каждые MaxFileSec.

Log namespaces

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

Journald не требует себе никаких специальных привилегий и может быть запущен даже от обычного пользователя (если пользователю разрешено писать в каталог с журналами, указанный в конфиге). Он поддерживает несколько инстансов с разными конфигами, причём "инстанс" указывается очень просто - имя инстанса передаётся первым аргументом командной строки. Например, вот так:

/lib/systemd/journald myapp

Руками этого делать чаще всего не нужно, потому что:

1) В опциях systemd-unit'а можно указать
[Service]
LogNamespace=myapp

2) после чего systemd попытается писать в сокеты (устройства и т.д.) в /run/systemd/journal.myapp.

3) Что приведёт к активации socket-юнита systemd-journald-varlink@myapp.socket

4) Что (через систему зависимостей) приведёт к активации systemd-journald@myapp.service

5) Что приведёт к запуску /lib/systemd/journald myap (в виде сервиса)

6) Который прочитает файл /etc/systemd/journald@myapp.conf (если найдёт).

7) И пойдёт писать всё, что пишут в этот LogNamespaceв журнал в /var/log/journal/{{machine_id}}.myapp

Это всё будет писаться со всеми полагающимися ротациями, дефолтными или нет настройками и т.д.

Удивительно красивая оркестрация через базовые примитивы без специальной логики под специальные случаи.

Фактически, написанного (плюс чуть-чуть man journald.conf) достаточно для того, чтобы начать его использовать. Остаются вопросы эргономики, эксплутации и производительности.

Багофичи

Внутри systemd-journald@.service написано LogStdout=null. Если у вас опечатка в вашем journald@myapp.conf, вы об этом не узнаете. Мы это поправили с помощью drop-in'а (оверрайда):

/etc/systemd/system/systemd-journald@myapp.service.d/override.conf
[Service]
StandardOutput=journal

В документации не очень внятно объяснено, как высчитывается SystemMaxFileSize. Вроде бы, это 1/8 от  SystemMaxUse, который capped at 4GB. По моим рассчётам получается что-то порядка 500Мб, а на практике - 128. Исправляется явным указанием значения.

Жизнь с толстым логом

("... та и в крынку не лезет" - анекдот)

Как только вы разрешаете вашему Важному Приложению писать Много Важных Логов у вас становится Много Важных Логов (и их архив). Это означает, что ряд порочных, но привычных техник перестаёт работать. Под запретом оказываются любые операции с journalctl, не имеющие фильтров. Т.е. никаких journalctl|grep TRACE, никаких journalctl |tail и т.д.

Свой namespace требует его указания:

journalctl --namespace myapp --since 10:30 -u myapp_main --grep TRACE

Compression сохраняет место, но под высокой нагрузкой утыкает journald (к счастью, отдельный процесс) в 100% одного ядра.

Безусловно, нужно отключать запись в syslog (ForwardSyslog=no), ради этого всё и задумывалось.

Рейтлимит может оказаться неожиданностью для программистов, которые ожидали бесконечно производительной бесконечной ленты у машины тьюринга (для записи бесконечных логов). Так как рейтлимит срабатывает по рейту, а не по важным эвентам, может оказаться, что Самая Важная Строчка не записана. Можно отключить ratelimit, но тогда Самая Важная Строчка будет уротирована забытым тредом, который непрерывно трейсится и перезапускается в течение единиц часов (даже при терабайтном месте для логов).

Послесловие

Почему не ELK? Во-первых ELK перестал быть opensource. Странная лицензия, фактически, shareware с непонятными рисками для бизнеса. Во-вторых jvm со своим волшебным миром, за которым нужно глаз да глаз (в сравнении с этим journald уже есть, отлично работает и имеет здравые дефолты). В третьих локальные логи офигенны - если у вас 400Гб логов в день, 20 серверов, то это 8Тб логов в день. 740 мегабит непрерывно, не считая всплесков. Какой там ELK-кластер надо докупить под такую штуку? А тут, на серверах, локальное место пропадает, да ещё и с готовым шардингом. Если нет задачи централизованной аналитики (а её нет), то локальные логи - это хорошо и здорово. У журналов есть индексы, а у journalctl достаточно высокая производительность (привет, С), чтобы простой --grep (не путать с |grep) работал достаточно хорошо (а часто, и значительно лучше, чем мучительное тыц-тыц в Кибане, для которой вывести 10000 записей одновременно - это DoS атака на браузер).