[v2,3/6] Add a mutex to guarantee single writer to qemu_logfile handle.

Also added qemu_logfile_init() for initializing the logfile mutex.

Signed-off-by: Robert Foley <robert.foley@linaro.org>
---
v2
    - In qemu_set_log() moved location of mutex lock/unlock 
      due to cleanup changes.
---
v1
    - changed qemu_logfile_init() to use __constructor__.
---
 util/log.c | 14 ++++++++++++++
 1 file changed, 14 insertions(+)

Robert Foley <robert.foley@linaro.org> writes:

> Also added qemu_logfile_init() for initializing the logfile mutex.
>
> Signed-off-by: Robert Foley <robert.foley@linaro.org>
> ---
> v2
>     - In qemu_set_log() moved location of mutex lock/unlock
>       due to cleanup changes.
> ---
> v1
>     - changed qemu_logfile_init() to use __constructor__.
> ---
>  util/log.c | 14 ++++++++++++++
>  1 file changed, 14 insertions(+)
>
> diff --git a/util/log.c b/util/log.c
> index 417d16ec66..91ebb5c924 100644
> --- a/util/log.c
> +++ b/util/log.c
> @@ -24,8 +24,10 @@
>  #include "qapi/error.h"
>  #include "qemu/cutils.h"
>  #include "trace/control.h"
> +#include "qemu/thread.h"
>
>  static char *logfilename;
> +static QemuMutex qemu_logfile_mutex;
>  FILE *qemu_logfile;
>  int qemu_loglevel;
>  static int log_append = 0;
> @@ -49,6 +51,11 @@ int qemu_log(const char *fmt, ...)
>      return ret;
>  }
>
> +static void __attribute__((__constructor__)) qemu_logfile_init(void)
> +{
> +    qemu_mutex_init(&qemu_logfile_mutex);
> +}
> +
>  static bool log_uses_own_buffers;
>
>  /* enable or disable low levels log */
> @@ -70,7 +77,10 @@ void qemu_set_log(int log_flags)
>      if (qemu_loglevel && (!is_daemonized() || logfilename)) {
>          need_to_open_file = true;
>      }
> +    g_assert(qemu_logfile_mutex.initialized);
> +    qemu_mutex_lock(&qemu_logfile_mutex);
>      if (qemu_logfile && !need_to_open_file) {
> +        qemu_mutex_unlock(&qemu_logfile_mutex);
>          qemu_log_close();
>      } else if (!qemu_logfile && need_to_open_file) {
>          if (logfilename) {
> @@ -105,6 +115,7 @@ void qemu_set_log(int log_flags)
>  #endif
>              log_append = 1;
>          }
> +        qemu_mutex_unlock(&qemu_logfile_mutex);
>      }
>  }

This looks a bit odd. I can see it's fixed up in a later patch but I
guess the reason is to avoid a double lock when we get to
qemu_log_close(). In the cases of unavoidable temporary ugliness in a
patch series it is best to note the problem and mention it will be
cleaned up by a later patch in the series.

With an extra comment in the commit message:

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>

>
> @@ -240,12 +251,15 @@ void qemu_log_flush(void)
>  /* Close the log file */
>  void qemu_log_close(void)
>  {
> +    g_assert(qemu_logfile_mutex.initialized);
> +    qemu_mutex_lock(&qemu_logfile_mutex);
>      if (qemu_logfile) {
>          if (qemu_logfile != stderr) {
>              fclose(qemu_logfile);
>          }
>          qemu_logfile = NULL;
>      }
> +    qemu_mutex_unlock(&qemu_logfile_mutex);
>  }
>
>  const QEMULogItem qemu_log_items[] = {


--
Alex Bennée

On Mon, 18 Nov 2019 at 07:16, Alex Bennée <alex.bennee@linaro.org> wrote:
>
> > +    qemu_mutex_lock(&qemu_logfile_mutex);
> >      if (qemu_logfile && !need_to_open_file) {
> > +        qemu_mutex_unlock(&qemu_logfile_mutex);
> >          qemu_log_close();
> >      } else if (!qemu_logfile && need_to_open_file) {
> >          if (logfilename) {
> > @@ -105,6 +115,7 @@ void qemu_set_log(int log_flags)
> >  #endif
> >              log_append = 1;
> >          }
> > +        qemu_mutex_unlock(&qemu_logfile_mutex);
> >      }
> >  }
>
> This looks a bit odd. I can see it's fixed up in a later patch but I
> guess the reason is to avoid a double lock when we get to
> qemu_log_close(). In the cases of unavoidable temporary ugliness in a
> patch series it is best to note the problem and mention it will be
> cleaned up by a later patch in the series.
>
> With an extra comment in the commit message:
>
> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
>
This is true that given the order of the patches, we needed to add
this bit of temporary ugliness to avoid the double lock with this
commit, knowing that we would undo these changes later.

