[PATCH v1 3/3] libcamera: base: log: Do not instantiate disabled `LogMessage`s

[Barnabás Pőcze]

Hi


2025. 03. 03. 22:15 keltezéssel, Laurent Pinchart írta:
> Hi Barnabás,
> 
> Thank you for the patch.
> 
> On Mon, Mar 03, 2025 at 04:48:44PM +0100, Barnabás Pőcze wrote:
>> At the moment every `LOG()` macro invocation results in a `LogMessage`
>> being created, the message serialized into an `std::stringstream`.
>> Only in the destructor is is actually checked whether the corresponding
>> `LogCategory` enables the given log level.
>>
>> This is not too efficient, it would be better to skip the log message
>> construction and all the `operator<<()` invocations if the message will
>> just be discarded.
> 
> This means that the behaviour of a LOG() statement where operands have
> side effects would differ depending on the log level. We should really
> not use any expression with side effects when logging, but if we happen
> to do so, the resulting issue would be fairly hard to debug.

That is true, but how likely is it? Do you think the likelihood is big
enough to warrant this? I would assume it is unlikely.


> 
> Would it be possible for the LOG() macro to return a "blackhole" object
> when the severity would result in the message being discarded ?

If we had `LOG(X, Y, args...)`, then it would be more or less trivial.
But with the current status quo I think something like this is needed:

   struct LogMessageStream {
     std::ostringstream *const s = nullptr;

     template<typename T, typename = std::void_t<decltype(*s << std::declval<const T&>())>>
     LogMessageStream operator<<(const T& x) const
     {
       if (s) *s << x;
       return *this;
     }
   };

I am not sure how well the optimizer can handle this (probably not too bad).
Also there are still many `x.toString()` calls, and especially in log messages,
which would unfortunately still be evaluated unnecessarily.


Regards,
Barnabás Pőcze


> 
>> This could be easily if the `LOG()` macro accepted its arguments
>> like a traditional function as in that case an appropriate `if`
>> statement can be injected in a do-while loop. However, that is
>> not the case, the `LOG()` macro should effectively "return"
>> a stream.
>>
>> It is not possible inject an `if` statement directly as that would
>> lead to issues:
>>
>>    if (...)
>>      LOG(...)
>>    else
>>     ...
>>
>> The `else` would bind the to the `if` in the `LOG()` macro. This is
>> diagnosed by `-Wdangling-else`.
>>
>> An alternative approach would be to use a `for` loop and force
>> a single iteration using a boolean flag or similar. This is entirely
>> doable but I think the implemented approach is easier to understand.
>>
>> This change implements the early log level checking using a `switch`
>> statement as this avoids the dangling else related issues. One small
>> issue arises because having a boolean controlling expression is diagnosed
>> by clang (`-Wswitch-bool`); the result is cast to `int` to avoid the warning.
>>
>> Signed-off-by: Barnabás Pőcze <barnabas.pocze at ideasonboard.com>
>> ---
>>
>> One remaining questions is the handling of "Fatal" log messages. I think
>> it would make sense to handle them separately because that way the compiler
>> could be told that it is actually a `[[noreturn]]` function call.
>>
>> ---
>>   include/libcamera/base/log.h | 9 +++++++--
>>   1 file changed, 7 insertions(+), 2 deletions(-)
>>
>> diff --git a/include/libcamera/base/log.h b/include/libcamera/base/log.h
>> index 958cb488d..1a14b8dbc 100644
>> --- a/include/libcamera/base/log.h
>> +++ b/include/libcamera/base/log.h
>> @@ -108,10 +108,15 @@ LogMessage _log(const LogCategory &category, LogSeverity severity,
>>   #ifndef __DOXYGEN__
>>   #define _LOG_CATEGORY(name) logCategory##name
>>
>> +#define _LOG(cat, sev) \
>> +	switch (const auto &_logCategory = (cat); int(_logCategory.severity() <= Log##sev)) \
>> +	case 1: \
>> +		_log(_logCategory, Log##sev).stream()
>> +
>>   #define _LOG1(severity) \
>> -	_log(LogCategory::defaultCategory(), Log##severity).stream()
>> +	_LOG(LogCategory::defaultCategory(), severity)
>>   #define _LOG2(category, severity) \
>> -	_log(_LOG_CATEGORY(category)(), Log##severity).stream()
>> +	_LOG(_LOG_CATEGORY(category)(), severity)
>>
>>   /*
>>    * Expand the LOG() macro to _LOG1() or _LOG2() based on the number of
>