[dm-devel] [PATCH v2 29/29] libmultipath: fix race between log_safe and log_thread_stop()

[Benjamin Marzinski]

On Fri, Oct 16, 2020 at 12:45:01PM +0200, mwilck at suse.com wrote:
> From: Martin Wilck <mwilck at suse.com>
> 
> log_safe() could race with log_thread_stop(); simply
> checking the value of log_thr has never been safe. By converting the
> mutexes to static initializers, we avoid having to destroy them, and thus
> possibly accessing a destroyed mutex in log_safe(). Furthermore, taking
> both the logev_lock and the logq_lock makes sure the logarea isn't freed
> while we are writing to it.
> 

I don't see any problems with this, but I also don't think it's necssary
to hold the log thread lock (logev_lock), just to add a message to the
queue. It seems like protecting the log queue is the job of logq_lock.
As long as log_safe() enqueues the message before flush_logqueue() is
called in log_thread_stop(), it should be fine. This could be solved by
simply having a static variable in log_pthread.c named something like
log_area_enabled, that always accessed while holding the logq_lock, and
is set to true when the log_area is created, and set to false just
before calling the flush_logqueue() in log_thread_stop(). Then log_safe
just needs to check this before calling log_enqueue(). If it's true,
then logged messages will get flushed, so it can safely enqueue the
message. If it's false, then log_safe should call vsyslog() directly. 

In fairness, if the argument is that we should try to only lock what's
absolutely necessary, then multipath has far worse offenders than
logev_lock. So I don't feel super strongly about this, if there's a
reason why you like your way better.

-Ben

> Signed-off-by: Martin Wilck <mwilck at suse.com>
> ---
>  libmultipath/log_pthread.c | 39 ++++++++++++++++++++++++--------------
>  1 file changed, 25 insertions(+), 14 deletions(-)
> 
> diff --git a/libmultipath/log_pthread.c b/libmultipath/log_pthread.c
> index 3c73941..91c9c19 100644
> --- a/libmultipath/log_pthread.c
> +++ b/libmultipath/log_pthread.c
> @@ -17,31 +17,42 @@
>  
>  static pthread_t log_thr;
>  
> -static pthread_mutex_t logq_lock;
> -static pthread_mutex_t logev_lock;
> -static pthread_cond_t logev_cond;
> +/* logev_lock must not be taken with logq_lock held */
> +static pthread_mutex_t logq_lock = PTHREAD_MUTEX_INITIALIZER;
> +static pthread_mutex_t logev_lock = PTHREAD_MUTEX_INITIALIZER;
> +static pthread_cond_t logev_cond = PTHREAD_COND_INITIALIZER;
>  
>  static int logq_running;
>  static int log_messages_pending;
>  
>  void log_safe (int prio, const char * fmt, va_list ap)
>  {
> +	bool running;
> +
>  	if (prio > LOG_DEBUG)
>  		prio = LOG_DEBUG;
>  
> -	if (log_thr == (pthread_t)0) {
> -		vsyslog(prio, fmt, ap);
> -		return;
> -	}
> +	/*
> +	 * logev_lock protects logq_running. By holding it, we avoid a race
> +	 * with log_thread_stop() -> log_close(), which would free the logarea.
> +	 */
> +	pthread_mutex_lock(&logev_lock);
> +	pthread_cleanup_push(cleanup_mutex, &logev_lock);
> +	running = logq_running;
>  
> -	pthread_mutex_lock(&logq_lock);
> -	log_enqueue(prio, fmt, ap);
> -	pthread_mutex_unlock(&logq_lock);
> +	if (running) {
> +		pthread_mutex_lock(&logq_lock);
> +		pthread_cleanup_push(cleanup_mutex, &logq_lock);
> +		log_enqueue(prio, fmt, ap);
> +		pthread_cleanup_pop(1);
>  
> -	pthread_mutex_lock(&logev_lock);
> -	log_messages_pending = 1;
> -	pthread_cond_signal(&logev_cond);
> -	pthread_mutex_unlock(&logev_lock);
> +		log_messages_pending = 1;
> +		pthread_cond_signal(&logev_cond);
> +	}
> +	pthread_cleanup_pop(1);
> +
> +	if (!running)
> +		vsyslog(prio, fmt, ap);
>  }
>  
>  static void flush_logqueue (void)
> -- 
> 2.28.0