Макросы логирования в C++: почему всё так сложно

Когда разработчик впервые смотрит на современную библиотеку логирования для C++, его почти всегда удивляет одно и то же: количество макросов.

Почему их так много? Разве нельзя просто сделать одну красивую функцию Log() и успокоиться? Почему у библиотек вроде logme появляются десятки вариантов вроде LogmeI, LogmeW, LogmePV, fLogmeD, CH, SID, CHINT и других?

На первый взгляд всё это выглядит как историческое наследие времен C89. Однако если попытаться написать действительно удобную и быструю систему логирования для production-приложений, выясняется неприятная вещь: многие возможности C++ начинают работать против вас.

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

Простая функция логирования выглядит хорошо только в примерах

Почти все начинают примерно так:

void Log(LogLevel level, const std::string& text);

или чуть современнее:

template<typename... Args>
void Log(LogLevel level, std::format_string<Args...> fmt, Args&&... args);

В тестовом проекте это выглядит отлично. Однако проблемы начинаются очень быстро.

Например, хочется автоматически видеть:

• файл
• строку
• функцию
• subsystem
• channel
• thread id

Можно, конечно, вручную передавать __FILE__ и __LINE__, но уже через несколько дней становится понятно, что никто не хочет писать такое: 

Log(
  INFO
  , __FILE__
  , __LINE__
  , __FUNCTION__
  , "Connected to {}"
  , host 
);

 В результате макрос решает эту проблему намного естественнее:

LogmeI("Connected to %s", host.c_str());

Теперь библиотека сама знает:

• откуда был вызов
• какой уровень логирования использовался
• какой subsystem активен
• какие OutputFlags применяются

Именно поэтому с этого момента количество макросов начинает быстро расти.

Почему макросы логирования в C++ до сих пор используются

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

Главная причина — стоимость отключенного логирования.

Представим такой код:

LogmeD("Result: %s", ExpensiveOperation().c_str());

Если DEBUG-логирование отключено, разработчик ожидает почти нулевой overhead. При этом без макроса добиться такого поведения сложно.

Обычная функция увидит уже вычисленные аргументы. То есть ExpensiveOperation() всё равно выполнится.

Макрос позволяет проверить уровень логирования еще до вычисления параметров: 

if (Channel->CanWrite(DEBUG)) 
{ 
  ... 
}

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

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

Почему макросов логирования в C++ так много

Вот здесь начинается самое интересное.

Когда библиотека логирования становится большой, оказывается, что одного стиля вызова недостаточно.

Кто-то, например, предпочитает printf-style:

LogmeI("Socket %d connected to %s", socket, host.c_str());

Другие разработчики, напротив, предпочитают stream-style:

LogmeI() << "Socket " << socket << " connected to " << host;

В logme поддерживаются оба варианта. Причем через один и тот же макрос.

Если форматная строка передана — используется форматирование. Если нет — макрос возвращает объект для потокового вывода.

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

Однако вместе с этим сразу появляются дополнительные сложности:

• single statement semantics
• временные объекты
• lifetime stream builder’ов
• обработка пустых __VA_ARGS__
• MSVC preprocessor quirks

И всё это приходится учитывать внутри макросов.

Даже препроцессоры компиляторов ведут себя по-разному

Кроме того, это отдельная боль любой серьезной logging library.

Многие разработчики не сталкиваются с этим, пока не попытаются написать сложный variadic macro.

Например:

#define MYLOG(...)

звучит просто. Однако дальше внезапно выясняется:

• старый MSVC ведет себя не так как Clang
• __VA_OPT__ есть не везде
• IntelliSense может видеть код иначе чем настоящий компилятор
• разные preprocessors MSVC дают разный результат

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

В logme это особенно заметно из-за большого количества макросов и поддержки разных режимов вызова.

Почему inline functions не заменяют макросы логирования в C++

После появления std::source_location многим показалось, что проблема наконец решена.

Теперь можно писать:

Log(
  std::source_location::current(),
  "Connected"
);

И это действительно помогает.

Тем не менее полностью заменить макросы это не может.

Например:

• всё еще остается проблема disabled logging
• нужны compile-time shortcuts
• нужно удобно задавать уровень логирования
• хочется минимального синтаксического шума
• нужно поддерживать stream-style вызовы

В реальном production-коде разница между:

LogmeW("Connection timeout");

и

Log(
  LogLevel::Warning,
  std::source_location::current(),
  "Connection timeout"
);

оказывается намного важнее, чем кажется.

Особенно когда таких вызовов в проекте десятки тысяч.

В какой-то момент логирование становится DSL

Это интересный эффект, который хорошо заметен в больших logging frameworks.

Макросы начинают формировать почти отдельный язык внутри C++.

Например, в logme появляются:

• subsystem macros
• channel shortcuts
• profiling macros
• conditional logging
• once/every-interval logging
• stream and printf duality

Код начинает выглядеть уже не как вызовы функций, а как описание событий системы:

LogmePV();
LogmeD(CH("NET"), "connected to %s", host.c_str());
LogmeW_EVERY(1000, "retrying...");

И это, конечно, не случайно.

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

Именно поэтому библиотеки вроде logme постепенно приходят к большому набору специализированных макросов.

Самое сложное — сделать всё это быстрым

Снаружи макросы выглядят простыми. На практике внутри современной logging library обычно скрывается огромное количество оптимизаций.

Например, в logme используется ContextCache — статический объект на месте вызова, который хранит уже разобранное состояние форматирования.

Это позволяет избежать повторного парсинга строки и уменьшить overhead при массовом логировании.

Со стороны пользователя всё выглядит очень просто:

LogmeI("value=%d", value);

Но внутри библиотека уже:

• знает call site
• кеширует формат
• переиспользует состояние
• минимизирует allocations
• пытается удешевить disabled path

И значительная часть этой механики завязана именно на макросы.

Поэтому идеального решения здесь нет

Иногда можно услышать мнение, что «нормальная библиотека должна обходиться без макросов».

На практике, однако, всё намного сложнее.

Если библиотека:

• должна быть быстрой
• удобной
• portable
• поддерживать разные стили вызова
• давать zero-cost disabled logging
• автоматически собирать context

то количество макросов почти неизбежно начинает расти.

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