[libcamera-devel,1/4] libcamera: logging: add syslog, stream, and nowhere logging targets

1675 diff mbox series

Allow logging to syslog, or any given ostream, or to nowhere. The
logging API is updated to accomodate these new logging destinations.
LogMessage is modified to allow this.

Signed-off-by: Paul Elder <paul.elder@ideasonboard.com>
---
 include/libcamera/logging.h |  13 +-
 src/libcamera/include/log.h |  11 ++
 src/libcamera/log.cpp       | 345 +++++++++++++++++++++++++++++-------
 3 files changed, 306 insertions(+), 63 deletions(-)

Hi Paul,

Thank you for the patch.

On Sat, Jul 13, 2019 at 05:16:17AM +0900, Paul Elder wrote:
> Allow logging to syslog, or any given ostream, or to nowhere. The
> logging API is updated to accomodate these new logging destinations.
> LogMessage is modified to allow this.

It's fine for this time, but review would have been easier if you had
split this patch in three: rework of the internal API to pass the
LogMessage to the Logger, addition of ostream log support and addition
of syslog support.

> Signed-off-by: Paul Elder <paul.elder@ideasonboard.com>
> ---
>  include/libcamera/logging.h |  13 +-
>  src/libcamera/include/log.h |  11 ++
>  src/libcamera/log.cpp       | 345 +++++++++++++++++++++++++++++-------
>  3 files changed, 306 insertions(+), 63 deletions(-)
> 
> diff --git a/include/libcamera/logging.h b/include/libcamera/logging.h
> index a8495cf..a6fa8dc 100644
> --- a/include/libcamera/logging.h
> +++ b/include/libcamera/logging.h
> @@ -9,8 +9,17 @@
>  
>  namespace libcamera {
>  
> -void logSetFile(const char *file);
> -int logSetLevel(const char *category, const char *level);
> +enum LoggingTarget {
> +	LoggingTargetNone,
> +	LoggingTargetSyslog,
> +	LoggingTargetFile,
> +	LoggingTargetStream,
> +};
> +
> +int logSetFile(const char *path);
> +int logSetStream(std::ostream &stream);

We're going to keep a reference to the ostream internally, so I would
pass it as a pointer.

> +int logSetTarget(LoggingTarget target);
> +void logSetLevel(const char *category, const char *level);
>  
>  } /* namespace libcamera */
>  
> diff --git a/src/libcamera/include/log.h b/src/libcamera/include/log.h
> index 802836d..394db83 100644
> --- a/src/libcamera/include/log.h
> +++ b/src/libcamera/include/log.h
> @@ -60,12 +60,23 @@ public:
>  
>  	std::ostream &stream() { return msgStream_; }
>  
> +	std::string &timestamp() { return logTimestamp_; }
> +	LogSeverity severity() { return severity_; }
> +	std::string &category() { return logCategory_; }
> +	std::string &fileInfo() { return logFileInfo_; }
> +	std::string &msg() { return msg_; }

All the functions returning a reference should return a const reference,
and be marked as const.

> +
>  private:
>  	void init(const char *fileName, unsigned int line);
>  
>  	std::ostringstream msgStream_;
>  	const LogCategory &category_;
>  	LogSeverity severity_;
> +
> +	std::string logTimestamp_;

Let's store this as a struct timespec and do the formatting in the
Logger, with everything else.

> +	std::string logCategory_;

We should expose category_ instead and drop this field.

> +	std::string logFileInfo_;

I would call this fileInfo_ as logFileInfo mislead me into thinking it
was information about the log file.

