[libcamera-devel] [PATCH] libcamera: log: Print the function name in log

Niklas Söderlund niklas.soderlund at ragnatech.se
Sat Aug 17 15:45:56 CEST 2019


Hi Jacopo, Laurent,

On 2019-08-12 18:18:03 +0300, Laurent Pinchart wrote:
> Hi Jacopo,
> 
> Thank you for the patch.
> 
> On Mon, Aug 12, 2019 at 02:49:19PM +0200, Jacopo Mondi wrote:
> > Add the function name to the log tag.
> > 
> > With this patch applied, the log format looks like:
> > INFO Camera camera_manager.cpp - start():83 libcamera v0.0.0+655-ddf32590
> 
> I think I would prefer keeping the line number associated with the file:
> 
> INFO Camera camera_manager.cpp:83 - start() libcamera v0.0.0+655-ddf32590

I agree with Laurent here, I like to line number to be kept together 
with the file name.

> 
> or maybe
> 
> INFO Camera start() (camera_manager.cpp:83) libcamera v0.0.0+655-ddf32590
> 
> ?
> 
> I'm a bit bothered by the missing class name to be honest, as it makes
> the function name less useful without the context. The filename helps,
> but then does the function name alone bring much added value ? What's
> everybody's experience when reading logs, would the function name alone
> improve readability even if it increases the length of the lines ?

I must admit when I read logs from C++ I only look at the file.cpp:line 
marking and ignore the function name as without the class name it's not 
so useful for me. I'm not bothered by it being in the output and I have 
little concern about the length of the log lines, provided the file+line 
information is early enough on the line.

That being said and to add to the bikesheeding, if the function name is 
to be printed I think it could be useful to print it in its class 
context.  My suggested log line would be something like:

INFO Camera camera_manager.cpp:83 CameraManager::start(): libcamera v0.0.0+655-ddf32590

I do not (yet) find the Log categories super useful so I would be open 
to discuss dropping them, but then again I'm not bothered by them and 
maybe they can be useful for log filtering going forward.

