Логирование во встраиваемом Linux: как не износить флеш раньше времени

Перевод статьи A Practical Guide to Embedded Linux Logging — Interrupt (Memfault).

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

Сбор диагностики — это набор компромиссов. Если логировать каждое событие, вы зальёте память записями и вручите следующему инженеру тысячи строк для раскопок. Если логировать слишком мало — расследовать будет нечего. На устройствах с ограниченными ресурсами обе крайности бьют сильнее. Для встраиваемого Linux износ флеша — серьёзная угроза сроку жизни устройства в поле: каждая строка лога, дошедшая до постоянного хранилища, — это запись, а на NAND и eMMC записи расходуют ресурс.

Почему логирование нагружает устройство#

Большинство встраиваемых Linux-систем хранят данные на eMMC: контроллер флеша, который занимается выравниванием износа и управлением блоками, плюс NAND-память, видимая системе как /dev/mmcblk0. У флеша конечный срок жизни, определяемый прежде всего числом циклов программирования/стирания (P/E), после которого поведение памяти становится непредсказуемым. Чем больше вы пишете — тем быстрее он изнашивается.

Но записи неодинаковы. И объём, и размер каждой записи напрямую влияют на износ. Это описывается коэффициентом усиления записи (write amplification factor, WAF) — отношением физически записанных байт к логическим, которые действительно нужны приложению. Логи, по природе своей мелкие и частые, дают очень плохой WAF.

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

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

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

Логи ядра#

Пространство ядра — это место, где работает ядро ОС с неограниченным доступом к железу и памяти. Любое сообщение, порождённое кодом в пространстве ядра, печатается как сообщение ядра: обнаружение оборудования, инициализация драйверов, события загрузки, ошибки памяти, низкоуровневые предупреждения.

Логи ядра выводятся вызовом printk(), и каждое сообщение относится к одному из восьми уровней:

Уровень	Макрос	Номер
Emergency	`KERN_EMERG`	0
Alert	`KERN_ALERT`	1
Critical	`KERN_CRIT`	2
Error	`KERN_ERR`	3
Warning	`KERN_WARNING`	4
Notice	`KERN_NOTICE`	5
Info	`KERN_INFO`	6
Debug	`KERN_DEBUG`	7

Все сообщения ядра попадают в кольцевой буфер фиксированного размера в оперативной памяти; размер задаётся при сборке параметром CONFIG_LOG_BUF_SHIFT. Буфер живёт в RAM, то есть по природе своей энергозависим: сообщения ядра не переживают перезагрузку. Посмотреть буфер проще всего командой dmesg, которая читает его через /dev/kmsg или через klogctl().

Большинство современных дистрибутивов по умолчанию забирают логи ядра и перекладывают их в собственное хранилище — у journald за это отвечает ReadKMsg=yes в journald.conf. Раз многие демоны и так подключены к /dev/kmsg, стоит проверить, что сообщения ядра не дублируются, а фильтрация по уровню настроена по-разному для разработки и для продакшена.

Агрегация системных логов#

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

Syslog#

Исторически syslog был стандартным протоколом сбора логов. Демон агрегирует сообщения и складывает их в человекочитаемые текстовые файлы в /var/log/. Главное достоинство — читать и искать по ним можно чем угодно, хоть grep. На обычных дистрибутивах /var/log смонтирован в постоянное хранилище, а вот во встраиваемых сборках /var чаще монтируют в tmpfs (то есть в RAM), чтобы поберечь флеш.

Из демонов распространены rsyslog, syslog-ng, а для встраиваемого Linux — BusyBox syslogd.

BusyBox syslogd по умолчанию не держит большой буфер в памяти: каждое сообщение он пишет напрямую в /var/log/messages по мере поступления. То есть куда именно уйдут эти записи, целиком определяется точкой монтирования /var/log — либо в постоянное хранилище, где каждая строка превращается в запись во флеш, либо в tmpfs, где она не переживёт перезагрузку.

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

CONFIG_FEATURE_IPC_SYSLOG=y
CONFIG_FEATURE_IPC_SYSLOG_BUFFER_SIZE=16
CONFIG_LOGREAD=y

Режим включается запуском syslogd с флагом -C. Так вы жёстко ограничиваете расход RAM размером буфера и получаете свободу реализовать собственную логику хранения и пересылки. Оговорка одна: буфер кольцевой, и на многословных системах самые старые записи будут затираться. Для устройств с дефицитом памяти это может быть лучшим из доступных вариантов.

BusyBox syslogd умеет простую фильтрацию по уровню (-l LEVEL), отбрасывая всё менее срочное, но фильтрации по содержимому и ограничения частоты, как у rsyslog и syslog-ng, у него нет.

Поскольку syslogd непрерывно пишет в один файл, его всегда нужно сочетать с ротацией, иначе /var/log будет расти без границ. Кое-какая ротация в BusyBox есть, но обычно полагаются на logrotate. В любом случае критично задать жёсткие ограничения по максимальному размеру и возрасту, включить сжатие и настроить ротацию.

syslogd хорошо подходит системам с невысокой и средней многословностью и жёстким бюджетом ресурсов — но из-за скудных возможностей настройки по производительности он проигрывает более современным решениям.

journald#

journald неразрывно связан с systemd и работает только на системах с ним. Главное его преимущество перед syslog — он рассчитан на большие объёмы. Вместо человекочитаемого текста journald хранит логи в бинарном структурированном индексированном формате, и запрос journalctl -u <unit> отрабатывает быстрее, чем grep по большим текстовым файлам.