> +	std::string msg_;
>  };
>  
>  class Loggable
> diff --git a/src/libcamera/log.cpp b/src/libcamera/log.cpp
> index 709c669..df63e81 100644
> --- a/src/libcamera/log.cpp
> +++ b/src/libcamera/log.cpp
> @@ -15,8 +15,11 @@
>  #include <iostream>
>  #include <list>
>  #include <string.h>
> +#include <syslog.h>
>  #include <unordered_set>
>  
> +#include <libcamera/logging.h>
> +
>  #include "utils.h"
>  
>  /**
> @@ -60,7 +63,12 @@ class Logger
>  public:
>  	static Logger *instance();
>  
> -	void write(const std::string &msg);
> +	void write(LogMessage *msg);

	void write(const LogMessage &msg);

as passing a null msg is not valid, and you don't need to modify it.

> +
> +	int logSetFile(const char *path);
> +	int logSetStream(std::ostream &stream);

Pointer here as well.

> +	int logSetTarget(LoggingTarget target);
> +	void logSetLevel(const char *category, const char *level);
>  
>  private:
>  	Logger();
> @@ -68,9 +76,7 @@ private:
>  	void parseLogFile();
>  	void parseLogLevels();
>  	static LogSeverity parseLogLevel(const std::string &level);
> -
> -	friend int logSetFile(const char *file);
> -	friend void logSetLevel(const char *category, const char *level);
> +	void closeLog();
>  
>  	friend LogCategory;
>  	void registerCategory(LogCategory *category);
> @@ -81,40 +87,83 @@ private:
>  
>  	std::ofstream file_;
>  	std::ostream *output_;
> +
> +	enum LoggingTarget target_;

s/enum //

>  };
>  
> +/**
> + * \enum LoggingTarget
> + * \brief Log destination type
> + * \var LoggingTargetNone
> + * \brief No logging destination
> + * \sa logSetTarget

You don't need to repeat the \sa line, let's have one only after \brief.

> + * \var LoggingTargetSyslog
> + * \brief Log to syslog
> + * \sa logSetTarget
> + * \var LoggingTargetFile
> + * \brief Log to file
> + * \sa logSetFile
> + * \var LoggingTargetStream
> + * \brief Log to stream
> + * \sa logSetStream
> + */
> +
>  /**
>   * \brief Set the log file

Let's name this "Direct logging to a file" and update the other
accordingly, as it does more than just setting the log file.

> - * \param[in] file Full path to the log file
> + * \param[in] path Full path to the log file
>   *
> - * This function sets the logging output file to \a file. The previous log file,
> + * This function sets the logging output file to \a path. The previous log file,

"This function directs the log output to the file identified by \a path. The
previous log target, if any, is closed, ..."

>   * if any, is closed, and all new log messages will be written to the new log
>   * file.
>   *
> - * If \a file is a null pointer, the log is directed to stderr. If the
> - * function returns an error, the log file is not changed.
> + * If the function returns an error, the log file is not changed.

s/log file/log target/

Those three comments apply to the other functions (and the corresponding
methods of the Logger class).

>   *
>   * \return Zero on success, or a negative error code otherwise.
>   */
> -int logSetFile(const char *file)
> +int logSetFile(const char *path)
>  {
> -	Logger *logger = Logger::instance();
> -
> -	if (!file) {
> -		logger->output_ = &std::cerr;
> -		logger->file_.close();
> -		return 0;
> -	}
> +	return Logger::instance()->logSetFile(path);
> +}
>  
> -	std::ofstream logFile(file);
> -	if (!logFile.good())
> -		return -EINVAL;
> +/**
> + * \brief Set the log stream
> + * \param[in] stream Stream to send log output to
> + *
> + * This function sets the logging output stream to \a stream. The previous log file,
> + * if any, is closed, and all new log messages will be written to the new log
> + * stream.

Please wrap at 80 columns.

> + *
> + * If the function returns an error, the log file is not changed.
> + *
> + * \return Zero on success, or a negative error code otherwise.
> + */
> +int logSetStream(std::ostream &stream)
> +{
> +	return Logger::instance()->logSetStream(stream);
> +}
>  
> -	if (logger->output_ != &std::cerr)
> -		logger->file_.close();
> -	logger->file_ = std::move(logFile);
> -	logger->output_ = &logger->file_;
> -	return 0;
> +/**
> + * \brief Set the log target
> + * \param[in] target Log destination
> + *
> + * This function sets the logging output to the target specified by \a target.
> + * The allowed values of \a target are LoggingTargetNone and LoggingTargetSyslog.
> + * LoggingTargetNone will send the log output to nowhere, and LoggingTargetSyslog
> + * will send the log output to syslog. The previous log file, if any, is closed,
> + * and all new log messages will be written to the new log destination.

Wrapping here too please.

> + *
> + * LoggingTargetFile and LoggingTargetStream are not valid values for \a target.
> + * Use logSetFile() and logSetStream() instead, respectively.
> + *
> + * \sa LoggingTarget

I think you can drop this as doxygen will link to Logging Target in the
function argument.

> + *
> + * If the function returns an error, the log file is not changed.
> + *
> + * \return Zero on success, or a negative error code otherwise.
> + */
> +int logSetTarget(LoggingTarget target)
> +{
> +	return Logger::instance()->logSetTarget(target);
>  }
>  
>  /**
> @@ -134,15 +183,41 @@ int logSetFile(const char *file)
>   */
>  void logSetLevel(const char *category, const char *level)
>  {
> -	Logger *logger = Logger::instance();
> +	Logger::instance()->logSetLevel(category, level);
> +}
>  
> -	LogSeverity severity = Logger::parseLogLevel(level);
> -	if (severity == LogInvalid)
> -		return;
> +static int log_severity_to_syslog(LogSeverity severity)
> +{
> +	switch (severity) {
> +	case LogDebug:
> +		return LOG_DEBUG;
> +	case LogInfo:
> +		return LOG_INFO;
> +	case LogWarning:
> +		return LOG_WARNING;
> +	case LogError:
> +		return LOG_ERR;
> +	case LogFatal:
> +		return LOG_ALERT;
> +	default:
> +		return LOG_NOTICE;
> +	}
> +}
>  
> -	for (LogCategory *c : logger->categories_)
> -		if (!strcmp(c->name(), category))
> -			c->setSeverity(severity);
> +static const char *log_severity_name(LogSeverity severity)
> +{
> +	static const char *const names[] = {
> +		"  DBG",
> +		" INFO",
> +		" WARN",
> +		"  ERR",
> +		"FATAL",
> +	};
> +
> +	if (static_cast<unsigned int>(severity) < ARRAY_SIZE(names))
> +		return names[severity];
> +	else
> +		return "UNKWN";
>  }
>  
>  /**
> @@ -163,17 +238,119 @@ Logger *Logger::instance()
>   * \brief Write a message to the configured logger output
>   * \param[in] msg The message string

This should be updated.

>   */
> -void Logger::write(const std::string &msg)
> +void Logger::write(LogMessage *msg)
> +{
> +	std::string str;
> +
> +	switch (target_) {
> +	case LoggingTargetNone:
> +		break;
> +	case LoggingTargetSyslog:
> +		str = std::string(log_severity_name(msg->severity())) + " " +
> +		      msg->category() + " " + msg->fileInfo() + " " + msg->msg();
> +		syslog(log_severity_to_syslog(msg->severity()), "%s", str.c_str());

I would move this to a writeSyslog() method.

> +		break;
> +	case LoggingTargetFile:
> +	case LoggingTargetStream:
> +		str = msg->timestamp() + log_severity_name(msg->severity()) +
> +		      " " + msg->category() + " " + msg->fileInfo() + " " +
> +		      msg->msg();
> +		output_->write(str.c_str(), str.size());
> +		output_->flush();

And this to a writeStream() method.

> +		break;
> +	}
> +}
> +
> +/**
> + * \brief Set the log file
> + * \param[in] path Full path to the log file
> + *
> + * \sa logSetFile

Could you verify that this links to the global function, and that you
don't need to specify libcamera::logSetFile() ?

> + *
> + * \return Zero on success, or a negative error code otherwise.
> + */
> +int Logger::logSetFile(const char *path)
> +{
> +	std::ofstream logFile(path);
> +	if (!logFile.good())
> +		return -EINVAL;
> +
> +	closeLog();
> +	file_ = std::move(logFile);
> +	output_ = &file_;
> +	target_ = LoggingTargetFile;
> +
> +	return 0;
> +}
> +
> +/**
> + * \brief Set the log stream
> + * \param[in] stream Stream to send log output to
> + *
> + * \sa logSetStream
> + *
> + * \return Zero on success, or a negative error code otherwise.
> + */
> +int Logger::logSetStream(std::ostream &stream)
>  {
> -	output_->write(msg.c_str(), msg.size());
> -	output_->flush();
> +	closeLog();
> +	output_ = &stream;
> +	target_ = LoggingTargetStream;
> +	return 0;
> +}
> +
> +/**
> + * \brief Set the log target
> + * \param[in] target Log destination
> + *
> + * \sa logSetTarget
> + *
> + * \return Zero on success, or a negative error code otherwise.
> + */
> +int Logger::logSetTarget(enum LoggingTarget target)
> +{
> +	switch (target) {
> +	case LoggingTargetNone:
> +		closeLog();
> +		output_ = nullptr;
> +		target_ = LoggingTargetNone;
> +		break;
> +	case LoggingTargetSyslog:
> +		openlog("libcamera", LOG_PID, 0);
> +		closeLog();
> +		output_ = nullptr;
> +		target_ = LoggingTargetSyslog;
> +		break;
> +	default:
> +		return -EINVAL;
> +	}
> +
> +	return 0;
> +}
> +
> +/**
> + * \brief Set the log level
> + * \param[in] category Logging category
> + * \param[in] level Log level
> + *
> + * \sa logSetLevel
> + */
> +void Logger::logSetLevel(const char *category, const char *level)
> +{
> +	LogSeverity severity = Logger::parseLogLevel(level);

Now that this method is part of the Logger file you can drop the
Logger:: prefix.

> +	if (severity == LogInvalid)
> +		return;
> +
> +	for (LogCategory *c : categories_)
> +		if (!strcmp(c->name(), category))
> +			c->setSeverity(severity);

Should we break here ?

>  }
>  
>  /**
>   * \brief Construct a logger
>   */
>  Logger::Logger()
> -	: output_(&std::cerr)
> +	: output_(&std::cerr), target_(LoggingTargetStream)
>  {
>  	parseLogFile();
>  	parseLogLevels();
> @@ -184,6 +361,7 @@ Logger::Logger()
>   *
>   * If the LIBCAMERA_LOG_FILE environment variable is set, open the file it
>   * points to and redirect the logger output to it. Errors are silently ignored
> + *

?

>   * and don't affect the logger output (set to stderr).
>   */
>  void Logger::parseLogFile()
> @@ -192,9 +370,16 @@ void Logger::parseLogFile()
>  	if (!file)
>  		return;
>  
> +	if (!strcmp(file, "syslog")) {

You should document the magic "syslog" value for the LIBCAMERA_LOG_FILE
environment variable.

> +		openlog("libcamera", LOG_PID, 0);
> +		target_ = LoggingTargetSyslog;
> +		return;
> +	}
> +
>  	file_.open(file);
>  	if (file_.good())
>  		output_ = &file_;
> +	target_ = LoggingTargetFile;

Should this method call setLogSyslog() and setLogFile() instead of
duplicating the code ?

>  }
>  
>  /**
> @@ -286,6 +471,25 @@ LogSeverity Logger::parseLogLevel(const std::string &level)
>  	return static_cast<LogSeverity>(severity);
>  }
>  
> +/**
> + * \brief Close the current log file

s/file/target/

> + */
> +void Logger::closeLog()
> +{
> +	switch (target_) {
> +	case LoggingTargetNone:
> +		break;
> +	case LoggingTargetSyslog:
> +		closelog();
> +		break;
> +	case LoggingTargetFile:
> +		file_.close();
> +		break;
> +	case LoggingTargetStream:
> +		break;
> +	}

Should we add

	target_ = LoggingTargetNone;
	output_ = nullptr;

?

> +}
> +
>  /**
>   * \brief Register a log category with the logger
>   * \param[in] category The log category
> @@ -408,22 +612,6 @@ const LogCategory &LogCategory::defaultCategory()
>  	return category;
>  }
>  
> -static const char *log_severity_name(LogSeverity severity)
> -{
> -	static const char *const names[] = {
> -		"  DBG",
> -		" INFO",
> -		" WARN",
> -		"  ERR",
> -		"FATAL",
> -	};
> -
> -	if (static_cast<unsigned int>(severity) < ARRAY_SIZE(names))
> -		return names[severity];
> -	else
> -		return "UNKWN";
> -}
> -
>  /**
>   * \class LogMessage
>   * \brief Internal log message representation.
> @@ -495,16 +683,22 @@ void LogMessage::init(const char *fileName, unsigned int line)
>  	/* Log the timestamp, severity and file information. */
>  	struct timespec timestamp;
>  	clock_gettime(CLOCK_MONOTONIC, &timestamp);
> -	msgStream_.fill('0');
> -	msgStream_ << "[" << timestamp.tv_sec / (60 * 60) << ":"
> +	std::ostringstream ossTimestamp;
> +	ossTimestamp.fill('0');
> +	ossTimestamp << "[" << timestamp.tv_sec / (60 * 60) << ":"
>  		   << std::setw(2) << (timestamp.tv_sec / 60) % 60 << ":"
>  		   << std::setw(2) << timestamp.tv_sec % 60 << "."
>  		   << std::setw(9) << timestamp.tv_nsec << "]";
> -	msgStream_.fill(' ');
> +	ossTimestamp.fill(' ');
> +	logTimestamp_ = ossTimestamp.str();
> +
> +	std::ostringstream ossCategory;
> +	ossCategory << category_.name();
> +	logCategory_ = ossCategory.str();
>  
> -	msgStream_ << " " << log_severity_name(severity_);
> -	msgStream_ << " " << category_.name();
> -	msgStream_ << " " << utils::basename(fileName) << ":" << line << " ";
> +	std::ostringstream ossFileInfo;
> +	ossFileInfo << utils::basename(fileName) << ":" << line;
> +	logFileInfo_ = ossFileInfo.str();
>  }
>  
>  LogMessage::~LogMessage()
> @@ -514,11 +708,10 @@ LogMessage::~LogMessage()
>  		return;
>  
>  	msgStream_ << std::endl;
> +	msg_ = msgStream_.str();

