| Message ID | 20250303154844.745574-4-barnabas.pocze@ideasonboard.com |
|---|---|
| State | New |
| Headers | show |
| Series |
|
| Related | show |
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. Would it be possible for the LOG() macro to return a "blackhole" object when the severity would result in the message being discarded ? > 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@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
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@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 >
Quoting Barnabás Pőcze (2025-03-03 21:46:47) > 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@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() > >> + this looks like ... magic ? With the above discussion from Laurent on this 3/3 - perhaps 1/3 and 2/3 could be merged and this one dealt with separately. -- Kieran > >> #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 > > >
On Mon, Mar 03, 2025 at 10:46:47PM +0100, Barnabás Pőcze wrote: > 2025. 03. 03. 22:15 keltezéssel, Laurent Pinchart írta: > > 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. It's not very likely, but it would be very hard to debug. Probability times damage is hard to evaluate, but it worries me a bit. > > 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. That's certainly right. Would you recommend handling the issue through reviews to make sure log statements have no side effect ? > >> 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@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
Hi 2025. 07. 21. 20:45 keltezéssel, Kieran Bingham írta: > Quoting Barnabás Pőcze (2025-03-03 21:46:47) >> 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@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() >>>> + > > this looks like ... magic ? > > With the above discussion from Laurent on this 3/3 - perhaps 1/3 and 2/3 > could be merged and this one dealt with separately. Patch 2 is really only needed because of patch 3, so I will merge just patch 1. Regards, Barnabás Pőcze > > -- > Kieran > > >>>> #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 >>> >>
Hi Barnabás, On Wed, Jul 23, 2025 at 05:50:51PM +0200, Barnabás Pőcze wrote: > 2025. 07. 21. 20:45 keltezéssel, Kieran Bingham írta: > > Quoting Barnabás Pőcze (2025-03-03 21:46:47) > >> 2025. 03. 03. 22:15 keltezéssel, Laurent Pinchart írta: > >>> 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@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() > >>>> + > > > > this looks like ... magic ? > > > > With the above discussion from Laurent on this 3/3 - perhaps 1/3 and 2/3 > > could be merged and this one dealt with separately. > > Patch 2 is really only needed because of patch 3, so I will merge just patch 1. Let's finish the discussion on this mail thread and try to get this one merged too. > >>>> #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
Hi 2025. 07. 21. 21:30 keltezéssel, Laurent Pinchart írta: > On Mon, Mar 03, 2025 at 10:46:47PM +0100, Barnabás Pőcze wrote: >> 2025. 03. 03. 22:15 keltezéssel, Laurent Pinchart írta: >>> 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. > > It's not very likely, but it would be very hard to debug. Probability > times damage is hard to evaluate, but it worries me a bit. > >>> 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. > > That's certainly right. > > Would you recommend handling the issue through reviews to make sure log > statements have no side effect ? I have given it some thought, and sadly I have no better idea. I still believe that the advantages outweigh the potential issues. I have one anecdotal evidence: pipewire has the same behaviour and I have never seen it cause any issues (although it's probably harder to do that in C in this case); it even has a log level that can be removed from the compilation altogether (which has lead to multiple build failures over the years, but that's all). 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@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 >
On Wed, Jul 23, 2025 at 06:06:01PM +0200, Barnabás Pőcze wrote: > 2025. 07. 21. 21:30 keltezéssel, Laurent Pinchart írta: > > On Mon, Mar 03, 2025 at 10:46:47PM +0100, Barnabás Pőcze wrote: > >> 2025. 03. 03. 22:15 keltezéssel, Laurent Pinchart írta: > >>> 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. > > > > It's not very likely, but it would be very hard to debug. Probability > > times damage is hard to evaluate, but it worries me a bit. > > > >>> 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. > > > > That's certainly right. > > > > Would you recommend handling the issue through reviews to make sure log > > statements have no side effect ? > > I have given it some thought, and sadly I have no better idea. I still believe that > the advantages outweigh the potential issues. I have one anecdotal evidence: pipewire > has the same behaviour and I have never seen it cause any issues (although it's probably > harder to do that in C in this case); it even has a log level that can be removed from > the compilation altogether (which has lead to multiple build failures over the years, > but that's all). OK, let's focus on the advantages then, and cross our fingers :-) > >>>> 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@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
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
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 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@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(-) -- 2.48.1