В реальной системе логгер оценивают не по 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 — это более гибкая система управления потоком сообщений, при этом остающаяся быстрой, что подтверждается бенчмарками.

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

Комментарии (10)


  1. xSVPx
    07.04.2026 07:53

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

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


    1. emishkurov Автор
      07.04.2026 07:53

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


  1. a-tk
    07.04.2026 07:53

    Вопрос влияния на производительность при генерации сообщений ниже требуемого уровня логирования оставляем в стороне?


    1. emishkurov Автор
      07.04.2026 07:53

      конечно же никто не отменял традиционные методы фильтрации логируемых сообщений. это и уровень. да собственно и возможность полной блокировки вывода в лог. если интересно, посмотрите другую мою статью - https://habr.com/ru/articles/1012874/


      1. a-tk
        07.04.2026 07:53

        Речь про другое: если сообщение не нужно на текущем уровне логирования, то вообще не надо его формировать, включая форматирование и прочее.


        1. emishkurov Автор
          07.04.2026 07:53

          так и происходит в библиотеках, которые я рассматривал


          1. emishkurov Автор
            07.04.2026 07:53

            обратите внимание что в предлагаемой к вниманию статье benchmark библиотек логирования C++ в разделе Overhead логирования как раз рассматривает то о чем выв говорите и приводятся конкретные результаты тестирования. к условиям тестирования могут быть претензии (например, в стиле "Quill показал не лучшие результаты потому что его тестировали не в тех условиях для которых он предназначен"). но ведь там как раз суть тестов в измерении затрат на логирование в ситуации когда форматировать не нужно


  1. SpiderEkb
    07.04.2026 07:53

    Все верно в общем и целом. Пришли примерно к тому же (плюс-минус, учитывая нашу специфику - у нас вся работа с БД, соответственно, логи тоже пишутся в таблицы БД + есть настроечные таблицы для каждой системы логирования)

    Мы пришли к такой структуре. В настройках:

    • Узел логирования (близко к тому, что у вас называется "подсистема")

    • Текущий уровень логирования (остановились на трех уровнях - E - вывод только ошибок; B - вывод ошибок и бизнес сообщений и T - ошибки, бизнес сообщения и трейсы)

    • Статус активности узла

    • Глубина хранения лога для каждого уровня логирования (например, D007 для E; D005 для B и D002 для T) - поскольку все в таблицах БД, сопровождение в начале каждого дня запускает скрипт прочистки лога где удаляется все, выходящее за глубину хранения.

    В самом логе:

    • Дата

    • Таймштамп

    • Узел логирования

    • Полное имя задания (у нас все работает в изолированных заданиях - job, потоки внутри задания используются мало)

    • Уровень логирования

    • Ключ сообщения (используется для дополнительной фильтрации, может использоваться, например, для связки сообщения об ошибки с конкретной записью в БД при обработке которой эта ошибка произошла)

    • Данные сообщения

    • Точка вызова (позволяет привязать сообщение к конкретной точке кода где оно случилось)

    Кроме собственно функций записи в лог есть функция AllowLog где указывается узел логирования и уровень логирования. Сделана она для того, чтобы не тратить время на формирование сообщения лога в тех случаях, когда оно до лога не дойдет (узел логирования не активен или для него установлен уровень E, а сообщение имеет уровень B или T). Это уже было добавлено позднее по результатам нагрузочных тестов.

    Поскольку логи в БД, то работа с ними потом обычным скулем - просто, быстро и никаких проблем с фильтрацией по любому параметру (сочетанию параметров).


    1. emishkurov Автор
      07.04.2026 07:53

      Да, очень похоже на то, к чему в итоге приходят в реальных системах

      Особенно показательно, что у вас:

      • есть разбиение на узлы

      • уровень управляется отдельно

      • и отдельно появился AllowLog после нагрузочных тестов

      Это как раз иллюстрирует основной тезис статьи — логирование начинает жить своей жизнью, как отдельная подсистема, а не просто “вызовы printf”.

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

      С БД как хранилищем тоже понятный выбор, особенно если потом активно анализируете логи SQL-запросами. Тут уже больше вопрос компромисса между удобством анализа и нагрузкой на саму систему хранения.

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


      1. SpiderEkb
        07.04.2026 07:53

        С БД как хранилищем тоже понятный выбор, особенно если потом активно анализируете логи SQL-запросами. Тут уже больше вопрос компромисса между удобством анализа и нагрузкой на саму систему хранения.

        Тут влияет специфика платформы - мы работаем на IBM i (AS/400), тут БД (DB2) является частью ОС, интегрирована в нее на низком уровне (включая SQL движок) и посему очень быстрая. Особенности файловой системы, что тут нет файлов как таковых. Все есть объект. Есть объект типа PF - физический файл. Это таблица. Есть LF - логический файл, индекс (несколько шире на само деле, но ближе всего индекс), есть DSPF - дисплейный файл, описание экранной формы, есть PRTF - принтерный файл, описание формы для вывода на печать (в спул печати). А вот просто текстового файла тут нет (как хранятся исходники лучше не спрашивать - начну рассказывать во всех подробностях :-)

        Параллельно нативной ФС есть еще "интегрированная файловая система (IFS). Это уже UNIX-like ФС.

        Т.е. варианты вывода - в таблицу БД, на IFS или в спул печати. Так вот в БД не только самый удобный для последующей работы - интерактивный скуль тут есть как в терминале, так и отдельным приложением, не требующим терминала (оно еще и умеет планы запросов показывать и диагностику всякую), но и самый быстрый и экономичный по ресурсам.

        Все остальное - да, выросло в процессе работы. Система очень большая, команд много. У каждой команды в принципе своя подходы. Принципы общие, но в деталях могут быть различия. Одно время (где-то 18-19-й годы) обсуждалась централизованная система логирования, но потом пришли к тому, что будет слишком громоздко и сложно учесть во всех деталях требования всех команд. А поскольку каждая команда отвечает за свой участок (скажем, мы, комплаенс, никогда не полезем в зону ответственности той же системы расчетов или тарифного модуля), то у каждой команды свои логи. Иногда (по необходимости), их может быть несколько - у нас есть общий и еще пара под конкретные линейки, там, где требуется какая-то специфическая информация помимо той что описал выше).

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

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

        Но без логирования нельзя - это не только расследование инцидентов, но и выявление не консистентности данных, выявление ситуаций когда автоматическая обработка не проходит и требуется ручной разбор (например в каких-то ситуациях когда идет массовая обработка, та же ежегодная актуализация где в выборку попадает 25+ млн записей и какие-то из них выдают ошибку и потом уходят на ручной разбор)... Там много чего может быть.

        Но здесь идет речь исключительно о продуктовых логах. Т.е. тех ошибках, которые перехватываются и обрабатываются. К сожалению, бывают и падения - необработанные исключения. Это уже отражается в системных логах - у каждого задания всегда есть свой joblog, который ведется системой (мы, конечно, можем туда сообщения кидать, но стараемся этого не делать - они и так достаточно объемные). Пока задание активно, его можно смотреть в терминале системной командой или скулем с использованием системной UDTF. По завершению задания joblog преобразуется в спульник (spool file) и уходит в спул печати профайла из под которого это задание было запущено. Дальше его уже можно с сервера на комп вытащить в виде txt или pdf. Там все достаточно подробно, примерно вот так:

        MCH6802    Escape                  40   28.03.26  19:56:13.901238  QLEAWI       QSYS        *STMT    QLEAWI      QSYS        *STMT
                                             From module . . . . . . . . :   QLEDTAWI
                                             From procedure  . . . . . . :   CEEUTCO
                                             Statement . . . . . . . . . :   2
                                             To module . . . . . . . . . :   QLEDTAWI
                                             To procedure  . . . . . . . :   CEEUTCO
                                             Statement . . . . . . . . . :   2
                                             Message . . . . :   Literal values cannot be changed.
                                             Cause . . . . . :   An attempt was made to write over a literal (constant)
                                               value. A common cause of this exception condition is supplying the address
                                               of a literal as an argument when the called code is expecting to return
                                               information at that address. Note that all program calls pass arguments by
                                               address. The object that contains the literal value is QRNXUTIL.

        И сопровождение говорит "там у вас упало", то сразу "давайте джоблоги и если есть дампы".

        Т.е. тут есть разделение на логи продуктовые и системные. Продуктовые делаем сами, системные, к счастью, ведет система без нашего вмешательства.