Should we implement the LogMessage::msg() accessor as msgStream_.str()
to avoid storing a copy of the message ?

>  
> -	if (severity_ >= category_.severity()) {
> -		std::string msg(msgStream_.str());
> -		Logger::instance()->write(msg);
> -	}
> +	if (severity_ >= category_.severity())
> +		Logger::instance()->write(this);
>  
>  	if (severity_ == LogSeverity::LogFatal)
>  		std::abort();
> @@ -534,6 +727,36 @@ LogMessage::~LogMessage()
>   * \return A reference to the log message stream
>   */
>  
> +/**
> + * \fn LogMessage::timestamp()
> + * \brief Getter for the timestamp of the log message

s/Getter for/Retrieve/

> + * \return The timestamp of the message, as a string
> + */
> +
> +/**
> + * \fn LogMessage::severity()
> + * \brief Getter for the severity of the log message
> + * \return The severity of the message
> + */
> +
> +/**
> + * \fn LogMessage::category()
> + * \brief Getter for the category of the log message
> + * \return The category of the message, as a string
> + */
> +
> +/**
> + * \fn LogMessage::fileInfo()
> + * \brief Getter for the file info of the log message
> + * \return The file info of the message, as a string
> + */
> +
> +/**
> + * \fn LogMessage::msg()
> + * \brief Getter for the message text of the log message
> + * \return The message text of the message, as a string
> + */
> +
>  /**
>   * \class Loggable
>   * \brief Base class to support log message extensions