Ключевые параметры journald.conf:

[Journal]
Storage=persistent        # persistent | volatile | auto | none
Compress=yes              # сжимать объекты больше порогового размера (по умолчанию да)
SystemMaxUse=50M          # потолок размера /var/log/journal
RuntimeMaxUse=16M         # потолок размера /run/log/journal (tmpfs)
SyncIntervalSec=5m        # максимальный интервал между принудительными fsync()
RateLimitIntervalSec=30s
RateLimitBurst=1000       # отбрасывать сообщения сверх этого всплеска за интервал
ForwardToSyslog=no

Варианты хранения:

persistent — запись во флеш в /var/log/journal;
volatile — запись в tmpfs/RAM в /run/log/journal;
auto — persistent, если /var/log/journal уже существует, иначе volatile;
none — журнал не ведётся ни на диске, ни в памяти, логи только пересылаются в цели ForwardTo*=.

Во встраиваемом Linux /var, скорее всего, смонтирован в tmpfs, так что схему монтирования стоит перепроверить. Хранение в энергозависимой памяти — самый радикальный способ снизить износ: записи в RAM не стоят ни одного цикла P/E. Но для большинства сценариев это лишает логи смысла. Вариант none или volatile оправдан, если вы пересылаете логи в облако или превращаете их в метрики — то есть основная часть данных всё равно хранится вне устройства.

Ограничения размера напрямую влияют на объём хранимого. Compress= уменьшает число физически записанных байт при том же логическом объёме, а SystemMaxUse= и RuntimeMaxUse= задают жёсткие потолки по флешу и оперативной памяти.

Отдельно стоит отметить механизмы, которые борются с усилением записи. SyncIntervalSec= группирует записи и не вызывает fsync() на каждом сообщении (исключение — CRIT, ALERT и EMERG). Более длинный интервал синхронизации означает в среднем меньше физических записей большего размера при том же объёме логов — то есть меньший износ флеша. Плата — потеря большего «хвоста» логов при внезапной потере питания. А RateLimitIntervalSec= и RateLimitBurst= ограничивают, сколько сообщений за интервал journald вообще примет, чтобы один шумный сервис не затопил журнал.

Как хранить меньше#

Централизация и обработка логов#

Когда устройств в поле становится много, стоит посмотреть дальше привычных демонов. Что, если из всего, что попадает в journald или syslog, сохранять только важное? Здесь пригождаются инструменты вроде Fluent Bit: он слушает заданные потоки логов, применяет фильтры и пересылает дальше только то, что вам нужно.

Простейший пример fluent-bit.conf:

[INPUT]
  Name systemd
  Tag kernel.power
  Systemd_Filter _TRANSPORT=kernel

[FILTER]
  Name grep
  Match kernel.power
  Regex MESSAGE (?i)(low.power|power.management|suspend|thermal|throttl|battery|cpufreq|pmu)

[OUTPUT]
  Name tcp
  Host 127.0.0.1
  Port 5170

Эта конфигурация принимает все логи ядра, приходящие в systemd, отбирает сообщения про питание, температуру и батарею и отправляет подходящие на TCP-порт. Фильтрация здесь примитивная, но приём становится довольно мощным, когда применяется к логам разных приложений, а гибкие варианты вывода позволяют передать данные другому приложению — для дальнейшей обработки или отправки в облако.

Логи в метрики#

Ещё один способ сократить объём — превращать сообщения в метрики. Что, если вместо сотен строк логов на тысячах устройств просто считать, сколько раз устройство входило в критическое состояние? Вместо того чтобы хранить каждую ошибку передачи Ethernet отдельной строкой, которую потом надо искать и агрегировать на бэкенде, можно инкрементировать счётчик. Теперь вы отвечаете на вопрос «как часто это случается» и оцениваете серьёзность проблемы, не храня сами строки.

Такие инструменты обычно просты в настройке: нужно написать регулярные выражения, по которым сопоставляются входящие строки. И Fluent Bit, и memfaultd умеют по совпадению шаблона увеличивать локальные метрики вместо того, чтобы пропускать строку дальше (или в дополнение к этому).

Например, чтобы считать, сколько раз OOM-killer убивал процесс, заводится счётчик OOMKill_<ProcessName>, который увеличивается при появлении подходящей строки:

{
  "counter_name": "oomkill_$1",
  "pattern": "Out of memory: Killed process \\d+ \\((.*)\\)",
  ...
}

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

Итог#

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

Где должны жить логи? Большинству устройств нужно хоть что-то в постоянном хранилище, чтобы ответить «почему эта штука упала в поле». Но каждый записанный байт вычитается из бюджета циклов P/E. А если вы пересылаете логи в облако для удалённой отладки, то больший объём — это ещё и больше денег на устройство: вопрос «сколько» становится не только про срок службы, но и про стоимость эксплуатации парка.

В каком виде хранить? Простой текст читать легче всего и искать проще всего, но он быстро растёт. Бинарные сжатые форматы (journald) уменьшают физический объём при том же содержимом и быстрее отвечают на запросы — но требуют своих инструментов для чтения и сильнее рискуют повреждением, если что-то пойдёт не так посреди записи.

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

Ни одна из этих настроек не выставляется один раз и навсегда. Это компромиссы, к которым стоит возвращаться по мере того, как меняются парк устройств, прошивка и характер отказов.