[libcamera-devel] [PATCH v4 5/6] libcamera: internal: log: Report function on asserts

[Kieran Bingham]

Hi Laurent,

On 20/04/2021 23:05, Laurent Pinchart wrote:
> Hi Kieran,
> 
> Thank you for the patch.
> 
> On Tue, Apr 20, 2021 at 02:07:40PM +0100, Kieran Bingham wrote:
>> Report the function which fails an assertion as well as the actual
>> assertion.
>>
>> This now reports as:
>>
>> [30:08:53.218816270] [226567] FATAL default request.cpp:150 assertion "d" failed in reuse()
>> rather than:
>> [30:11:05.271888926] [228531] FATAL default request.cpp:150 assertion "d" failed
>>
>> Signed-off-by: Kieran Bingham <kieran.bingham at ideasonboard.com>
>>
>> ---
>> We could use __PRETTY_FUNCTION__ instead to get:
>> [30:17:16.736265045] [232054] FATAL default request.cpp:150 assertion "d" failed in void libcamera::Request::reuse(libcamera::Request::ReuseFlag)
> 
> Is this feature useful for an ASSERT() only, or should we print the
> function name in all log messages ?

At the moment, I didn't want to change for all, as it makes everything
longer.

What I liked about having the ASSERT say the function name is it helps
quickly identify the assertion failure.

For instance, there may be multiple identical /equivalent assertions in
lots of functions through a module.

When it happens, I want to know quickly which one it was.

For example, the Assertions added into request, as demonstrated above
would give the same print for 6 ASSERTs with only the line number as a
difference.

That's much easier to parse if it states /which/ instance of the assert
failed, without relying on a further lookup to get the initial feel for
what went wrong.


> The short function name has limited
> value, while the pretty function name is likely too long :-S

The 'too long' is why I have chosen the short version...


> Given that debugging an assertion failure involves open the source
> anyway, I wonder if there's an actual value in printing the function
> name as we have the file name and line number.

Sure - but not always if you're already deep into debugging something.

Imagine you throw a handful of extra assertions in, across a set of
functions and what you are trying to do is rapidly narrow down the
cause... function names help there to save a manual lookup process.



>>  include/libcamera/internal/log.h | 7 ++++---
>>  1 file changed, 4 insertions(+), 3 deletions(-)
>>
>> diff --git a/include/libcamera/internal/log.h b/include/libcamera/internal/log.h
>> index be0bab3c1272..b66bf55bc57d 100644
>> --- a/include/libcamera/internal/log.h
>> +++ b/include/libcamera/internal/log.h
>> @@ -117,9 +117,10 @@ LogMessage _log(const LogCategory *category, LogSeverity severity,
>>  #endif /* __DOXYGEN__ */
>>  
>>  #ifndef NDEBUG
>> -#define ASSERT(condition) static_cast<void>(({				\
>> -	if (!(condition))						\
>> -		LOG(Fatal) << "assertion \"" #condition "\" failed";	\
>> +#define ASSERT(condition) static_cast<void>(({                          \
>> +	if (!(condition))                                               \
>> +		LOG(Fatal) << "assertion \"" #condition "\" failed in " \
>> +			   << __func__ << "()";                         \
>>  }))
>>  #else
>>  #define ASSERT(condition) static_cast<void>(false && (condition))
> 

-- 
Regards
--
Kieran