Логгер — это не про скорость: что действительно важно в дизайне

В реальной системе логгер оценивают не по API и не по синтаксису вызова. Его оценивают в момент инцидента— когда нужно быстро понять, что сломалось, и не положить сервис дополнительной нагрузкой.

Логгер — это не только про скорость вывода

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

Первая проблема, которая всплывает практически сразу, связана не со скоростью, а со структурой. Лог начинает отражать структуру кода, а не структуру происходящего. Есть бизнес‑логика, есть библиотеки, есть множество параллельных операций, и каждая из них пишет что‑то своё. В итоге лог превращается в поток сообщений, где перемешаны разные задачи, и вместо «обработки конкретного запроса» мы видим просто последовательность вызовов. На небольшом проекте это ещё можно терпеть, но в серверной системе такая картина быстро становится непригодной для анализа.

Естественное желание — привязать лог не к месту вызова, а к самой задаче. Самый прямой путь — передавать контекст через параметры (например, инстанс логгера), но довольно быстро это начинает протекать через весь код и превращается в обязательный шум в сигнатурах. Гораздо более устойчивый подход — привязать контекст к потоку выполнения. В библиотеке logme это делается через thread channel:

auto requestCh = Logme::Instance->CreateChannel(Logme::ID("req-42"));
LogmeThreadChannel(requestCh);

HandleRequest();

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

void ParseHeaders()
{
  LogmeW("invalid header");
}

В этот момент лог начинает соответствовать структуре работы системы: можно открыть лог и увидеть, что происходило в рамках конкретной операции. В более классических моделях, как в spdlog или Quill, основной единицей остаётся logger, и контекст приходится организовывать вокруг него. Это проще концептуально, но хуже ложится на сценарий, где важно логировать именно «задачу», а не «объект логгера».

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

LogmeW(LOGME_ONCE4THIS, "disk is full");

Важно понимать, что здесь происходит: сообщение будет выведено только один раз для данного экземпляра класса (за счёт механизма OverrideGenerator), даже если этот код вызывается многократно. Это позволяет зафиксировать проблему и при этом не разрушить читаемость лога повторяющимися строками.

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

Хорошо это видно на примере HTTP/2. Это мультиплексированный протокол, в рамках одного соединения обрабатывается множество запросов. Обычно хочется иметь два уровня логирования: лог всего соединения (уровень протокола) и отдельные логи для каждого запроса. При этом сообщения уровня запроса полезно видеть и в логе соединения, поэтому канал протокола прилинкован к каналу запроса.

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

Logme::Override ovr;
ovr.Add.DisableLink = true;

LogmeI(ovr, "request-specific detail");

По умолчаниюсообщение из канала запроса попало бы и в связанный канал протокола. DisableLink = true останавливает это распространение, и сообщение остаётся только в локальном канале. В результате получается естественная модель: сообщения общего уровня пишутся без override и видны везде, а сообщения частного уровня остаются там, где им и место. Это позволяет одновременно держать протокольный лог компактным и лог запроса — детальным.

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

В этом случае появляется второй уровень детализации — subsystem:

LOGME_SUBSYSTEM(cacheSid, "cache");
LOGME_SUBSYSTEM(parserSid, "parser");

LogmeD(cacheSid, "cache miss");
LogmeD(parserSid, "header parsed");

Дальше важен не сам код, а управление. В рантайме можно включить логирование только для одной подсистемы, например cache, оставив остальные выключенными. В этом случае в лог попадёт только сообщение про cache miss, а header parsed вообще не будет выведено.

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

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

void FfmpegLogCallback(void* ptr, int level, const char* fmt, va_list args)
{
  char buffer[2048];
  vsnprintf(buffer, sizeof(buffer), fmt, args);

  Logme::Override ovr;
  ovr.Add.DisableLink = true;

  LogmeW(ovr, "[ffmpeg] %s", buffer);
}

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

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

LogmeI("value=%i", value);
fLogmeI("value={}", value);
LogmeI() << "value=" << value;

В spdlog основной акцент сделан на fmt, а в Quill форматирование является частью backend pipeline: вызывающий поток лишь передаёт данные, а преобразование в строку и запись происходят асинхронно. При этом используется тот же fmt/std::format, отличие не в формате, а в моменте выполнения. В logme допускается сосуществование нескольких моделей.

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

В нормальном режиме такие системы логируют минимум, чтобы не влиять на производительность. Но как только возникает проблема, ситуация меняется. Нужно быстро понять, что происходит, и при этом нет возможности остановить систему и “посмотреть внимательнее”.

Типичный сценарий при этом выглядит довольно просто. Возникает проблема, и по симптомам есть подозрение, что она связана, например, с кешем. Вместо того чтобы включать подробное логирование для всей системы, включается только подсистема cache. Если этого недостаточно, можно дополнительно изолировать конкретную задачу через thread channel, чтобы её лог не смешивался с остальными. Если появляются повторяющиеся ошибки, они ограничиваются, чтобы лог оставался читаемым.

При этом важно, что такое управление делается динамически — уже на работающей системе. В logme для этого используется утилита logmectl, которая позволяет включать и выключать подсистемы, менять уровни и поведение логирования без перезапуска процесса.

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

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

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

Если посмотреть на популярные библиотеки под этим углом, становится видно, что они делают акцент на разных вещах. spdlog — это очень быстрый и простой инструмент записи. Quill — это строго организованный асинхронный pipeline. logme — это более гибкая система управления потоком сообщений, при этом остающаяся быстрой, что подтверждается бенчмарками.

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