I will add more details to the commit message.

Thanks,
-Rob

On Mon, 18 Nov 2019 at 07:16, Alex Bennée <alex.bennee@linaro.org> wrote:
>
>
> Robert Foley <robert.foley@linaro.org> writes:
>
> > Also added qemu_logfile_init() for initializing the logfile mutex.
> >
> > Signed-off-by: Robert Foley <robert.foley@linaro.org>
> > ---
> > v2
> >     - In qemu_set_log() moved location of mutex lock/unlock
> >       due to cleanup changes.
> > ---
> > v1
> >     - changed qemu_logfile_init() to use __constructor__.
> > ---
> >  util/log.c | 14 ++++++++++++++
> >  1 file changed, 14 insertions(+)
> >
> > diff --git a/util/log.c b/util/log.c
> > index 417d16ec66..91ebb5c924 100644
> > --- a/util/log.c
> > +++ b/util/log.c
> > @@ -24,8 +24,10 @@
> >  #include "qapi/error.h"
> >  #include "qemu/cutils.h"
> >  #include "trace/control.h"
> > +#include "qemu/thread.h"
> >
> >  static char *logfilename;
> > +static QemuMutex qemu_logfile_mutex;
> >  FILE *qemu_logfile;
> >  int qemu_loglevel;
> >  static int log_append = 0;
> > @@ -49,6 +51,11 @@ int qemu_log(const char *fmt, ...)
> >      return ret;
> >  }
> >
> > +static void __attribute__((__constructor__)) qemu_logfile_init(void)
> > +{
> > +    qemu_mutex_init(&qemu_logfile_mutex);
> > +}
> > +
> >  static bool log_uses_own_buffers;
> >
> >  /* enable or disable low levels log */
> > @@ -70,7 +77,10 @@ void qemu_set_log(int log_flags)
> >      if (qemu_loglevel && (!is_daemonized() || logfilename)) {
> >          need_to_open_file = true;
> >      }
> > +    g_assert(qemu_logfile_mutex.initialized);
> > +    qemu_mutex_lock(&qemu_logfile_mutex);
> >      if (qemu_logfile && !need_to_open_file) {
> > +        qemu_mutex_unlock(&qemu_logfile_mutex);
> >          qemu_log_close();
> >      } else if (!qemu_logfile && need_to_open_file) {
> >          if (logfilename) {
> > @@ -105,6 +115,7 @@ void qemu_set_log(int log_flags)
> >  #endif
> >              log_append = 1;
> >          }
> > +        qemu_mutex_unlock(&qemu_logfile_mutex);
> >      }
> >  }
>
> This looks a bit odd. I can see it's fixed up in a later patch but I
> guess the reason is to avoid a double lock when we get to
> qemu_log_close(). In the cases of unavoidable temporary ugliness in a
> patch series it is best to note the problem and mention it will be
> cleaned up by a later patch in the series.
>
> With an extra comment in the commit message:
>
> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
>
> >
> > @@ -240,12 +251,15 @@ void qemu_log_flush(void)
> >  /* Close the log file */
> >  void qemu_log_close(void)
> >  {
> > +    g_assert(qemu_logfile_mutex.initialized);
> > +    qemu_mutex_lock(&qemu_logfile_mutex);
> >      if (qemu_logfile) {
> >          if (qemu_logfile != stderr) {
> >              fclose(qemu_logfile);
> >          }
> >          qemu_logfile = NULL;
> >      }
> > +    qemu_mutex_unlock(&qemu_logfile_mutex);
> >  }
> >
> >  const QEMULogItem qemu_log_items[] = {
>
>
> --
> Alex Bennée