[libcamera-devel] [PATCH] libcamera: base: log: Don't crash when logging after Logger destruction

[paul.elder at ideasonboard.com]

Hi Laurent,

On Fri, Aug 27, 2021 at 06:58:41PM +0300, Laurent Pinchart wrote:
> libcamera isn't supposed to log messages after the logger is destroyed,
> as the global logger instance is destroyed after the main() function
> returns, and the camera manager is supposed to have been stopped and
> destroyed before that.
> 
> This rule is difficult to enforce in the V4L2 compat implementation, as
> there is no location where we can destroy the camera manager manually
> before the logger is destroyed. This results in a use-after-free
> condition when the camera manager gets stopped during destruction.
> 
> Fix it by not trying to print log messages when the global logger
> instance has been destroyed.
> 
> This is a bit of a hack, but hopefully not too bad. There could be race
> conditions when using a CameraManager instance that is destroyed as part
> of the destruction of global variables (like the V4L2 compat layer does,
> it wraps CameraManager in a singleton V4L2CompatManager class, and
> destroys it when V4L2CompatManager is destroyed) as the CameraManager
> thread will still be running when the logger gets destroyed, but this
> doesn't cause any regression as we destroy the logger without any
> safeguard measure today anyway.

This looks like a good protection in general.

> 
> There are other options that could be considered. Forcing destruction of
> the logger after the camera manager in the V4L2 compat layer is one of
> them, but turned out to be difficult. For instance care would need to be
> taken *not* to log any message in the mmap() wrapper if the fd doesn't
> match a wrapped camera, as mmap() is called very early in the
> initialization process, before libcamera and the logger get initialized.
> The resulting implementation would likely be fairly complex.
> 
> Another option could be to wrap the logger with a shared pointer, and
> keep a reference to it in CameraManager. That's more intrusive, and it's
> not clear if it would be worth it.
> 
> Signed-off-by: Laurent Pinchart <laurent.pinchart at ideasonboard.com>
> ---
>  src/libcamera/base/log.cpp | 18 ++++++++++++++++--
>  1 file changed, 16 insertions(+), 2 deletions(-)
> 
> diff --git a/src/libcamera/base/log.cpp b/src/libcamera/base/log.cpp
> index 073b7c34b75e..a3e3f9ea2712 100644
> --- a/src/libcamera/base/log.cpp
> +++ b/src/libcamera/base/log.cpp
> @@ -270,12 +270,16 @@ private:
>  	friend LogCategory;
>  	void registerCategory(LogCategory *category);
>  
> +	static bool destroyed_;
> +
>  	std::unordered_set<LogCategory *> categories_;
>  	std::list<std::pair<std::string, LogSeverity>> levels_;
>  
>  	std::shared_ptr<LogOutput> output_;
>  };
>  
> +bool Logger::destroyed_ = false;

What's the merit of putting this here instead of in the constructor?


Paul

> +
>  /**
>   * \enum LoggingTarget
>   * \brief Log destination type
> @@ -372,6 +376,8 @@ void logSetLevel(const char *category, const char *level)
>  
>  Logger::~Logger()
>  {
> +	destroyed_ = true;
> +
>  	for (LogCategory *category : categories_)
>  		delete category;
>  }
> @@ -387,6 +393,10 @@ Logger::~Logger()
>  Logger *Logger::instance()
>  {
>  	static Logger instance;
> +
> +	if (destroyed_)
> +		return nullptr;
> +
>  	return &instance;
>  }
>  
> @@ -808,13 +818,17 @@ LogMessage::~LogMessage()
>  	if (severity_ == LogInvalid)
>  		return;
>  
> +	Logger *logger = Logger::instance();
> +	if (!logger)
> +		return;
> +
>  	msgStream_ << std::endl;
>  
>  	if (severity_ >= category_.severity())
> -		Logger::instance()->write(*this);
> +		logger->write(*this);
>  
>  	if (severity_ == LogSeverity::LogFatal) {
> -		Logger::instance()->backtrace();
> +		logger->backtrace();
>  		std::abort();
>  	}
>  }
> -- 
> Regards,
> 
> Laurent Pinchart
>