> 
> > Compared to:
> > INFO Camera camera_manager.cpp:83 libcamera v0.0.0+654-a6799dc5
> > 
> > Signed-off-by: Jacopo Mondi <jacopo at jmondi.org>
> > ---
> >  src/libcamera/include/log.h | 19 +++++++++---------
> >  src/libcamera/log.cpp       | 40 ++++++++++++++++++++++---------------
> >  2 files changed, 34 insertions(+), 25 deletions(-)
> > 
> > diff --git a/src/libcamera/include/log.h b/src/libcamera/include/log.h
> > index 9b203f97e304..e65d20af1ca9 100644
> > --- a/src/libcamera/include/log.h
> > +++ b/src/libcamera/include/log.h
> > @@ -50,9 +50,9 @@ const LogCategory &_LOG_CATEGORY(name)()				\
> >  class LogMessage
> >  {
> >  public:
> > -	LogMessage(const char *fileName, unsigned int line,
> > +	LogMessage(const char *fileName, const char *func, unsigned int line,
> 
> Should we name the new parameter funcName to match fileName ? Or rename
> fileName to file ?
> 
> I would prefer keeping the file name and line number grouped, and thus
> adding the func parameter either as the first parameter of the function,
> or as the third one.
> 
> Same comments for all other functions or macros.
> 
> >  		   LogSeverity severity);
> > -	LogMessage(const char *fileName, unsigned int line,
> > +	LogMessage(const char *fileName, const char *func, unsigned int line,
> >  		   const LogCategory &category, LogSeverity severity);
> >  	LogMessage(const LogMessage &) = delete;
> >  	LogMessage(LogMessage &&);
> > @@ -67,7 +67,7 @@ public:
> >  	const std::string msg() const { return msgStream_.str(); }
> >  
> >  private:
> > -	void init(const char *fileName, unsigned int line);
> > +	void init(const char *fileName, const char* func, unsigned int line);
> >  
> >  	std::ostringstream msgStream_;
> >  	const LogCategory &category_;
> > @@ -84,24 +84,25 @@ public:
> >  protected:
> >  	virtual std::string logPrefix() const = 0;
> >  
> > -	LogMessage _log(const char *file, unsigned int line,
> > +	LogMessage _log(const char *file, const char *func, unsigned int line,
> >  			LogSeverity severity) const;
> > -	LogMessage _log(const char *file, unsigned int line,
> > +	LogMessage _log(const char *file, const char *func, unsigned int line,
> >  			const LogCategory &category,
> >  			LogSeverity severity) const;
> >  };
> >  
> > -LogMessage _log(const char *file, unsigned int line, LogSeverity severity);
> > -LogMessage _log(const char *file, unsigned int line,
> > +LogMessage _log(const char *file, const char *func, unsigned int line,
> > +		LogSeverity severity);
> > +LogMessage _log(const char *file, const char *func, unsigned int line,
> >  		const LogCategory &category, LogSeverity severity);
> >  
> >  #ifndef __DOXYGEN__
> >  #define _LOG_CATEGORY(name) logCategory##name
> >  
> >  #define _LOG1(severity) \
> > -	_log(__FILE__, __LINE__, Log##severity).stream()
> > +	_log(__FILE__, __func__, __LINE__, Log##severity).stream()
> >  #define _LOG2(category, severity) \
> > -	_log(__FILE__, __LINE__, _LOG_CATEGORY(category)(), Log##severity).stream()
> > +	_log(__FILE__, __func__, __LINE__, _LOG_CATEGORY(category)(), Log##severity).stream()
> >  
> >  /*
> >   * Expand the LOG() macro to _LOG1() or _LOG2() based on the number of
> > diff --git a/src/libcamera/log.cpp b/src/libcamera/log.cpp
> > index 91f7c3ee5157..fa9a16452f25 100644
> > --- a/src/libcamera/log.cpp
> > +++ b/src/libcamera/log.cpp
> > @@ -720,6 +720,7 @@ const LogCategory &LogCategory::defaultCategory()
> >  /**
> >   * \brief Construct a log message for the default category
> >   * \param[in] fileName The file name where the message is logged from
> > + * \param[in] func The function name where the message is logged from
> >   * \param[in] line The line number where the message is logged from
> >   * \param[in] severity The log message severity, controlling how the message
> >   * will be displayed
> > @@ -728,16 +729,17 @@ const LogCategory &LogCategory::defaultCategory()
> >   * \a severity argument sets the message severity to control whether it will be
> >   * output or dropped.
> >   */
> > -LogMessage::LogMessage(const char *fileName, unsigned int line,
> > +LogMessage::LogMessage(const char *fileName, const char *func ,unsigned int line,
> >  		       LogSeverity severity)
> >  	: category_(LogCategory::defaultCategory()), severity_(severity)
> >  {
> > -	init(fileName, line);
> > +	init(fileName, func, line);
> >  }
> >  
> >  /**
> >   * \brief Construct a log message for a given category
> >   * \param[in] fileName The file name where the message is logged from
> > + * \param[in] func The function name where the message is logged from
> >   * \param[in] line The line number where the message is logged from
> >   * \param[in] category The log message category, controlling how the message
> >   * will be displayed
> > @@ -748,11 +750,11 @@ LogMessage::LogMessage(const char *fileName, unsigned int line,
> >   * \a severity argument sets the message severity to control whether it will be
> >   * output or dropped.
> >   */
> > -LogMessage::LogMessage(const char *fileName, unsigned int line,
> > +LogMessage::LogMessage(const char *fileName, const char *func, unsigned int line,
> >  		       const LogCategory &category, LogSeverity severity)
> >  	: category_(category), severity_(severity)
> >  {
> > -	init(fileName, line);
> > +	init(fileName, func, line);
> >  }
> >  
> >  /**
> > @@ -774,13 +776,14 @@ LogMessage::LogMessage(LogMessage &&other)
> >  	other.severity_ = LogInvalid;
> >  }
> >  
> > -void LogMessage::init(const char *fileName, unsigned int line)
> > +void LogMessage::init(const char *fileName, const char *func, unsigned int line)
> >  {
> >  	/* Log the timestamp, severity and file information. */
> >  	clock_gettime(CLOCK_MONOTONIC, &timestamp_);
> >  
> >  	std::ostringstream ossFileInfo;
> > -	ossFileInfo << utils::basename(fileName) << ":" << line;
> > +	ossFileInfo << utils::basename(fileName) << " - "
> > +		    << func << "():" << line;
> >  	fileInfo_ = ossFileInfo.str();
> >  }
> >  
> > @@ -868,6 +871,7 @@ Loggable::~Loggable()
> >  /**
> >   * \brief Create a temporary LogMessage object to log a message
> >   * \param[in] fileName The file name where the message is logged from
> > + * \param[in] func The function name where the message is logged from
> >   * \param[in] line The line number where the message is logged from
> >   * \param[in] severity The log message severity
> >   *
> > @@ -876,10 +880,10 @@ Loggable::~Loggable()
> >   *
> >   * \return A log message
> >   */
> > -LogMessage Loggable::_log(const char *fileName, unsigned int line,
> > -			  LogSeverity severity) const
> > +LogMessage Loggable::_log(const char *fileName, const char *func,
> > +			  unsigned int line, LogSeverity severity) const
> >  {
> > -	LogMessage msg(fileName, line, severity);
> > +	LogMessage msg(fileName, func, line, severity);
> >  
> >  	msg.stream() << logPrefix() << ": ";
> >  	return msg;
> > @@ -888,6 +892,7 @@ LogMessage Loggable::_log(const char *fileName, unsigned int line,
> >  /**
> >   * \brief Create a temporary LogMessage object to log a message
> >   * \param[in] fileName The file name where the message is logged from
> > + * \param[in] func The function name where the message is logged from
> >   * \param[in] line The line number where the message is logged from
> >   * \param[in] category The log message category
> >   * \param[in] severity The log message severity
> > @@ -897,11 +902,11 @@ LogMessage Loggable::_log(const char *fileName, unsigned int line,
> >   *
> >   * \return A log message
> >   */
> > -LogMessage Loggable::_log(const char *fileName, unsigned int line,
> > -			  const LogCategory &category,
> > +LogMessage Loggable::_log(const char *fileName, const char *func,
> > +			  unsigned int line, const LogCategory &category,
> >  			  LogSeverity severity) const
> >  {
> > -	LogMessage msg(fileName, line, category, severity);
> > +	LogMessage msg(fileName, func, line, category, severity);
> >  
> >  	msg.stream() << logPrefix() << ": ";
> >  	return msg;
> > @@ -910,6 +915,7 @@ LogMessage Loggable::_log(const char *fileName, unsigned int line,
> >  /**
> >   * \brief Create a temporary LogMessage object to log a message
> >   * \param[in] fileName The file name where the message is logged from
> > + * \param[in] func The function name where the message is logged from
> >   * \param[in] line The line number where the message is logged from
> >   * \param[in] severity The log message severity
> >   *
> > @@ -918,14 +924,16 @@ LogMessage Loggable::_log(const char *fileName, unsigned int line,
> >   *
> >   * \return A log message
> >   */
> > -LogMessage _log(const char *fileName, unsigned int line, LogSeverity severity)
> > +LogMessage _log(const char *fileName, const char *func,
> > +		unsigned int line, LogSeverity severity)
> >  {
> > -	return LogMessage(fileName, line, severity);
> > +	return LogMessage(fileName, func, line, severity);
> >  }
> >  
> >  /**
> >   * \brief Create a temporary LogMessage object to log a message
> >   * \param[in] fileName The file name where the message is logged from
> > + * \param[in] func The function name where the message is logged from
> >   * \param[in] line The line number where the message is logged from
> >   * \param[in] category The log message category
> >   * \param[in] severity The log message severity
> > @@ -935,10 +943,10 @@ LogMessage _log(const char *fileName, unsigned int line, LogSeverity severity)
> >   *
> >   * \return A log message
> >   */
> > -LogMessage _log(const char *fileName, unsigned int line,
> > +LogMessage _log(const char *fileName, const char *func, unsigned int line,
> >  		const LogCategory &category, LogSeverity severity)
> >  {
> > -	return LogMessage(fileName, line, category, severity);
> > +	return LogMessage(fileName, func, line, category, severity);
> >  }
> >  
> >  /**
> 
> -- 
> Regards,
> 
> Laurent Pinchart
> _______________________________________________
> libcamera-devel mailing list
> libcamera-devel at lists.libcamera.org
> https://lists.libcamera.org/listinfo/libcamera-devel

-- 
Regards,
Niklas Söderlund


More information about the libcamera-devel mailing list