In our case the difference logging level was set to ERROR. There were no lines logged. I ran a valgrind with no special settings
- log4cpp was approximately 5% of total running time
- after modifying logging macros, it was 0.02%
The effect would depend on how one does logging. If the logging statements are simple strings, then I would not expect a huge impact. In our case the statements could look like
GR_LOG_DEBUG(d_logger, fmt::format("frequency = {} sample rate = {}", freq, samplerate));
The formatting string will be evaluated to get a char* even if logging level is INFO due to being an _expression_ in an operator call.
With simple string literal for log statement, a CategoryStream would need to be created regardless of the logging level.
I had another look at log4cpp source and there are log calls that allow variadic parameter lists similar to sprintf statements after the level has been confirmed. Maybe they were deemed too heavy for the case of simple logging.
I essentially just did what Jeff mentioned - added priority check into the macro. So instead of
#define GR_LOG_INFO(logger, msg) \
{ \
*logger << log4cpp::Priority::INFO << (msg) << log4cpp::eol; \
}
we use
#define ALB_LOG_INFO(logger, msg) \
{ \
if (logger->isPriorityEnabled(log4cpp::Priority::INFO)) \
*logger << log4cpp::Priority::INFO << (msg) << log4cpp::eol; \
}
This is just a stop-gap, really. It is not ideal since, if a logger is enabled, the isPriorityEnabled(..) is called twice. But in the short term, it does the job. If the logger is not enabled the priority is checked once and logging statement is not evaluated.
Hope that made sense.
Cheers
Boris