[PATCH v2 0/6] Make the qemu_logfile handle thread safe.

[PATCH v2 0/6] Make the qemu_logfile handle thread safe.

[Robert Foley]

This patch adds thread safety to the qemu_logfile handle.  This now
allows changing the logfile while logging is active, and also solves 
the issue of a seg fault while changing the logfile.

This patch adds use of RCU for handling the swap out of the 
old qemu_logfile file descriptor.

Also added a few tests for logfile including changing the logfile
and closing the logfile.

One change also added for a pre-existing double free issue in 
qemu_set_log_filename() uncovered with the new test.

We also cleaned up the flow of code in qemu_set_log().

---
v2
    - This version of the patch adds some cleanup of code in
      qemu_set_log().
    - Also changed the order of patches to move our fix for the
      double free issue in qemu_set_log_filename() up to the beginning
      of the patch.
---
v1
    - This version of the patch incorporates changes 
      from the first round of review.  
    - It also includes a fix for an issue in
      qemu_set_log_filename().  This issue was uncovered 
      by the test added for this patch.
---
Robert Foley (6):
  Fix double free issue in qemu_set_log_filename().
  Cleaned up flow of code in qemu_set_log(), to simplify and clarify.
  Add a mutex to guarantee single writer to qemu_logfile handle.
  qemu_log_lock/unlock now preserves the qemu_logfile handle.
  Add use of RCU for qemu_logfile.
  Added tests for close and change of logfile.

 accel/tcg/cpu-exec.c          |   4 +-
 accel/tcg/translate-all.c     |   4 +-
 accel/tcg/translator.c        |   4 +-
 exec.c                        |   4 +-
 hw/net/can/can_sja1000.c      |   4 +-
 include/exec/log.h            |  33 +++++++++--
 include/qemu/log.h            |  49 +++++++++++++---
 net/can/can_socketcan.c       |   5 +-
 target/cris/translate.c       |   4 +-
 target/i386/translate.c       |   5 +-
 target/lm32/translate.c       |   4 +-
 target/microblaze/translate.c |   4 +-
 target/nios2/translate.c      |   4 +-
 target/tilegx/translate.c     |   7 ++-
 target/unicore32/translate.c  |   4 +-
 tcg/tcg.c                     |  28 ++++++----
 tests/test-logging.c          |  80 ++++++++++++++++++++++++++
 util/log.c                    | 102 ++++++++++++++++++++++++++--------
 18 files changed, 275 insertions(+), 74 deletions(-)

-- 
2.17.1

[PATCH v2 1/6] Fix double free issue in qemu_set_log_filename().

[Robert Foley]

After freeing the logfilename, we set logfilename to NULL, in case of an
error which returns without setting logfilename.

Signed-off-by: Robert Foley <robert.foley@linaro.org>
Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
---
v2
    - moved this change to the beginning of the patch series.
---
v1
    - This is new in the patch v1.
---
 util/log.c | 1 +
 1 file changed, 1 insertion(+)

diff --git a/util/log.c b/util/log.c
index 1ca13059ee..4316fe74ee 100644
--- a/util/log.c
+++ b/util/log.c
@@ -113,6 +113,7 @@ void qemu_set_log_filename(const char *filename, Error **errp)
 {
     char *pidstr;
     g_free(logfilename);
+    logfilename = NULL;
 
     pidstr = strstr(filename, "%");
     if (pidstr) {
-- 
2.17.1

[PATCH v2 2/6] Cleaned up flow of code in qemu_set_log(), to simplify and clarify.

[Robert Foley]

Also added some explanation of the reasoning behind the branches.

Signed-off-by: Robert Foley <robert.foley@linaro.org>
---
v2
    - This is new in patch v2.
---
 util/log.c | 21 +++++++++++++++------
 1 file changed, 15 insertions(+), 6 deletions(-)

diff --git a/util/log.c b/util/log.c
index 4316fe74ee..417d16ec66 100644
--- a/util/log.c
+++ b/util/log.c
@@ -54,12 +54,25 @@ static bool log_uses_own_buffers;
 /* enable or disable low levels log */
 void qemu_set_log(int log_flags)
 {
+    bool need_to_open_file = false;
     qemu_loglevel = log_flags;
 #ifdef CONFIG_TRACE_LOG
     qemu_loglevel |= LOG_TRACE;
 #endif
-    if (!qemu_logfile &&
-        (is_daemonized() ? logfilename != NULL : qemu_loglevel)) {
+    /*
+     * In all cases we only log if qemu_loglevel is set.
+     * Also:
+     *   If not daemonized we will always log either to stderr
+     *     or to a file (if there is a logfilename).
+     *   If we are daemonized,
+     *     we will only log if there is a logfilename.
+     */
+    if (qemu_loglevel && (!is_daemonized() || logfilename)) {
+        need_to_open_file = true;
+    }
+    if (qemu_logfile && !need_to_open_file) {
+        qemu_log_close();
+    } else if (!qemu_logfile && need_to_open_file) {
         if (logfilename) {
             qemu_logfile = fopen(logfilename, log_append ? "a" : "w");
             if (!qemu_logfile) {
@@ -93,10 +106,6 @@ void qemu_set_log(int log_flags)
             log_append = 1;
         }
     }
-    if (qemu_logfile &&
-        (is_daemonized() ? logfilename == NULL : !qemu_loglevel)) {
-        qemu_log_close();
-    }
 }
 
 void qemu_log_needs_buffers(void)
-- 
2.17.1

Re: [PATCH v2 2/6] Cleaned up flow of code in qemu_set_log(), to simplify and clarify.

[Alex Bennée]

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

> Also added some explanation of the reasoning behind the branches.
>
> Signed-off-by: Robert Foley <robert.foley@linaro.org>

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

> ---
> v2
>     - This is new in patch v2.
> ---
>  util/log.c | 21 +++++++++++++++------
>  1 file changed, 15 insertions(+), 6 deletions(-)
>
> diff --git a/util/log.c b/util/log.c
> index 4316fe74ee..417d16ec66 100644
> --- a/util/log.c
> +++ b/util/log.c
> @@ -54,12 +54,25 @@ static bool log_uses_own_buffers;
>  /* enable or disable low levels log */
>  void qemu_set_log(int log_flags)
>  {
> +    bool need_to_open_file = false;
>      qemu_loglevel = log_flags;
>  #ifdef CONFIG_TRACE_LOG
>      qemu_loglevel |= LOG_TRACE;
>  #endif
> -    if (!qemu_logfile &&
> -        (is_daemonized() ? logfilename != NULL : qemu_loglevel)) {
> +    /*
> +     * In all cases we only log if qemu_loglevel is set.
> +     * Also:
> +     *   If not daemonized we will always log either to stderr
> +     *     or to a file (if there is a logfilename).
> +     *   If we are daemonized,
> +     *     we will only log if there is a logfilename.
> +     */
> +    if (qemu_loglevel && (!is_daemonized() || logfilename)) {
> +        need_to_open_file = true;
> +    }
> +    if (qemu_logfile && !need_to_open_file) {
> +        qemu_log_close();
> +    } else if (!qemu_logfile && need_to_open_file) {
>          if (logfilename) {
>              qemu_logfile = fopen(logfilename, log_append ? "a" : "w");
>              if (!qemu_logfile) {
> @@ -93,10 +106,6 @@ void qemu_set_log(int log_flags)
>              log_append = 1;
>          }
>      }
> -    if (qemu_logfile &&
> -        (is_daemonized() ? logfilename == NULL : !qemu_loglevel)) {
> -        qemu_log_close();
> -    }
>  }
>
>  void qemu_log_needs_buffers(void)


--
Alex Bennée

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

[Robert Foley]

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);
     }
 }
 
@@ -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[] = {
-- 
2.17.1

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

[Alex Bennée]

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

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

[Robert Foley]

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

[PATCH v2 4/6] qemu_log_lock/unlock now preserves the qemu_logfile handle.

[Robert Foley]

qemu_log_lock() now returns a handle and qemu_log_unlock() receives a
handle to unlock.  This allows for changing the handle during logging
and ensures the lock() and unlock() are for the same file.

Signed-off-by: Robert Foley <robert.foley@linaro.org>
Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
---
v1
    - Moved this up in the patch sequence to be
      before adding RCU for qemu_logfile.
---
 include/qemu/log.h            |  9 ++++++---
 accel/tcg/cpu-exec.c          |  4 ++--
 accel/tcg/translate-all.c     |  4 ++--
 accel/tcg/translator.c        |  4 ++--
 exec.c                        |  4 ++--
 hw/net/can/can_sja1000.c      |  4 ++--
 net/can/can_socketcan.c       |  5 ++---
 target/cris/translate.c       |  4 ++--
 target/i386/translate.c       |  5 +++--
 target/lm32/translate.c       |  4 ++--
 target/microblaze/translate.c |  4 ++--
 target/nios2/translate.c      |  4 ++--
 target/tilegx/translate.c     |  7 ++++---
 target/unicore32/translate.c  |  4 ++--
 tcg/tcg.c                     | 16 ++++++++--------
 15 files changed, 43 insertions(+), 39 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index a91105b2ad..a7c5b01571 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -53,14 +53,17 @@ static inline bool qemu_log_separate(void)
  * qemu_loglevel is never set when qemu_logfile is unset.
  */
 
-static inline void qemu_log_lock(void)
+static inline FILE *qemu_log_lock(void)
 {
     qemu_flockfile(qemu_logfile);
+    return logfile->fd;
 }
 
-static inline void qemu_log_unlock(void)
+static inline void qemu_log_unlock(FILE *fd)
 {
-    qemu_funlockfile(qemu_logfile);
+    if (fd) {
+        qemu_funlockfile(fd);
+    }
 }
 
 /* Logging functions: */
diff --git a/accel/tcg/cpu-exec.c b/accel/tcg/cpu-exec.c
index c01f59c743..62068d10c3 100644
--- a/accel/tcg/cpu-exec.c
+++ b/accel/tcg/cpu-exec.c
@@ -156,7 +156,7 @@ static inline tcg_target_ulong cpu_tb_exec(CPUState *cpu, TranslationBlock *itb)
 #if defined(DEBUG_DISAS)
     if (qemu_loglevel_mask(CPU_LOG_TB_CPU)
         && qemu_log_in_addr_range(itb->pc)) {
-        qemu_log_lock();
+        FILE *logfile = qemu_log_lock();
         int flags = 0;
         if (qemu_loglevel_mask(CPU_LOG_TB_FPU)) {
             flags |= CPU_DUMP_FPU;
@@ -165,7 +165,7 @@ static inline tcg_target_ulong cpu_tb_exec(CPUState *cpu, TranslationBlock *itb)
         flags |= CPU_DUMP_CCOP;
 #endif
         log_cpu_state(cpu, flags);
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
     }
 #endif /* DEBUG_DISAS */
 
diff --git a/accel/tcg/translate-all.c b/accel/tcg/translate-all.c
index 9f48da9472..bb325a2bc4 100644
--- a/accel/tcg/translate-all.c
+++ b/accel/tcg/translate-all.c
@@ -1804,7 +1804,7 @@ TranslationBlock *tb_gen_code(CPUState *cpu,
 #ifdef DEBUG_DISAS
     if (qemu_loglevel_mask(CPU_LOG_TB_OUT_ASM) &&
         qemu_log_in_addr_range(tb->pc)) {
-        qemu_log_lock();
+        FILE *logfile = qemu_log_lock();
         qemu_log("OUT: [size=%d]\n", gen_code_size);
         if (tcg_ctx->data_gen_ptr) {
             size_t code_size = tcg_ctx->data_gen_ptr - tb->tc.ptr;
@@ -1829,7 +1829,7 @@ TranslationBlock *tb_gen_code(CPUState *cpu,
         }
         qemu_log("\n");
         qemu_log_flush();
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
     }
 #endif
 
diff --git a/accel/tcg/translator.c b/accel/tcg/translator.c
index f977682be7..603d17ff83 100644
--- a/accel/tcg/translator.c
+++ b/accel/tcg/translator.c
@@ -138,11 +138,11 @@ void translator_loop(const TranslatorOps *ops, DisasContextBase *db,
 #ifdef DEBUG_DISAS
     if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM)
         && qemu_log_in_addr_range(db->pc_first)) {
-        qemu_log_lock();
+        FILE *logfile = qemu_log_lock();
         qemu_log("----------------\n");
         ops->disas_log(db, cpu);
         qemu_log("\n");
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
     }
 #endif
 }
diff --git a/exec.c b/exec.c
index ffdb518535..c994a00f10 100644
--- a/exec.c
+++ b/exec.c
@@ -1223,13 +1223,13 @@ void cpu_abort(CPUState *cpu, const char *fmt, ...)
     fprintf(stderr, "\n");
     cpu_dump_state(cpu, stderr, CPU_DUMP_FPU | CPU_DUMP_CCOP);
     if (qemu_log_separate()) {
-        qemu_log_lock();
+        FILE *logfile = qemu_log_lock();
         qemu_log("qemu: fatal: ");
         qemu_log_vprintf(fmt, ap2);
         qemu_log("\n");
         log_cpu_state(cpu, CPU_DUMP_FPU | CPU_DUMP_CCOP);
         qemu_log_flush();
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
         qemu_log_close();
     }
     va_end(ap2);
diff --git a/hw/net/can/can_sja1000.c b/hw/net/can/can_sja1000.c
index 1f81341554..39c78faf9b 100644
--- a/hw/net/can/can_sja1000.c
+++ b/hw/net/can/can_sja1000.c
@@ -247,8 +247,8 @@ int can_sja_accept_filter(CanSJA1000State *s,
 static void can_display_msg(const char *prefix, const qemu_can_frame *msg)
 {
     int i;
+    FILE *logfile = qemu_log_lock();
 
-    qemu_log_lock();
     qemu_log("%s%03X [%01d] %s %s",
              prefix,
              msg->can_id & QEMU_CAN_EFF_MASK,
@@ -261,7 +261,7 @@ static void can_display_msg(const char *prefix, const qemu_can_frame *msg)
     }
     qemu_log("\n");
     qemu_log_flush();
-    qemu_log_unlock();
+    qemu_log_unlock(logfile);
 }
 
 static void buff2frame_pel(const uint8_t *buff, qemu_can_frame *frame)
diff --git a/net/can/can_socketcan.c b/net/can/can_socketcan.c
index 8a6ffad40c..29bfacd4f8 100644
--- a/net/can/can_socketcan.c
+++ b/net/can/can_socketcan.c
@@ -76,8 +76,7 @@ QEMU_BUILD_BUG_ON(offsetof(qemu_can_frame, data)
 static void can_host_socketcan_display_msg(struct qemu_can_frame *msg)
 {
     int i;
-
-    qemu_log_lock();
+    FILE *logfile = qemu_log_lock();
     qemu_log("[cansocketcan]: %03X [%01d] %s %s",
              msg->can_id & QEMU_CAN_EFF_MASK,
              msg->can_dlc,
@@ -89,7 +88,7 @@ static void can_host_socketcan_display_msg(struct qemu_can_frame *msg)
     }
     qemu_log("\n");
     qemu_log_flush();
-    qemu_log_unlock();
+    qemu_log_unlock(logfile);
 }
 
 static void can_host_socketcan_read(void *opaque)
diff --git a/target/cris/translate.c b/target/cris/translate.c
index e752bd0609..cb57516a44 100644
--- a/target/cris/translate.c
+++ b/target/cris/translate.c
@@ -3273,11 +3273,11 @@ void gen_intermediate_code(CPUState *cs, TranslationBlock *tb, int max_insns)
 #if !DISAS_CRIS
     if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM)
         && qemu_log_in_addr_range(pc_start)) {
-        qemu_log_lock();
+        FILE *logfile = qemu_log_lock();
         qemu_log("--------------\n");
         qemu_log("IN: %s\n", lookup_symbol(pc_start));
         log_target_disas(cs, pc_start, dc->pc - pc_start);
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
     }
 #endif
 #endif
diff --git a/target/i386/translate.c b/target/i386/translate.c
index 77e932d827..7c99ef1385 100644
--- a/target/i386/translate.c
+++ b/target/i386/translate.c
@@ -2502,14 +2502,15 @@ static void gen_unknown_opcode(CPUX86State *env, DisasContext *s)
     gen_illegal_opcode(s);
 
     if (qemu_loglevel_mask(LOG_UNIMP)) {
+        FILE *logfile = qemu_log_lock();
         target_ulong pc = s->pc_start, end = s->pc;
-        qemu_log_lock();
+
         qemu_log("ILLOPC: " TARGET_FMT_lx ":", pc);
         for (; pc < end; ++pc) {
             qemu_log(" %02x", cpu_ldub_code(env, pc));
         }
         qemu_log("\n");
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
     }
 }
 
diff --git a/target/lm32/translate.c b/target/lm32/translate.c
index 778cae1e81..73db9654d6 100644
--- a/target/lm32/translate.c
+++ b/target/lm32/translate.c
@@ -1137,10 +1137,10 @@ void gen_intermediate_code(CPUState *cs, TranslationBlock *tb, int max_insns)
 #ifdef DEBUG_DISAS
     if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM)
         && qemu_log_in_addr_range(pc_start)) {
-        qemu_log_lock();
+        FILE *logfile = qemu_log_lock();
         qemu_log("\n");
         log_target_disas(cs, pc_start, dc->pc - pc_start);
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
     }
 #endif
 }
diff --git a/target/microblaze/translate.c b/target/microblaze/translate.c
index 761f535357..cc1ad15656 100644
--- a/target/microblaze/translate.c
+++ b/target/microblaze/translate.c
@@ -1766,10 +1766,10 @@ void gen_intermediate_code(CPUState *cs, TranslationBlock *tb, int max_insns)
 #if !SIM_COMPAT
     if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM)
         && qemu_log_in_addr_range(pc_start)) {
-        qemu_log_lock();
+        FILE *logfile = qemu_log_lock();
         qemu_log("--------------\n");
         log_target_disas(cs, pc_start, dc->pc - pc_start);
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
     }
 #endif
 #endif
diff --git a/target/nios2/translate.c b/target/nios2/translate.c
index e17656e66f..82107bf270 100644
--- a/target/nios2/translate.c
+++ b/target/nios2/translate.c
@@ -892,11 +892,11 @@ void gen_intermediate_code(CPUState *cs, TranslationBlock *tb, int max_insns)
 #ifdef DEBUG_DISAS
     if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM)
         && qemu_log_in_addr_range(tb->pc)) {
-        qemu_log_lock();
+        FILE *logfile = qemu_log_lock();
         qemu_log("IN: %s\n", lookup_symbol(tb->pc));
         log_target_disas(cs, tb->pc, dc->pc - tb->pc);
         qemu_log("\n");
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
     }
 #endif
 }
diff --git a/target/tilegx/translate.c b/target/tilegx/translate.c
index 68dd4aa2d8..fd406f4f71 100644
--- a/target/tilegx/translate.c
+++ b/target/tilegx/translate.c
@@ -2377,6 +2377,7 @@ void gen_intermediate_code(CPUState *cs, TranslationBlock *tb, int max_insns)
     uint64_t pc_start = tb->pc;
     uint64_t page_start = pc_start & TARGET_PAGE_MASK;
     int num_insns = 0;
+    FILE *logfile = NULL;
 
     dc->pc = pc_start;
     dc->mmuidx = 0;
@@ -2388,7 +2389,7 @@ void gen_intermediate_code(CPUState *cs, TranslationBlock *tb, int max_insns)
     dc->zero = NULL;
 
     if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM)) {
-        qemu_log_lock();
+        logfile = qemu_log_lock();
         qemu_log("IN: %s\n", lookup_symbol(pc_start));
     }
     gen_tb_start(tb);
@@ -2418,9 +2419,9 @@ void gen_intermediate_code(CPUState *cs, TranslationBlock *tb, int max_insns)
     tb->size = dc->pc - pc_start;
     tb->icount = num_insns;
 
-    if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM)) {
+    if (logfile) {
         qemu_log("\n");
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
     }
 }
 
diff --git a/target/unicore32/translate.c b/target/unicore32/translate.c
index 0e01f35856..0f6891b8aa 100644
--- a/target/unicore32/translate.c
+++ b/target/unicore32/translate.c
@@ -1994,12 +1994,12 @@ done_generating:
 #ifdef DEBUG_DISAS
     if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM)
         && qemu_log_in_addr_range(pc_start)) {
-        qemu_log_lock();
+        FILE *logfile = qemu_log_lock();
         qemu_log("----------------\n");
         qemu_log("IN: %s\n", lookup_symbol(pc_start));
         log_target_disas(cs, pc_start, dc->pc - pc_start);
         qemu_log("\n");
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
     }
 #endif
     tb->size = dc->pc - pc_start;
diff --git a/tcg/tcg.c b/tcg/tcg.c
index 5475d49ed1..0511266d85 100644
--- a/tcg/tcg.c
+++ b/tcg/tcg.c
@@ -1085,7 +1085,7 @@ void tcg_prologue_init(TCGContext *s)
 
 #ifdef DEBUG_DISAS
     if (qemu_loglevel_mask(CPU_LOG_TB_OUT_ASM)) {
-        qemu_log_lock();
+        FILE *logfile = qemu_log_lock();
         qemu_log("PROLOGUE: [size=%zu]\n", prologue_size);
         if (s->data_gen_ptr) {
             size_t code_size = s->data_gen_ptr - buf0;
@@ -1110,7 +1110,7 @@ void tcg_prologue_init(TCGContext *s)
         }
         qemu_log("\n");
         qemu_log_flush();
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
     }
 #endif
 
@@ -4041,11 +4041,11 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
 #ifdef DEBUG_DISAS
     if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP)
                  && qemu_log_in_addr_range(tb->pc))) {
-        qemu_log_lock();
+        FILE *logfile = qemu_log_lock();
         qemu_log("OP:\n");
         tcg_dump_ops(s, false);
         qemu_log("\n");
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
     }
 #endif
 
@@ -4086,11 +4086,11 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
 #ifdef DEBUG_DISAS
         if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP_IND)
                      && qemu_log_in_addr_range(tb->pc))) {
-            qemu_log_lock();
+            FILE *logfile = qemu_log_lock();
             qemu_log("OP before indirect lowering:\n");
             tcg_dump_ops(s, false);
             qemu_log("\n");
-            qemu_log_unlock();
+            qemu_log_unlock(logfile);
         }
 #endif
         /* Replace indirect temps with direct temps.  */
@@ -4107,11 +4107,11 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
 #ifdef DEBUG_DISAS
     if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP_OPT)
                  && qemu_log_in_addr_range(tb->pc))) {
-        qemu_log_lock();
+        FILE *logfile = qemu_log_lock();
         qemu_log("OP after optimization and liveness analysis:\n");
         tcg_dump_ops(s, true);
         qemu_log("\n");
-        qemu_log_unlock();
+        qemu_log_unlock(logfile);
     }
 #endif
 
-- 
2.17.1

[PATCH v2 5/6] Add use of RCU for qemu_logfile.

[Robert Foley]

This now allows changing the logfile while logging is active,
and also solves the issue of a seg fault while changing the logfile.

Any read access to the qemu_logfile handle will use
the rcu_read_lock()/unlock() around the use of the handle.
To fetch the handle we will use atomic_rcu_read().
We also in many cases do a check for validity of the
logfile handle before using it to deal with the case where the
file is closed and set to NULL.

The cases where we write to the qemu_logfile will use atomic_rcu_set().
Writers will also use call_rcu() with a newly added qemu_logfile_free
function for freeing/closing when readers have finished.

Signed-off-by: Robert Foley <robert.foley@linaro.org>
---
v2
    - No specific changes, just merging in cleanup changes in qemu_set_log().
---
v1
    - Changes for review comments.
    - Minor changes to definition of QemuLogFile.
    - Changed qemu_log_separate() to fix unbalanced and 
      remove qemu_log_enabled() check.
    - changed qemu_log_lock() to include else.
    - make qemu_logfile_free static.
    - use g_assert(logfile) in qemu_logfile_free.
    - Relocated unlock out of if/else in qemu_log_close(), and
      in qemu_set_log().
---
 include/qemu/log.h | 42 +++++++++++++++++++++++----
 util/log.c         | 72 ++++++++++++++++++++++++++++++++--------------
 include/exec/log.h | 33 ++++++++++++++++++---
 tcg/tcg.c          | 12 ++++++--
 4 files changed, 126 insertions(+), 33 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index a7c5b01571..528e1f9dd7 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -3,9 +3,16 @@
 
 /* A small part of this API is split into its own header */
 #include "qemu/log-for-trace.h"
+#include "qemu/rcu.h"
+
+typedef struct QemuLogFile {
+    struct rcu_head rcu;
+    FILE *fd;
+} QemuLogFile;
 
 /* Private global variable, don't use */
-extern FILE *qemu_logfile;
+extern QemuLogFile *qemu_logfile;
+
 
 /* 
  * The new API:
@@ -25,7 +32,16 @@ static inline bool qemu_log_enabled(void)
  */
 static inline bool qemu_log_separate(void)
 {
-    return qemu_logfile != NULL && qemu_logfile != stderr;
+    QemuLogFile *logfile;
+    bool res = false;
+
+    rcu_read_lock();
+    logfile = atomic_rcu_read(&qemu_logfile);
+    if (logfile && logfile->fd != stderr) {
+        res = true;
+    }
+    rcu_read_unlock();
+    return res;
 }
 
 #define CPU_LOG_TB_OUT_ASM (1 << 0)
@@ -55,14 +71,23 @@ static inline bool qemu_log_separate(void)
 
 static inline FILE *qemu_log_lock(void)
 {
-    qemu_flockfile(qemu_logfile);
-    return logfile->fd;
+    QemuLogFile *logfile;
+    rcu_read_lock();
+    logfile = atomic_rcu_read(&qemu_logfile);
+    if (logfile) {
+        qemu_flockfile(logfile->fd);
+        return logfile->fd;
+    } else {
+        rcu_read_unlock();
+        return NULL;
+    }
 }
 
 static inline void qemu_log_unlock(FILE *fd)
 {
     if (fd) {
         qemu_funlockfile(fd);
+        rcu_read_unlock();
     }
 }
 
@@ -73,9 +98,14 @@ static inline void qemu_log_unlock(FILE *fd)
 static inline void GCC_FMT_ATTR(1, 0)
 qemu_log_vprintf(const char *fmt, va_list va)
 {
-    if (qemu_logfile) {
-        vfprintf(qemu_logfile, fmt, va);
+    QemuLogFile *logfile;
+
+    rcu_read_lock();
+    logfile = atomic_rcu_read(&qemu_logfile);
+    if (logfile) {
+        vfprintf(logfile->fd, fmt, va);
     }
+    rcu_read_unlock();
 }
 
 /* log only if a bit is set on the current loglevel mask:
diff --git a/util/log.c b/util/log.c
index 91ebb5c924..9f9b6b74b7 100644
--- a/util/log.c
+++ b/util/log.c
@@ -28,7 +28,7 @@
 
 static char *logfilename;
 static QemuMutex qemu_logfile_mutex;
-FILE *qemu_logfile;
+QemuLogFile *qemu_logfile;
 int qemu_loglevel;
 static int log_append = 0;
 static GArray *debug_regions;
@@ -37,10 +37,14 @@ static GArray *debug_regions;
 int qemu_log(const char *fmt, ...)
 {
     int ret = 0;
-    if (qemu_logfile) {
+    QemuLogFile *logfile;
+
+    rcu_read_lock();
+    logfile = atomic_rcu_read(&qemu_logfile);
+    if (logfile) {
         va_list ap;
         va_start(ap, fmt);
-        ret = vfprintf(qemu_logfile, fmt, ap);
+        ret = vfprintf(logfile->fd, fmt, ap);
         va_end(ap);
 
         /* Don't pass back error results.  */
@@ -48,6 +52,7 @@ int qemu_log(const char *fmt, ...)
             ret = 0;
         }
     }
+    rcu_read_unlock();
     return ret;
 }
 
@@ -56,12 +61,24 @@ static void __attribute__((__constructor__)) qemu_logfile_init(void)
     qemu_mutex_init(&qemu_logfile_mutex);
 }
 
+static void qemu_logfile_free(QemuLogFile *logfile)
+{
+    g_assert(logfile);
+
+    if (logfile->fd != stderr) {
+        fclose(logfile->fd);
+    }
+    g_free(logfile);
+}
+
 static bool log_uses_own_buffers;
 
 /* enable or disable low levels log */
 void qemu_set_log(int log_flags)
 {
     bool need_to_open_file = false;
+    QemuLogFile *logfile;
+
     qemu_loglevel = log_flags;
 #ifdef CONFIG_TRACE_LOG
     qemu_loglevel |= LOG_TRACE;
@@ -80,43 +97,47 @@ void qemu_set_log(int log_flags)
     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();
+        logfile = qemu_logfile;
+        atomic_rcu_set(&qemu_logfile, NULL);
+        call_rcu(logfile, qemu_logfile_free, rcu);
     } else if (!qemu_logfile && need_to_open_file) {
+        logfile = g_new0(QemuLogFile, 1);
         if (logfilename) {
-            qemu_logfile = fopen(logfilename, log_append ? "a" : "w");
-            if (!qemu_logfile) {
+            logfile->fd = fopen(logfilename, log_append ? "a" : "w");
+            if (!logfile->fd) {
+                g_free(logfile);
                 perror(logfilename);
                 _exit(1);
             }
             /* In case we are a daemon redirect stderr to logfile */
             if (is_daemonized()) {
-                dup2(fileno(qemu_logfile), STDERR_FILENO);
-                fclose(qemu_logfile);
+                dup2(fileno(logfile->fd), STDERR_FILENO);
+                fclose(logfile->fd);
                 /* This will skip closing logfile in qemu_log_close() */
-                qemu_logfile = stderr;
+                logfile->fd = stderr;
             }
         } else {
             /* Default to stderr if no log file specified */
             assert(!is_daemonized());
-            qemu_logfile = stderr;
+            logfile->fd = stderr;
         }
         /* must avoid mmap() usage of glibc by setting a buffer "by hand" */
         if (log_uses_own_buffers) {
             static char logfile_buf[4096];
 
-            setvbuf(qemu_logfile, logfile_buf, _IOLBF, sizeof(logfile_buf));
+            setvbuf(logfile->fd, logfile_buf, _IOLBF, sizeof(logfile_buf));
         } else {
 #if defined(_WIN32)
             /* Win32 doesn't support line-buffering, so use unbuffered output. */
-            setvbuf(qemu_logfile, NULL, _IONBF, 0);
+            setvbuf(logfile->fd, NULL, _IONBF, 0);
 #else
-            setvbuf(qemu_logfile, NULL, _IOLBF, 0);
+            setvbuf(logfile->fd, NULL, _IOLBF, 0);
 #endif
             log_append = 1;
         }
-        qemu_mutex_unlock(&qemu_logfile_mutex);
+        atomic_rcu_set(&qemu_logfile, logfile);
     }
+    qemu_mutex_unlock(&qemu_logfile_mutex);
 }
 
 void qemu_log_needs_buffers(void)
@@ -245,19 +266,28 @@ out:
 /* fflush() the log file */
 void qemu_log_flush(void)
 {
-    fflush(qemu_logfile);
+    QemuLogFile *logfile;
+
+    rcu_read_lock();
+    logfile = atomic_rcu_read(&qemu_logfile);
+    if (logfile) {
+        fflush(logfile->fd);
+    }
+    rcu_read_unlock();
 }
 
 /* Close the log file */
 void qemu_log_close(void)
 {
+    QemuLogFile *logfile;
+
     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;
+    logfile = qemu_logfile;
+
+    if (logfile) {
+        atomic_rcu_set(&qemu_logfile, NULL);
+        call_rcu(logfile, qemu_logfile_free, rcu);
     }
     qemu_mutex_unlock(&qemu_logfile_mutex);
 }
 diff --git a/include/exec/log.h b/include/exec/log.h
index e2cfd436e6..9bd1e4aa20 100644
--- a/include/exec/log.h
+++ b/include/exec/log.h
@@ -15,8 +15,15 @@
  */
 static inline void log_cpu_state(CPUState *cpu, int flags)
 {
+    QemuLogFile *logfile;
+
     if (qemu_log_enabled()) {
-        cpu_dump_state(cpu, qemu_logfile, flags);
+        rcu_read_lock();
+        logfile = atomic_rcu_read(&qemu_logfile);
+        if (logfile) {
+            cpu_dump_state(cpu, logfile->fd, flags);
+        }
+        rcu_read_unlock();
     }
 }
 
@@ -40,19 +47,37 @@ static inline void log_cpu_state_mask(int mask, CPUState *cpu, int flags)
 static inline void log_target_disas(CPUState *cpu, target_ulong start,
                                     target_ulong len)
 {
-    target_disas(qemu_logfile, cpu, start, len);
+    QemuLogFile *logfile;
+    rcu_read_lock();
+    logfile = atomic_rcu_read(&qemu_logfile);
+    if (logfile) {
+        target_disas(logfile->fd, cpu, start, len);
+    }
+    rcu_read_unlock();
 }
 
 static inline void log_disas(void *code, unsigned long size)
 {
-    disas(qemu_logfile, code, size);
+    QemuLogFile *logfile;
+    rcu_read_lock();
+    logfile = atomic_rcu_read(&qemu_logfile);
+    if (logfile) {
+        disas(logfile->fd, code, size);
+    }
+    rcu_read_unlock();
 }
 
 #if defined(CONFIG_USER_ONLY)
 /* page_dump() output to the log file: */
 static inline void log_page_dump(void)
 {
-    page_dump(qemu_logfile);
+    QemuLogFile *logfile;
+    rcu_read_lock();
+    logfile = atomic_rcu_read(&qemu_logfile);
+    if (logfile) {
+        page_dump(logfile->fd);
+    }
+    rcu_read_unlock();
 }
 #endif
 #endif
diff --git a/tcg/tcg.c b/tcg/tcg.c
index 0511266d85..4f616ba38b 100644
--- a/tcg/tcg.c
+++ b/tcg/tcg.c
@@ -2114,9 +2114,17 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
         }
 
         if (have_prefs || op->life) {
-            for (; col < 40; ++col) {
-                putc(' ', qemu_logfile);
+
+            QemuLogFile *logfile;
+
+            rcu_read_lock();
+            logfile = atomic_rcu_read(&qemu_logfile);
+            if (logfile) {
+                for (; col < 40; ++col) {
+                    putc(' ', logfile->fd);
+                }
             }
+            rcu_read_unlock();
         }
 
         if (op->life) {
-- 
2.17.1

Re: [PATCH v2 5/6] Add use of RCU for qemu_logfile.

[Alex Bennée]

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

> This now allows changing the logfile while logging is active,
> and also solves the issue of a seg fault while changing the logfile.
>
> Any read access to the qemu_logfile handle will use
> the rcu_read_lock()/unlock() around the use of the handle.
> To fetch the handle we will use atomic_rcu_read().
> We also in many cases do a check for validity of the
> logfile handle before using it to deal with the case where the
> file is closed and set to NULL.
>
> The cases where we write to the qemu_logfile will use atomic_rcu_set().
> Writers will also use call_rcu() with a newly added qemu_logfile_free
> function for freeing/closing when readers have finished.
>
> Signed-off-by: Robert Foley <robert.foley@linaro.org>
> ---
> v2
>     - No specific changes, just merging in cleanup changes in qemu_set_log().
> ---
> v1
>     - Changes for review comments.
>     - Minor changes to definition of QemuLogFile.
>     - Changed qemu_log_separate() to fix unbalanced and
>       remove qemu_log_enabled() check.
>     - changed qemu_log_lock() to include else.
>     - make qemu_logfile_free static.
>     - use g_assert(logfile) in qemu_logfile_free.
>     - Relocated unlock out of if/else in qemu_log_close(), and
>       in qemu_set_log().
> ---
>  include/qemu/log.h | 42 +++++++++++++++++++++++----
>  util/log.c         | 72 ++++++++++++++++++++++++++++++++--------------
>  include/exec/log.h | 33 ++++++++++++++++++---
>  tcg/tcg.c          | 12 ++++++--
>  4 files changed, 126 insertions(+), 33 deletions(-)
>
> diff --git a/include/qemu/log.h b/include/qemu/log.h
> index a7c5b01571..528e1f9dd7 100644
> --- a/include/qemu/log.h
> +++ b/include/qemu/log.h
> @@ -3,9 +3,16 @@
>
>  /* A small part of this API is split into its own header */
>  #include "qemu/log-for-trace.h"
> +#include "qemu/rcu.h"
> +
> +typedef struct QemuLogFile {
> +    struct rcu_head rcu;
> +    FILE *fd;
> +} QemuLogFile;
>
>  /* Private global variable, don't use */
> -extern FILE *qemu_logfile;
> +extern QemuLogFile *qemu_logfile;
> +
>
>  /*
>   * The new API:
> @@ -25,7 +32,16 @@ static inline bool qemu_log_enabled(void)
>   */
>  static inline bool qemu_log_separate(void)
>  {
> -    return qemu_logfile != NULL && qemu_logfile != stderr;
> +    QemuLogFile *logfile;
> +    bool res = false;
> +
> +    rcu_read_lock();
> +    logfile = atomic_rcu_read(&qemu_logfile);
> +    if (logfile && logfile->fd != stderr) {
> +        res = true;
> +    }
> +    rcu_read_unlock();
> +    return res;
>  }
>
>  #define CPU_LOG_TB_OUT_ASM (1 << 0)
> @@ -55,14 +71,23 @@ static inline bool qemu_log_separate(void)
>
>  static inline FILE *qemu_log_lock(void)
>  {
> -    qemu_flockfile(qemu_logfile);
> -    return logfile->fd;
> +    QemuLogFile *logfile;
> +    rcu_read_lock();
> +    logfile = atomic_rcu_read(&qemu_logfile);
> +    if (logfile) {
> +        qemu_flockfile(logfile->fd);
> +        return logfile->fd;
> +    } else {
> +        rcu_read_unlock();

As qemu_log_lock() and unlock should be paired we can drop the unlock
here and do an unconditional unlock bellow even if a null fd is passed.

Otherwise:

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

> +        return NULL;
> +    }
>  }
>
>  static inline void qemu_log_unlock(FILE *fd)
>  {
>      if (fd) {
>          qemu_funlockfile(fd);
> +        rcu_read_unlock();
>      }
>  }
>
> @@ -73,9 +98,14 @@ static inline void qemu_log_unlock(FILE *fd)
>  static inline void GCC_FMT_ATTR(1, 0)
>  qemu_log_vprintf(const char *fmt, va_list va)
>  {
> -    if (qemu_logfile) {
> -        vfprintf(qemu_logfile, fmt, va);
> +    QemuLogFile *logfile;
> +
> +    rcu_read_lock();
> +    logfile = atomic_rcu_read(&qemu_logfile);
> +    if (logfile) {
> +        vfprintf(logfile->fd, fmt, va);
>      }
> +    rcu_read_unlock();
>  }
>
>  /* log only if a bit is set on the current loglevel mask:
> diff --git a/util/log.c b/util/log.c
> index 91ebb5c924..9f9b6b74b7 100644
> --- a/util/log.c
> +++ b/util/log.c
> @@ -28,7 +28,7 @@
>
>  static char *logfilename;
>  static QemuMutex qemu_logfile_mutex;
> -FILE *qemu_logfile;
> +QemuLogFile *qemu_logfile;
>  int qemu_loglevel;
>  static int log_append = 0;
>  static GArray *debug_regions;
> @@ -37,10 +37,14 @@ static GArray *debug_regions;
>  int qemu_log(const char *fmt, ...)
>  {
>      int ret = 0;
> -    if (qemu_logfile) {
> +    QemuLogFile *logfile;
> +
> +    rcu_read_lock();
> +    logfile = atomic_rcu_read(&qemu_logfile);
> +    if (logfile) {
>          va_list ap;
>          va_start(ap, fmt);
> -        ret = vfprintf(qemu_logfile, fmt, ap);
> +        ret = vfprintf(logfile->fd, fmt, ap);
>          va_end(ap);
>
>          /* Don't pass back error results.  */
> @@ -48,6 +52,7 @@ int qemu_log(const char *fmt, ...)
>              ret = 0;
>          }
>      }
> +    rcu_read_unlock();
>      return ret;
>  }
>
> @@ -56,12 +61,24 @@ static void __attribute__((__constructor__)) qemu_logfile_init(void)
>      qemu_mutex_init(&qemu_logfile_mutex);
>  }
>
> +static void qemu_logfile_free(QemuLogFile *logfile)
> +{
> +    g_assert(logfile);
> +
> +    if (logfile->fd != stderr) {
> +        fclose(logfile->fd);
> +    }
> +    g_free(logfile);
> +}
> +
>  static bool log_uses_own_buffers;
>
>  /* enable or disable low levels log */
>  void qemu_set_log(int log_flags)
>  {
>      bool need_to_open_file = false;
> +    QemuLogFile *logfile;
> +
>      qemu_loglevel = log_flags;
>  #ifdef CONFIG_TRACE_LOG
>      qemu_loglevel |= LOG_TRACE;
> @@ -80,43 +97,47 @@ void qemu_set_log(int log_flags)
>      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();
> +        logfile = qemu_logfile;
> +        atomic_rcu_set(&qemu_logfile, NULL);
> +        call_rcu(logfile, qemu_logfile_free, rcu);
>      } else if (!qemu_logfile && need_to_open_file) {
> +        logfile = g_new0(QemuLogFile, 1);
>          if (logfilename) {
> -            qemu_logfile = fopen(logfilename, log_append ? "a" : "w");
> -            if (!qemu_logfile) {
> +            logfile->fd = fopen(logfilename, log_append ? "a" : "w");
> +            if (!logfile->fd) {
> +                g_free(logfile);
>                  perror(logfilename);
>                  _exit(1);
>              }
>              /* In case we are a daemon redirect stderr to logfile */
>              if (is_daemonized()) {
> -                dup2(fileno(qemu_logfile), STDERR_FILENO);
> -                fclose(qemu_logfile);
> +                dup2(fileno(logfile->fd), STDERR_FILENO);
> +                fclose(logfile->fd);
>                  /* This will skip closing logfile in qemu_log_close() */
> -                qemu_logfile = stderr;
> +                logfile->fd = stderr;
>              }
>          } else {
>              /* Default to stderr if no log file specified */
>              assert(!is_daemonized());
> -            qemu_logfile = stderr;
> +            logfile->fd = stderr;
>          }
>          /* must avoid mmap() usage of glibc by setting a buffer "by hand" */
>          if (log_uses_own_buffers) {
>              static char logfile_buf[4096];
>
> -            setvbuf(qemu_logfile, logfile_buf, _IOLBF, sizeof(logfile_buf));
> +            setvbuf(logfile->fd, logfile_buf, _IOLBF, sizeof(logfile_buf));
>          } else {
>  #if defined(_WIN32)
>              /* Win32 doesn't support line-buffering, so use unbuffered output. */
> -            setvbuf(qemu_logfile, NULL, _IONBF, 0);
> +            setvbuf(logfile->fd, NULL, _IONBF, 0);
>  #else
> -            setvbuf(qemu_logfile, NULL, _IOLBF, 0);
> +            setvbuf(logfile->fd, NULL, _IOLBF, 0);
>  #endif
>              log_append = 1;
>          }
> -        qemu_mutex_unlock(&qemu_logfile_mutex);
> +        atomic_rcu_set(&qemu_logfile, logfile);
>      }
> +    qemu_mutex_unlock(&qemu_logfile_mutex);
>  }
>
>  void qemu_log_needs_buffers(void)
> @@ -245,19 +266,28 @@ out:
>  /* fflush() the log file */
>  void qemu_log_flush(void)
>  {
> -    fflush(qemu_logfile);
> +    QemuLogFile *logfile;
> +
> +    rcu_read_lock();
> +    logfile = atomic_rcu_read(&qemu_logfile);
> +    if (logfile) {
> +        fflush(logfile->fd);
> +    }
> +    rcu_read_unlock();
>  }
>
>  /* Close the log file */
>  void qemu_log_close(void)
>  {
> +    QemuLogFile *logfile;
> +
>      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;
> +    logfile = qemu_logfile;
> +
> +    if (logfile) {
> +        atomic_rcu_set(&qemu_logfile, NULL);
> +        call_rcu(logfile, qemu_logfile_free, rcu);
>      }
>      qemu_mutex_unlock(&qemu_logfile_mutex);
>  }
>  diff --git a/include/exec/log.h b/include/exec/log.h
> index e2cfd436e6..9bd1e4aa20 100644
> --- a/include/exec/log.h
> +++ b/include/exec/log.h
> @@ -15,8 +15,15 @@
>   */
>  static inline void log_cpu_state(CPUState *cpu, int flags)
>  {
> +    QemuLogFile *logfile;
> +
>      if (qemu_log_enabled()) {
> -        cpu_dump_state(cpu, qemu_logfile, flags);
> +        rcu_read_lock();
> +        logfile = atomic_rcu_read(&qemu_logfile);
> +        if (logfile) {
> +            cpu_dump_state(cpu, logfile->fd, flags);
> +        }
> +        rcu_read_unlock();
>      }
>  }
>
> @@ -40,19 +47,37 @@ static inline void log_cpu_state_mask(int mask, CPUState *cpu, int flags)
>  static inline void log_target_disas(CPUState *cpu, target_ulong start,
>                                      target_ulong len)
>  {
> -    target_disas(qemu_logfile, cpu, start, len);
> +    QemuLogFile *logfile;
> +    rcu_read_lock();
> +    logfile = atomic_rcu_read(&qemu_logfile);
> +    if (logfile) {
> +        target_disas(logfile->fd, cpu, start, len);
> +    }
> +    rcu_read_unlock();
>  }
>
>  static inline void log_disas(void *code, unsigned long size)
>  {
> -    disas(qemu_logfile, code, size);
> +    QemuLogFile *logfile;
> +    rcu_read_lock();
> +    logfile = atomic_rcu_read(&qemu_logfile);
> +    if (logfile) {
> +        disas(logfile->fd, code, size);
> +    }
> +    rcu_read_unlock();
>  }
>
>  #if defined(CONFIG_USER_ONLY)
>  /* page_dump() output to the log file: */
>  static inline void log_page_dump(void)
>  {
> -    page_dump(qemu_logfile);
> +    QemuLogFile *logfile;
> +    rcu_read_lock();
> +    logfile = atomic_rcu_read(&qemu_logfile);
> +    if (logfile) {
> +        page_dump(logfile->fd);
> +    }
> +    rcu_read_unlock();
>  }
>  #endif
>  #endif
> diff --git a/tcg/tcg.c b/tcg/tcg.c
> index 0511266d85..4f616ba38b 100644
> --- a/tcg/tcg.c
> +++ b/tcg/tcg.c
> @@ -2114,9 +2114,17 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
>          }
>
>          if (have_prefs || op->life) {
> -            for (; col < 40; ++col) {
> -                putc(' ', qemu_logfile);
> +
> +            QemuLogFile *logfile;
> +
> +            rcu_read_lock();
> +            logfile = atomic_rcu_read(&qemu_logfile);
> +            if (logfile) {
> +                for (; col < 40; ++col) {
> +                    putc(' ', logfile->fd);
> +                }
>              }
> +            rcu_read_unlock();
>          }
>
>          if (op->life) {


--
Alex Bennée

Re: [PATCH v2 5/6] Add use of RCU for qemu_logfile.

[Robert Foley]

On Mon, 18 Nov 2019 at 07:22, Alex Bennée <alex.bennee@linaro.org> wrote:
>
>
> > +    if (logfile) {
> > +        qemu_flockfile(logfile->fd);
> > +        return logfile->fd;
> > +    } else {
> > +        rcu_read_unlock();
>
> As qemu_log_lock() and unlock should be paired we can drop the unlock
> here and do an unconditional unlock bellow even if a null fd is passed.
>
> Otherwise:
>
> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
>
Sounds reasonable.  It sounds like we should change it to be something
like this.

static inline FILE *qemu_log_lock(void)
{
    QemuLogFile *logfile;
    rcu_read_lock();
    logfile = atomic_rcu_read(&qemu_logfile);
    if (logfile) {
        qemu_flockfile(logfile->fd);
        return logfile->fd;
    }
    rcu_read_unlock();
    return NULL;
}
I will make the changes.

Thanks,
-Rob
On Mon, 18 Nov 2019 at 07:22, Alex Bennée <alex.bennee@linaro.org> wrote:
>
>
> Robert Foley <robert.foley@linaro.org> writes:
>
> > This now allows changing the logfile while logging is active,
> > and also solves the issue of a seg fault while changing the logfile.
> >
> > Any read access to the qemu_logfile handle will use
> > the rcu_read_lock()/unlock() around the use of the handle.
> > To fetch the handle we will use atomic_rcu_read().
> > We also in many cases do a check for validity of the
> > logfile handle before using it to deal with the case where the
> > file is closed and set to NULL.
> >
> > The cases where we write to the qemu_logfile will use atomic_rcu_set().
> > Writers will also use call_rcu() with a newly added qemu_logfile_free
> > function for freeing/closing when readers have finished.
> >
> > Signed-off-by: Robert Foley <robert.foley@linaro.org>
> > ---
> > v2
> >     - No specific changes, just merging in cleanup changes in qemu_set_log().
> > ---
> > v1
> >     - Changes for review comments.
> >     - Minor changes to definition of QemuLogFile.
> >     - Changed qemu_log_separate() to fix unbalanced and
> >       remove qemu_log_enabled() check.
> >     - changed qemu_log_lock() to include else.
> >     - make qemu_logfile_free static.
> >     - use g_assert(logfile) in qemu_logfile_free.
> >     - Relocated unlock out of if/else in qemu_log_close(), and
> >       in qemu_set_log().
> > ---
> >  include/qemu/log.h | 42 +++++++++++++++++++++++----
> >  util/log.c         | 72 ++++++++++++++++++++++++++++++++--------------
> >  include/exec/log.h | 33 ++++++++++++++++++---
> >  tcg/tcg.c          | 12 ++++++--
> >  4 files changed, 126 insertions(+), 33 deletions(-)
> >
> > diff --git a/include/qemu/log.h b/include/qemu/log.h
> > index a7c5b01571..528e1f9dd7 100644
> > --- a/include/qemu/log.h
> > +++ b/include/qemu/log.h
> > @@ -3,9 +3,16 @@
> >
> >  /* A small part of this API is split into its own header */
> >  #include "qemu/log-for-trace.h"
> > +#include "qemu/rcu.h"
> > +
> > +typedef struct QemuLogFile {
> > +    struct rcu_head rcu;
> > +    FILE *fd;
> > +} QemuLogFile;
> >
> >  /* Private global variable, don't use */
> > -extern FILE *qemu_logfile;
> > +extern QemuLogFile *qemu_logfile;
> > +
> >
> >  /*
> >   * The new API:
> > @@ -25,7 +32,16 @@ static inline bool qemu_log_enabled(void)
> >   */
> >  static inline bool qemu_log_separate(void)
> >  {
> > -    return qemu_logfile != NULL && qemu_logfile != stderr;
> > +    QemuLogFile *logfile;
> > +    bool res = false;
> > +
> > +    rcu_read_lock();
> > +    logfile = atomic_rcu_read(&qemu_logfile);
> > +    if (logfile && logfile->fd != stderr) {
> > +        res = true;
> > +    }
> > +    rcu_read_unlock();
> > +    return res;
> >  }
> >
> >  #define CPU_LOG_TB_OUT_ASM (1 << 0)
> > @@ -55,14 +71,23 @@ static inline bool qemu_log_separate(void)
> >
> >  static inline FILE *qemu_log_lock(void)
> >  {
> > -    qemu_flockfile(qemu_logfile);
> > -    return logfile->fd;
> > +    QemuLogFile *logfile;
> > +    rcu_read_lock();
> > +    logfile = atomic_rcu_read(&qemu_logfile);
> > +    if (logfile) {
> > +        qemu_flockfile(logfile->fd);
> > +        return logfile->fd;
> > +    } else {
> > +        rcu_read_unlock();
>
> As qemu_log_lock() and unlock should be paired we can drop the unlock
> here and do an unconditional unlock bellow even if a null fd is passed.
>
> Otherwise:
>
> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
>
> > +        return NULL;
> > +    }
> >  }
> >
> >  static inline void qemu_log_unlock(FILE *fd)
> >  {
> >      if (fd) {
> >          qemu_funlockfile(fd);
> > +        rcu_read_unlock();
> >      }
> >  }
> >
> > @@ -73,9 +98,14 @@ static inline void qemu_log_unlock(FILE *fd)
> >  static inline void GCC_FMT_ATTR(1, 0)
> >  qemu_log_vprintf(const char *fmt, va_list va)
> >  {
> > -    if (qemu_logfile) {
> > -        vfprintf(qemu_logfile, fmt, va);
> > +    QemuLogFile *logfile;
> > +
> > +    rcu_read_lock();
> > +    logfile = atomic_rcu_read(&qemu_logfile);
> > +    if (logfile) {
> > +        vfprintf(logfile->fd, fmt, va);
> >      }
> > +    rcu_read_unlock();
> >  }
> >
> >  /* log only if a bit is set on the current loglevel mask:
> > diff --git a/util/log.c b/util/log.c
> > index 91ebb5c924..9f9b6b74b7 100644
> > --- a/util/log.c
> > +++ b/util/log.c
> > @@ -28,7 +28,7 @@
> >
> >  static char *logfilename;
> >  static QemuMutex qemu_logfile_mutex;
> > -FILE *qemu_logfile;
> > +QemuLogFile *qemu_logfile;
> >  int qemu_loglevel;
> >  static int log_append = 0;
> >  static GArray *debug_regions;
> > @@ -37,10 +37,14 @@ static GArray *debug_regions;
> >  int qemu_log(const char *fmt, ...)
> >  {
> >      int ret = 0;
> > -    if (qemu_logfile) {
> > +    QemuLogFile *logfile;
> > +
> > +    rcu_read_lock();
> > +    logfile = atomic_rcu_read(&qemu_logfile);
> > +    if (logfile) {
> >          va_list ap;
> >          va_start(ap, fmt);
> > -        ret = vfprintf(qemu_logfile, fmt, ap);
> > +        ret = vfprintf(logfile->fd, fmt, ap);
> >          va_end(ap);
> >
> >          /* Don't pass back error results.  */
> > @@ -48,6 +52,7 @@ int qemu_log(const char *fmt, ...)
> >              ret = 0;
> >          }
> >      }
> > +    rcu_read_unlock();
> >      return ret;
> >  }
> >
> > @@ -56,12 +61,24 @@ static void __attribute__((__constructor__)) qemu_logfile_init(void)
> >      qemu_mutex_init(&qemu_logfile_mutex);
> >  }
> >
> > +static void qemu_logfile_free(QemuLogFile *logfile)
> > +{
> > +    g_assert(logfile);
> > +
> > +    if (logfile->fd != stderr) {
> > +        fclose(logfile->fd);
> > +    }
> > +    g_free(logfile);
> > +}
> > +
> >  static bool log_uses_own_buffers;
> >
> >  /* enable or disable low levels log */
> >  void qemu_set_log(int log_flags)
> >  {
> >      bool need_to_open_file = false;
> > +    QemuLogFile *logfile;
> > +
> >      qemu_loglevel = log_flags;
> >  #ifdef CONFIG_TRACE_LOG
> >      qemu_loglevel |= LOG_TRACE;
> > @@ -80,43 +97,47 @@ void qemu_set_log(int log_flags)
> >      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();
> > +        logfile = qemu_logfile;
> > +        atomic_rcu_set(&qemu_logfile, NULL);
> > +        call_rcu(logfile, qemu_logfile_free, rcu);
> >      } else if (!qemu_logfile && need_to_open_file) {
> > +        logfile = g_new0(QemuLogFile, 1);
> >          if (logfilename) {
> > -            qemu_logfile = fopen(logfilename, log_append ? "a" : "w");
> > -            if (!qemu_logfile) {
> > +            logfile->fd = fopen(logfilename, log_append ? "a" : "w");
> > +            if (!logfile->fd) {
> > +                g_free(logfile);
> >                  perror(logfilename);
> >                  _exit(1);
> >              }
> >              /* In case we are a daemon redirect stderr to logfile */
> >              if (is_daemonized()) {
> > -                dup2(fileno(qemu_logfile), STDERR_FILENO);
> > -                fclose(qemu_logfile);
> > +                dup2(fileno(logfile->fd), STDERR_FILENO);
> > +                fclose(logfile->fd);
> >                  /* This will skip closing logfile in qemu_log_close() */
> > -                qemu_logfile = stderr;
> > +                logfile->fd = stderr;
> >              }
> >          } else {
> >              /* Default to stderr if no log file specified */
> >              assert(!is_daemonized());
> > -            qemu_logfile = stderr;
> > +            logfile->fd = stderr;
> >          }
> >          /* must avoid mmap() usage of glibc by setting a buffer "by hand" */
> >          if (log_uses_own_buffers) {
> >              static char logfile_buf[4096];
> >
> > -            setvbuf(qemu_logfile, logfile_buf, _IOLBF, sizeof(logfile_buf));
> > +            setvbuf(logfile->fd, logfile_buf, _IOLBF, sizeof(logfile_buf));
> >          } else {
> >  #if defined(_WIN32)
> >              /* Win32 doesn't support line-buffering, so use unbuffered output. */
> > -            setvbuf(qemu_logfile, NULL, _IONBF, 0);
> > +            setvbuf(logfile->fd, NULL, _IONBF, 0);
> >  #else
> > -            setvbuf(qemu_logfile, NULL, _IOLBF, 0);
> > +            setvbuf(logfile->fd, NULL, _IOLBF, 0);
> >  #endif
> >              log_append = 1;
> >          }
> > -        qemu_mutex_unlock(&qemu_logfile_mutex);
> > +        atomic_rcu_set(&qemu_logfile, logfile);
> >      }
> > +    qemu_mutex_unlock(&qemu_logfile_mutex);
> >  }
> >
> >  void qemu_log_needs_buffers(void)
> > @@ -245,19 +266,28 @@ out:
> >  /* fflush() the log file */
> >  void qemu_log_flush(void)
> >  {
> > -    fflush(qemu_logfile);
> > +    QemuLogFile *logfile;
> > +
> > +    rcu_read_lock();
> > +    logfile = atomic_rcu_read(&qemu_logfile);
> > +    if (logfile) {
> > +        fflush(logfile->fd);
> > +    }
> > +    rcu_read_unlock();
> >  }
> >
> >  /* Close the log file */
> >  void qemu_log_close(void)
> >  {
> > +    QemuLogFile *logfile;
> > +
> >      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;
> > +    logfile = qemu_logfile;
> > +
> > +    if (logfile) {
> > +        atomic_rcu_set(&qemu_logfile, NULL);
> > +        call_rcu(logfile, qemu_logfile_free, rcu);
> >      }
> >      qemu_mutex_unlock(&qemu_logfile_mutex);
> >  }
> >  diff --git a/include/exec/log.h b/include/exec/log.h
> > index e2cfd436e6..9bd1e4aa20 100644
> > --- a/include/exec/log.h
> > +++ b/include/exec/log.h
> > @@ -15,8 +15,15 @@
> >   */
> >  static inline void log_cpu_state(CPUState *cpu, int flags)
> >  {
> > +    QemuLogFile *logfile;
> > +
> >      if (qemu_log_enabled()) {
> > -        cpu_dump_state(cpu, qemu_logfile, flags);
> > +        rcu_read_lock();
> > +        logfile = atomic_rcu_read(&qemu_logfile);
> > +        if (logfile) {
> > +            cpu_dump_state(cpu, logfile->fd, flags);
> > +        }
> > +        rcu_read_unlock();
> >      }
> >  }
> >
> > @@ -40,19 +47,37 @@ static inline void log_cpu_state_mask(int mask, CPUState *cpu, int flags)
> >  static inline void log_target_disas(CPUState *cpu, target_ulong start,
> >                                      target_ulong len)
> >  {
> > -    target_disas(qemu_logfile, cpu, start, len);
> > +    QemuLogFile *logfile;
> > +    rcu_read_lock();
> > +    logfile = atomic_rcu_read(&qemu_logfile);
> > +    if (logfile) {
> > +        target_disas(logfile->fd, cpu, start, len);
> > +    }
> > +    rcu_read_unlock();
> >  }
> >
> >  static inline void log_disas(void *code, unsigned long size)
> >  {
> > -    disas(qemu_logfile, code, size);
> > +    QemuLogFile *logfile;
> > +    rcu_read_lock();
> > +    logfile = atomic_rcu_read(&qemu_logfile);
> > +    if (logfile) {
> > +        disas(logfile->fd, code, size);
> > +    }
> > +    rcu_read_unlock();
> >  }
> >
> >  #if defined(CONFIG_USER_ONLY)
> >  /* page_dump() output to the log file: */
> >  static inline void log_page_dump(void)
> >  {
> > -    page_dump(qemu_logfile);
> > +    QemuLogFile *logfile;
> > +    rcu_read_lock();
> > +    logfile = atomic_rcu_read(&qemu_logfile);
> > +    if (logfile) {
> > +        page_dump(logfile->fd);
> > +    }
> > +    rcu_read_unlock();
> >  }
> >  #endif
> >  #endif
> > diff --git a/tcg/tcg.c b/tcg/tcg.c
> > index 0511266d85..4f616ba38b 100644
> > --- a/tcg/tcg.c
> > +++ b/tcg/tcg.c
> > @@ -2114,9 +2114,17 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
> >          }
> >
> >          if (have_prefs || op->life) {
> > -            for (; col < 40; ++col) {
> > -                putc(' ', qemu_logfile);
> > +
> > +            QemuLogFile *logfile;
> > +
> > +            rcu_read_lock();
> > +            logfile = atomic_rcu_read(&qemu_logfile);
> > +            if (logfile) {
> > +                for (; col < 40; ++col) {
> > +                    putc(' ', logfile->fd);
> > +                }
> >              }
> > +            rcu_read_unlock();
> >          }
> >
> >          if (op->life) {
>
>
> --
> Alex Bennée

Re: [PATCH v2 5/6] Add use of RCU for qemu_logfile.

[Alex Bennée]

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

> On Mon, 18 Nov 2019 at 07:22, Alex Bennée <alex.bennee@linaro.org> wrote:
>>
>>
>> > +    if (logfile) {
>> > +        qemu_flockfile(logfile->fd);
>> > +        return logfile->fd;
>> > +    } else {
>> > +        rcu_read_unlock();
>>
>> As qemu_log_lock() and unlock should be paired we can drop the unlock
>> here and do an unconditional unlock bellow even if a null fd is passed.
>>
>> Otherwise:
>>
>> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
>>
> Sounds reasonable.  It sounds like we should change it to be something
> like this.
>
> static inline FILE *qemu_log_lock(void)
> {
>     QemuLogFile *logfile;
>     rcu_read_lock();
>     logfile = atomic_rcu_read(&qemu_logfile);
>     if (logfile) {
>         qemu_flockfile(logfile->fd);
>         return logfile->fd;
>     }
>     rcu_read_unlock();
>     return NULL;
> }
> I will make the changes.

No I mean as you have to call qemu_log_unlock() you can to the unlock
there. You have to hold the lock over the usage of the resource:

  static inline FILE *qemu_log_lock(void)
  {
      QemuLogFile *logfile;
      rcu_read_lock();
      logfile = atomic_rcu_read(&qemu_logfile);
      if (logfile) {
          qemu_flockfile(logfile->fd);
          return logfile->fd;
      } else {
          return NULL;
      }
  }

  static inline void qemu_log_unlock(FILE *fd)
  {
      if (fd) {
          qemu_funlockfile(fd);
      }
      rcu_read_unlock();
  }


>
> Thanks,
> -Rob
> On Mon, 18 Nov 2019 at 07:22, Alex Bennée <alex.bennee@linaro.org> wrote:
>>
>>
>> Robert Foley <robert.foley@linaro.org> writes:
>>
>> > This now allows changing the logfile while logging is active,
>> > and also solves the issue of a seg fault while changing the logfile.
>> >
>> > Any read access to the qemu_logfile handle will use
>> > the rcu_read_lock()/unlock() around the use of the handle.
>> > To fetch the handle we will use atomic_rcu_read().
>> > We also in many cases do a check for validity of the
>> > logfile handle before using it to deal with the case where the
>> > file is closed and set to NULL.
>> >
>> > The cases where we write to the qemu_logfile will use atomic_rcu_set().
>> > Writers will also use call_rcu() with a newly added qemu_logfile_free
>> > function for freeing/closing when readers have finished.
>> >
>> > Signed-off-by: Robert Foley <robert.foley@linaro.org>
>> > ---
>> > v2
>> >     - No specific changes, just merging in cleanup changes in qemu_set_log().
>> > ---
>> > v1
>> >     - Changes for review comments.
>> >     - Minor changes to definition of QemuLogFile.
>> >     - Changed qemu_log_separate() to fix unbalanced and
>> >       remove qemu_log_enabled() check.
>> >     - changed qemu_log_lock() to include else.
>> >     - make qemu_logfile_free static.
>> >     - use g_assert(logfile) in qemu_logfile_free.
>> >     - Relocated unlock out of if/else in qemu_log_close(), and
>> >       in qemu_set_log().
>> > ---
>> >  include/qemu/log.h | 42 +++++++++++++++++++++++----
>> >  util/log.c         | 72 ++++++++++++++++++++++++++++++++--------------
>> >  include/exec/log.h | 33 ++++++++++++++++++---
>> >  tcg/tcg.c          | 12 ++++++--
>> >  4 files changed, 126 insertions(+), 33 deletions(-)
>> >
>> > diff --git a/include/qemu/log.h b/include/qemu/log.h
>> > index a7c5b01571..528e1f9dd7 100644
>> > --- a/include/qemu/log.h
>> > +++ b/include/qemu/log.h
>> > @@ -3,9 +3,16 @@
>> >
>> >  /* A small part of this API is split into its own header */
>> >  #include "qemu/log-for-trace.h"
>> > +#include "qemu/rcu.h"
>> > +
>> > +typedef struct QemuLogFile {
>> > +    struct rcu_head rcu;
>> > +    FILE *fd;
>> > +} QemuLogFile;
>> >
>> >  /* Private global variable, don't use */
>> > -extern FILE *qemu_logfile;
>> > +extern QemuLogFile *qemu_logfile;
>> > +
>> >
>> >  /*
>> >   * The new API:
>> > @@ -25,7 +32,16 @@ static inline bool qemu_log_enabled(void)
>> >   */
>> >  static inline bool qemu_log_separate(void)
>> >  {
>> > -    return qemu_logfile != NULL && qemu_logfile != stderr;
>> > +    QemuLogFile *logfile;
>> > +    bool res = false;
>> > +
>> > +    rcu_read_lock();
>> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> > +    if (logfile && logfile->fd != stderr) {
>> > +        res = true;
>> > +    }
>> > +    rcu_read_unlock();
>> > +    return res;
>> >  }
>> >
>> >  #define CPU_LOG_TB_OUT_ASM (1 << 0)
>> > @@ -55,14 +71,23 @@ static inline bool qemu_log_separate(void)
>> >
>> >  static inline FILE *qemu_log_lock(void)
>> >  {
>> > -    qemu_flockfile(qemu_logfile);
>> > -    return logfile->fd;
>> > +    QemuLogFile *logfile;
>> > +    rcu_read_lock();
>> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> > +    if (logfile) {
>> > +        qemu_flockfile(logfile->fd);
>> > +        return logfile->fd;
>> > +    } else {
>> > +        rcu_read_unlock();
>>
>> As qemu_log_lock() and unlock should be paired we can drop the unlock
>> here and do an unconditional unlock bellow even if a null fd is passed.
>>
>> Otherwise:
>>
>> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
>>
>> > +        return NULL;
>> > +    }
>> >  }
>> >
>> >  static inline void qemu_log_unlock(FILE *fd)
>> >  {
>> >      if (fd) {
>> >          qemu_funlockfile(fd);
>> > +        rcu_read_unlock();
>> >      }
>> >  }
>> >
>> > @@ -73,9 +98,14 @@ static inline void qemu_log_unlock(FILE *fd)
>> >  static inline void GCC_FMT_ATTR(1, 0)
>> >  qemu_log_vprintf(const char *fmt, va_list va)
>> >  {
>> > -    if (qemu_logfile) {
>> > -        vfprintf(qemu_logfile, fmt, va);
>> > +    QemuLogFile *logfile;
>> > +
>> > +    rcu_read_lock();
>> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> > +    if (logfile) {
>> > +        vfprintf(logfile->fd, fmt, va);
>> >      }
>> > +    rcu_read_unlock();
>> >  }
>> >
>> >  /* log only if a bit is set on the current loglevel mask:
>> > diff --git a/util/log.c b/util/log.c
>> > index 91ebb5c924..9f9b6b74b7 100644
>> > --- a/util/log.c
>> > +++ b/util/log.c
>> > @@ -28,7 +28,7 @@
>> >
>> >  static char *logfilename;
>> >  static QemuMutex qemu_logfile_mutex;
>> > -FILE *qemu_logfile;
>> > +QemuLogFile *qemu_logfile;
>> >  int qemu_loglevel;
>> >  static int log_append = 0;
>> >  static GArray *debug_regions;
>> > @@ -37,10 +37,14 @@ static GArray *debug_regions;
>> >  int qemu_log(const char *fmt, ...)
>> >  {
>> >      int ret = 0;
>> > -    if (qemu_logfile) {
>> > +    QemuLogFile *logfile;
>> > +
>> > +    rcu_read_lock();
>> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> > +    if (logfile) {
>> >          va_list ap;
>> >          va_start(ap, fmt);
>> > -        ret = vfprintf(qemu_logfile, fmt, ap);
>> > +        ret = vfprintf(logfile->fd, fmt, ap);
>> >          va_end(ap);
>> >
>> >          /* Don't pass back error results.  */
>> > @@ -48,6 +52,7 @@ int qemu_log(const char *fmt, ...)
>> >              ret = 0;
>> >          }
>> >      }
>> > +    rcu_read_unlock();
>> >      return ret;
>> >  }
>> >
>> > @@ -56,12 +61,24 @@ static void __attribute__((__constructor__)) qemu_logfile_init(void)
>> >      qemu_mutex_init(&qemu_logfile_mutex);
>> >  }
>> >
>> > +static void qemu_logfile_free(QemuLogFile *logfile)
>> > +{
>> > +    g_assert(logfile);
>> > +
>> > +    if (logfile->fd != stderr) {
>> > +        fclose(logfile->fd);
>> > +    }
>> > +    g_free(logfile);
>> > +}
>> > +
>> >  static bool log_uses_own_buffers;
>> >
>> >  /* enable or disable low levels log */
>> >  void qemu_set_log(int log_flags)
>> >  {
>> >      bool need_to_open_file = false;
>> > +    QemuLogFile *logfile;
>> > +
>> >      qemu_loglevel = log_flags;
>> >  #ifdef CONFIG_TRACE_LOG
>> >      qemu_loglevel |= LOG_TRACE;
>> > @@ -80,43 +97,47 @@ void qemu_set_log(int log_flags)
>> >      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();
>> > +        logfile = qemu_logfile;
>> > +        atomic_rcu_set(&qemu_logfile, NULL);
>> > +        call_rcu(logfile, qemu_logfile_free, rcu);
>> >      } else if (!qemu_logfile && need_to_open_file) {
>> > +        logfile = g_new0(QemuLogFile, 1);
>> >          if (logfilename) {
>> > -            qemu_logfile = fopen(logfilename, log_append ? "a" : "w");
>> > -            if (!qemu_logfile) {
>> > +            logfile->fd = fopen(logfilename, log_append ? "a" : "w");
>> > +            if (!logfile->fd) {
>> > +                g_free(logfile);
>> >                  perror(logfilename);
>> >                  _exit(1);
>> >              }
>> >              /* In case we are a daemon redirect stderr to logfile */
>> >              if (is_daemonized()) {
>> > -                dup2(fileno(qemu_logfile), STDERR_FILENO);
>> > -                fclose(qemu_logfile);
>> > +                dup2(fileno(logfile->fd), STDERR_FILENO);
>> > +                fclose(logfile->fd);
>> >                  /* This will skip closing logfile in qemu_log_close() */
>> > -                qemu_logfile = stderr;
>> > +                logfile->fd = stderr;
>> >              }
>> >          } else {
>> >              /* Default to stderr if no log file specified */
>> >              assert(!is_daemonized());
>> > -            qemu_logfile = stderr;
>> > +            logfile->fd = stderr;
>> >          }
>> >          /* must avoid mmap() usage of glibc by setting a buffer "by hand" */
>> >          if (log_uses_own_buffers) {
>> >              static char logfile_buf[4096];
>> >
>> > -            setvbuf(qemu_logfile, logfile_buf, _IOLBF, sizeof(logfile_buf));
>> > +            setvbuf(logfile->fd, logfile_buf, _IOLBF, sizeof(logfile_buf));
>> >          } else {
>> >  #if defined(_WIN32)
>> >              /* Win32 doesn't support line-buffering, so use unbuffered output. */
>> > -            setvbuf(qemu_logfile, NULL, _IONBF, 0);
>> > +            setvbuf(logfile->fd, NULL, _IONBF, 0);
>> >  #else
>> > -            setvbuf(qemu_logfile, NULL, _IOLBF, 0);
>> > +            setvbuf(logfile->fd, NULL, _IOLBF, 0);
>> >  #endif
>> >              log_append = 1;
>> >          }
>> > -        qemu_mutex_unlock(&qemu_logfile_mutex);
>> > +        atomic_rcu_set(&qemu_logfile, logfile);
>> >      }
>> > +    qemu_mutex_unlock(&qemu_logfile_mutex);
>> >  }
>> >
>> >  void qemu_log_needs_buffers(void)
>> > @@ -245,19 +266,28 @@ out:
>> >  /* fflush() the log file */
>> >  void qemu_log_flush(void)
>> >  {
>> > -    fflush(qemu_logfile);
>> > +    QemuLogFile *logfile;
>> > +
>> > +    rcu_read_lock();
>> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> > +    if (logfile) {
>> > +        fflush(logfile->fd);
>> > +    }
>> > +    rcu_read_unlock();
>> >  }
>> >
>> >  /* Close the log file */
>> >  void qemu_log_close(void)
>> >  {
>> > +    QemuLogFile *logfile;
>> > +
>> >      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;
>> > +    logfile = qemu_logfile;
>> > +
>> > +    if (logfile) {
>> > +        atomic_rcu_set(&qemu_logfile, NULL);
>> > +        call_rcu(logfile, qemu_logfile_free, rcu);
>> >      }
>> >      qemu_mutex_unlock(&qemu_logfile_mutex);
>> >  }
>> >  diff --git a/include/exec/log.h b/include/exec/log.h
>> > index e2cfd436e6..9bd1e4aa20 100644
>> > --- a/include/exec/log.h
>> > +++ b/include/exec/log.h
>> > @@ -15,8 +15,15 @@
>> >   */
>> >  static inline void log_cpu_state(CPUState *cpu, int flags)
>> >  {
>> > +    QemuLogFile *logfile;
>> > +
>> >      if (qemu_log_enabled()) {
>> > -        cpu_dump_state(cpu, qemu_logfile, flags);
>> > +        rcu_read_lock();
>> > +        logfile = atomic_rcu_read(&qemu_logfile);
>> > +        if (logfile) {
>> > +            cpu_dump_state(cpu, logfile->fd, flags);
>> > +        }
>> > +        rcu_read_unlock();
>> >      }
>> >  }
>> >
>> > @@ -40,19 +47,37 @@ static inline void log_cpu_state_mask(int mask, CPUState *cpu, int flags)
>> >  static inline void log_target_disas(CPUState *cpu, target_ulong start,
>> >                                      target_ulong len)
>> >  {
>> > -    target_disas(qemu_logfile, cpu, start, len);
>> > +    QemuLogFile *logfile;
>> > +    rcu_read_lock();
>> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> > +    if (logfile) {
>> > +        target_disas(logfile->fd, cpu, start, len);
>> > +    }
>> > +    rcu_read_unlock();
>> >  }
>> >
>> >  static inline void log_disas(void *code, unsigned long size)
>> >  {
>> > -    disas(qemu_logfile, code, size);
>> > +    QemuLogFile *logfile;
>> > +    rcu_read_lock();
>> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> > +    if (logfile) {
>> > +        disas(logfile->fd, code, size);
>> > +    }
>> > +    rcu_read_unlock();
>> >  }
>> >
>> >  #if defined(CONFIG_USER_ONLY)
>> >  /* page_dump() output to the log file: */
>> >  static inline void log_page_dump(void)
>> >  {
>> > -    page_dump(qemu_logfile);
>> > +    QemuLogFile *logfile;
>> > +    rcu_read_lock();
>> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> > +    if (logfile) {
>> > +        page_dump(logfile->fd);
>> > +    }
>> > +    rcu_read_unlock();
>> >  }
>> >  #endif
>> >  #endif
>> > diff --git a/tcg/tcg.c b/tcg/tcg.c
>> > index 0511266d85..4f616ba38b 100644
>> > --- a/tcg/tcg.c
>> > +++ b/tcg/tcg.c
>> > @@ -2114,9 +2114,17 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
>> >          }
>> >
>> >          if (have_prefs || op->life) {
>> > -            for (; col < 40; ++col) {
>> > -                putc(' ', qemu_logfile);
>> > +
>> > +            QemuLogFile *logfile;
>> > +
>> > +            rcu_read_lock();
>> > +            logfile = atomic_rcu_read(&qemu_logfile);
>> > +            if (logfile) {
>> > +                for (; col < 40; ++col) {
>> > +                    putc(' ', logfile->fd);
>> > +                }
>> >              }
>> > +            rcu_read_unlock();
>> >          }
>> >
>> >          if (op->life) {
>>
>>
>> --
>> Alex Bennée


--
Alex Bennée

Re: [PATCH v2 5/6] Add use of RCU for qemu_logfile.

[Robert Foley]

On Mon, 18 Nov 2019 at 08:23, Alex Bennée <alex.bennee@linaro.org> wrote:
>
>
> Robert Foley <robert.foley@linaro.org> writes:
>
> > On Mon, 18 Nov 2019 at 07:22, Alex Bennée <alex.bennee@linaro.org> wrote:
> >>
> >>
> >> > +    if (logfile) {
> >> > +        qemu_flockfile(logfile->fd);
> >> > +        return logfile->fd;
> >> > +    } else {
> >> > +        rcu_read_unlock();
> >>
> >> As qemu_log_lock() and unlock should be paired we can drop the unlock
> >> here and do an unconditional unlock bellow even if a null fd is passed.
> >>
> >> Otherwise:
> >>
> >> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
> >>
> > Sounds reasonable.  It sounds like we should change it to be something
> > like this.
> >
> > static inline FILE *qemu_log_lock(void)
> > {
> >     QemuLogFile *logfile;
> >     rcu_read_lock();
> >     logfile = atomic_rcu_read(&qemu_logfile);
> >     if (logfile) {
> >         qemu_flockfile(logfile->fd);
> >         return logfile->fd;
> >     }
> >     rcu_read_unlock();
> >     return NULL;
> > }
> > I will make the changes.
>
> No I mean as you have to call qemu_log_unlock() you can to the unlock
> there. You have to hold the lock over the usage of the resource:
>
OK, got it.
We will need to make one other change to target/tilegx/translate.c
since it conditionally unlocks depending on what qemu_log_lock()
returns.

It seems like the right thing to do since it makes all uses of
qemu_log_lock() homogeneous in that they will always unconditionally
call qemu_log_unlock().

I will make the changes.

Thanks,
-Rob

On Mon, 18 Nov 2019 at 08:23, Alex Bennée <alex.bennee@linaro.org> wrote:
>
>
> Robert Foley <robert.foley@linaro.org> writes:
>
> > On Mon, 18 Nov 2019 at 07:22, Alex Bennée <alex.bennee@linaro.org> wrote:
> >>
> >>
> >> > +    if (logfile) {
> >> > +        qemu_flockfile(logfile->fd);
> >> > +        return logfile->fd;
> >> > +    } else {
> >> > +        rcu_read_unlock();
> >>
> >> As qemu_log_lock() and unlock should be paired we can drop the unlock
> >> here and do an unconditional unlock bellow even if a null fd is passed.
> >>
> >> Otherwise:
> >>
> >> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
> >>
> > Sounds reasonable.  It sounds like we should change it to be something
> > like this.
> >
> > static inline FILE *qemu_log_lock(void)
> > {
> >     QemuLogFile *logfile;
> >     rcu_read_lock();
> >     logfile = atomic_rcu_read(&qemu_logfile);
> >     if (logfile) {
> >         qemu_flockfile(logfile->fd);
> >         return logfile->fd;
> >     }
> >     rcu_read_unlock();
> >     return NULL;
> > }
> > I will make the changes.
>
> No I mean as you have to call qemu_log_unlock() you can to the unlock
> there. You have to hold the lock over the usage of the resource:
>
>   static inline FILE *qemu_log_lock(void)
>   {
>       QemuLogFile *logfile;
>       rcu_read_lock();
>       logfile = atomic_rcu_read(&qemu_logfile);
>       if (logfile) {
>           qemu_flockfile(logfile->fd);
>           return logfile->fd;
>       } else {
>           return NULL;
>       }
>   }
>
>   static inline void qemu_log_unlock(FILE *fd)
>   {
>       if (fd) {
>           qemu_funlockfile(fd);
>       }
>       rcu_read_unlock();
>   }
>
>
> >
> > Thanks,
> > -Rob
> > On Mon, 18 Nov 2019 at 07:22, Alex Bennée <alex.bennee@linaro.org> wrote:
> >>
> >>
> >> Robert Foley <robert.foley@linaro.org> writes:
> >>
> >> > This now allows changing the logfile while logging is active,
> >> > and also solves the issue of a seg fault while changing the logfile.
> >> >
> >> > Any read access to the qemu_logfile handle will use
> >> > the rcu_read_lock()/unlock() around the use of the handle.
> >> > To fetch the handle we will use atomic_rcu_read().
> >> > We also in many cases do a check for validity of the
> >> > logfile handle before using it to deal with the case where the
> >> > file is closed and set to NULL.
> >> >
> >> > The cases where we write to the qemu_logfile will use atomic_rcu_set().
> >> > Writers will also use call_rcu() with a newly added qemu_logfile_free
> >> > function for freeing/closing when readers have finished.
> >> >
> >> > Signed-off-by: Robert Foley <robert.foley@linaro.org>
> >> > ---
> >> > v2
> >> >     - No specific changes, just merging in cleanup changes in qemu_set_log().
> >> > ---
> >> > v1
> >> >     - Changes for review comments.
> >> >     - Minor changes to definition of QemuLogFile.
> >> >     - Changed qemu_log_separate() to fix unbalanced and
> >> >       remove qemu_log_enabled() check.
> >> >     - changed qemu_log_lock() to include else.
> >> >     - make qemu_logfile_free static.
> >> >     - use g_assert(logfile) in qemu_logfile_free.
> >> >     - Relocated unlock out of if/else in qemu_log_close(), and
> >> >       in qemu_set_log().
> >> > ---
> >> >  include/qemu/log.h | 42 +++++++++++++++++++++++----
> >> >  util/log.c         | 72 ++++++++++++++++++++++++++++++++--------------
> >> >  include/exec/log.h | 33 ++++++++++++++++++---
> >> >  tcg/tcg.c          | 12 ++++++--
> >> >  4 files changed, 126 insertions(+), 33 deletions(-)
> >> >
> >> > diff --git a/include/qemu/log.h b/include/qemu/log.h
> >> > index a7c5b01571..528e1f9dd7 100644
> >> > --- a/include/qemu/log.h
> >> > +++ b/include/qemu/log.h
> >> > @@ -3,9 +3,16 @@
> >> >
> >> >  /* A small part of this API is split into its own header */
> >> >  #include "qemu/log-for-trace.h"
> >> > +#include "qemu/rcu.h"
> >> > +
> >> > +typedef struct QemuLogFile {
> >> > +    struct rcu_head rcu;
> >> > +    FILE *fd;
> >> > +} QemuLogFile;
> >> >
> >> >  /* Private global variable, don't use */
> >> > -extern FILE *qemu_logfile;
> >> > +extern QemuLogFile *qemu_logfile;
> >> > +
> >> >
> >> >  /*
> >> >   * The new API:
> >> > @@ -25,7 +32,16 @@ static inline bool qemu_log_enabled(void)
> >> >   */
> >> >  static inline bool qemu_log_separate(void)
> >> >  {
> >> > -    return qemu_logfile != NULL && qemu_logfile != stderr;
> >> > +    QemuLogFile *logfile;
> >> > +    bool res = false;
> >> > +
> >> > +    rcu_read_lock();
> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> > +    if (logfile && logfile->fd != stderr) {
> >> > +        res = true;
> >> > +    }
> >> > +    rcu_read_unlock();
> >> > +    return res;
> >> >  }
> >> >
> >> >  #define CPU_LOG_TB_OUT_ASM (1 << 0)
> >> > @@ -55,14 +71,23 @@ static inline bool qemu_log_separate(void)
> >> >
> >> >  static inline FILE *qemu_log_lock(void)
> >> >  {
> >> > -    qemu_flockfile(qemu_logfile);
> >> > -    return logfile->fd;
> >> > +    QemuLogFile *logfile;
> >> > +    rcu_read_lock();
> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> > +    if (logfile) {
> >> > +        qemu_flockfile(logfile->fd);
> >> > +        return logfile->fd;
> >> > +    } else {
> >> > +        rcu_read_unlock();
> >>
> >> As qemu_log_lock() and unlock should be paired we can drop the unlock
> >> here and do an unconditional unlock bellow even if a null fd is passed.
> >>
> >> Otherwise:
> >>
> >> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
> >>
> >> > +        return NULL;
> >> > +    }
> >> >  }
> >> >
> >> >  static inline void qemu_log_unlock(FILE *fd)
> >> >  {
> >> >      if (fd) {
> >> >          qemu_funlockfile(fd);
> >> > +        rcu_read_unlock();
> >> >      }
> >> >  }
> >> >
> >> > @@ -73,9 +98,14 @@ static inline void qemu_log_unlock(FILE *fd)
> >> >  static inline void GCC_FMT_ATTR(1, 0)
> >> >  qemu_log_vprintf(const char *fmt, va_list va)
> >> >  {
> >> > -    if (qemu_logfile) {
> >> > -        vfprintf(qemu_logfile, fmt, va);
> >> > +    QemuLogFile *logfile;
> >> > +
> >> > +    rcu_read_lock();
> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> > +    if (logfile) {
> >> > +        vfprintf(logfile->fd, fmt, va);
> >> >      }
> >> > +    rcu_read_unlock();
> >> >  }
> >> >
> >> >  /* log only if a bit is set on the current loglevel mask:
> >> > diff --git a/util/log.c b/util/log.c
> >> > index 91ebb5c924..9f9b6b74b7 100644
> >> > --- a/util/log.c
> >> > +++ b/util/log.c
> >> > @@ -28,7 +28,7 @@
> >> >
> >> >  static char *logfilename;
> >> >  static QemuMutex qemu_logfile_mutex;
> >> > -FILE *qemu_logfile;
> >> > +QemuLogFile *qemu_logfile;
> >> >  int qemu_loglevel;
> >> >  static int log_append = 0;
> >> >  static GArray *debug_regions;
> >> > @@ -37,10 +37,14 @@ static GArray *debug_regions;
> >> >  int qemu_log(const char *fmt, ...)
> >> >  {
> >> >      int ret = 0;
> >> > -    if (qemu_logfile) {
> >> > +    QemuLogFile *logfile;
> >> > +
> >> > +    rcu_read_lock();
> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> > +    if (logfile) {
> >> >          va_list ap;
> >> >          va_start(ap, fmt);
> >> > -        ret = vfprintf(qemu_logfile, fmt, ap);
> >> > +        ret = vfprintf(logfile->fd, fmt, ap);
> >> >          va_end(ap);
> >> >
> >> >          /* Don't pass back error results.  */
> >> > @@ -48,6 +52,7 @@ int qemu_log(const char *fmt, ...)
> >> >              ret = 0;
> >> >          }
> >> >      }
> >> > +    rcu_read_unlock();
> >> >      return ret;
> >> >  }
> >> >
> >> > @@ -56,12 +61,24 @@ static void __attribute__((__constructor__)) qemu_logfile_init(void)
> >> >      qemu_mutex_init(&qemu_logfile_mutex);
> >> >  }
> >> >
> >> > +static void qemu_logfile_free(QemuLogFile *logfile)
> >> > +{
> >> > +    g_assert(logfile);
> >> > +
> >> > +    if (logfile->fd != stderr) {
> >> > +        fclose(logfile->fd);
> >> > +    }
> >> > +    g_free(logfile);
> >> > +}
> >> > +
> >> >  static bool log_uses_own_buffers;
> >> >
> >> >  /* enable or disable low levels log */
> >> >  void qemu_set_log(int log_flags)
> >> >  {
> >> >      bool need_to_open_file = false;
> >> > +    QemuLogFile *logfile;
> >> > +
> >> >      qemu_loglevel = log_flags;
> >> >  #ifdef CONFIG_TRACE_LOG
> >> >      qemu_loglevel |= LOG_TRACE;
> >> > @@ -80,43 +97,47 @@ void qemu_set_log(int log_flags)
> >> >      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();
> >> > +        logfile = qemu_logfile;
> >> > +        atomic_rcu_set(&qemu_logfile, NULL);
> >> > +        call_rcu(logfile, qemu_logfile_free, rcu);
> >> >      } else if (!qemu_logfile && need_to_open_file) {
> >> > +        logfile = g_new0(QemuLogFile, 1);
> >> >          if (logfilename) {
> >> > -            qemu_logfile = fopen(logfilename, log_append ? "a" : "w");
> >> > -            if (!qemu_logfile) {
> >> > +            logfile->fd = fopen(logfilename, log_append ? "a" : "w");
> >> > +            if (!logfile->fd) {
> >> > +                g_free(logfile);
> >> >                  perror(logfilename);
> >> >                  _exit(1);
> >> >              }
> >> >              /* In case we are a daemon redirect stderr to logfile */
> >> >              if (is_daemonized()) {
> >> > -                dup2(fileno(qemu_logfile), STDERR_FILENO);
> >> > -                fclose(qemu_logfile);
> >> > +                dup2(fileno(logfile->fd), STDERR_FILENO);
> >> > +                fclose(logfile->fd);
> >> >                  /* This will skip closing logfile in qemu_log_close() */
> >> > -                qemu_logfile = stderr;
> >> > +                logfile->fd = stderr;
> >> >              }
> >> >          } else {
> >> >              /* Default to stderr if no log file specified */
> >> >              assert(!is_daemonized());
> >> > -            qemu_logfile = stderr;
> >> > +            logfile->fd = stderr;
> >> >          }
> >> >          /* must avoid mmap() usage of glibc by setting a buffer "by hand" */
> >> >          if (log_uses_own_buffers) {
> >> >              static char logfile_buf[4096];
> >> >
> >> > -            setvbuf(qemu_logfile, logfile_buf, _IOLBF, sizeof(logfile_buf));
> >> > +            setvbuf(logfile->fd, logfile_buf, _IOLBF, sizeof(logfile_buf));
> >> >          } else {
> >> >  #if defined(_WIN32)
> >> >              /* Win32 doesn't support line-buffering, so use unbuffered output. */
> >> > -            setvbuf(qemu_logfile, NULL, _IONBF, 0);
> >> > +            setvbuf(logfile->fd, NULL, _IONBF, 0);
> >> >  #else
> >> > -            setvbuf(qemu_logfile, NULL, _IOLBF, 0);
> >> > +            setvbuf(logfile->fd, NULL, _IOLBF, 0);
> >> >  #endif
> >> >              log_append = 1;
> >> >          }
> >> > -        qemu_mutex_unlock(&qemu_logfile_mutex);
> >> > +        atomic_rcu_set(&qemu_logfile, logfile);
> >> >      }
> >> > +    qemu_mutex_unlock(&qemu_logfile_mutex);
> >> >  }
> >> >
> >> >  void qemu_log_needs_buffers(void)
> >> > @@ -245,19 +266,28 @@ out:
> >> >  /* fflush() the log file */
> >> >  void qemu_log_flush(void)
> >> >  {
> >> > -    fflush(qemu_logfile);
> >> > +    QemuLogFile *logfile;
> >> > +
> >> > +    rcu_read_lock();
> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> > +    if (logfile) {
> >> > +        fflush(logfile->fd);
> >> > +    }
> >> > +    rcu_read_unlock();
> >> >  }
> >> >
> >> >  /* Close the log file */
> >> >  void qemu_log_close(void)
> >> >  {
> >> > +    QemuLogFile *logfile;
> >> > +
> >> >      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;
> >> > +    logfile = qemu_logfile;
> >> > +
> >> > +    if (logfile) {
> >> > +        atomic_rcu_set(&qemu_logfile, NULL);
> >> > +        call_rcu(logfile, qemu_logfile_free, rcu);
> >> >      }
> >> >      qemu_mutex_unlock(&qemu_logfile_mutex);
> >> >  }
> >> >  diff --git a/include/exec/log.h b/include/exec/log.h
> >> > index e2cfd436e6..9bd1e4aa20 100644
> >> > --- a/include/exec/log.h
> >> > +++ b/include/exec/log.h
> >> > @@ -15,8 +15,15 @@
> >> >   */
> >> >  static inline void log_cpu_state(CPUState *cpu, int flags)
> >> >  {
> >> > +    QemuLogFile *logfile;
> >> > +
> >> >      if (qemu_log_enabled()) {
> >> > -        cpu_dump_state(cpu, qemu_logfile, flags);
> >> > +        rcu_read_lock();
> >> > +        logfile = atomic_rcu_read(&qemu_logfile);
> >> > +        if (logfile) {
> >> > +            cpu_dump_state(cpu, logfile->fd, flags);
> >> > +        }
> >> > +        rcu_read_unlock();
> >> >      }
> >> >  }
> >> >
> >> > @@ -40,19 +47,37 @@ static inline void log_cpu_state_mask(int mask, CPUState *cpu, int flags)
> >> >  static inline void log_target_disas(CPUState *cpu, target_ulong start,
> >> >                                      target_ulong len)
> >> >  {
> >> > -    target_disas(qemu_logfile, cpu, start, len);
> >> > +    QemuLogFile *logfile;
> >> > +    rcu_read_lock();
> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> > +    if (logfile) {
> >> > +        target_disas(logfile->fd, cpu, start, len);
> >> > +    }
> >> > +    rcu_read_unlock();
> >> >  }
> >> >
> >> >  static inline void log_disas(void *code, unsigned long size)
> >> >  {
> >> > -    disas(qemu_logfile, code, size);
> >> > +    QemuLogFile *logfile;
> >> > +    rcu_read_lock();
> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> > +    if (logfile) {
> >> > +        disas(logfile->fd, code, size);
> >> > +    }
> >> > +    rcu_read_unlock();
> >> >  }
> >> >
> >> >  #if defined(CONFIG_USER_ONLY)
> >> >  /* page_dump() output to the log file: */
> >> >  static inline void log_page_dump(void)
> >> >  {
> >> > -    page_dump(qemu_logfile);
> >> > +    QemuLogFile *logfile;
> >> > +    rcu_read_lock();
> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> > +    if (logfile) {
> >> > +        page_dump(logfile->fd);
> >> > +    }
> >> > +    rcu_read_unlock();
> >> >  }
> >> >  #endif
> >> >  #endif
> >> > diff --git a/tcg/tcg.c b/tcg/tcg.c
> >> > index 0511266d85..4f616ba38b 100644
> >> > --- a/tcg/tcg.c
> >> > +++ b/tcg/tcg.c
> >> > @@ -2114,9 +2114,17 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
> >> >          }
> >> >
> >> >          if (have_prefs || op->life) {
> >> > -            for (; col < 40; ++col) {
> >> > -                putc(' ', qemu_logfile);
> >> > +
> >> > +            QemuLogFile *logfile;
> >> > +
> >> > +            rcu_read_lock();
> >> > +            logfile = atomic_rcu_read(&qemu_logfile);
> >> > +            if (logfile) {
> >> > +                for (; col < 40; ++col) {
> >> > +                    putc(' ', logfile->fd);
> >> > +                }
> >> >              }
> >> > +            rcu_read_unlock();
> >> >          }
> >> >
> >> >          if (op->life) {
> >>
> >>
> >> --
> >> Alex Bennée
>
>
> --
> Alex Bennée

Re: [PATCH v2 5/6] Add use of RCU for qemu_logfile.

[Alex Bennée]

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

> On Mon, 18 Nov 2019 at 08:23, Alex Bennée <alex.bennee@linaro.org> wrote:
>>
>>
>> Robert Foley <robert.foley@linaro.org> writes:
>>
>> > On Mon, 18 Nov 2019 at 07:22, Alex Bennée <alex.bennee@linaro.org> wrote:
>> >>
>> >>
>> >> > +    if (logfile) {
>> >> > +        qemu_flockfile(logfile->fd);
>> >> > +        return logfile->fd;
>> >> > +    } else {
>> >> > +        rcu_read_unlock();
>> >>
>> >> As qemu_log_lock() and unlock should be paired we can drop the unlock
>> >> here and do an unconditional unlock bellow even if a null fd is passed.
>> >>
>> >> Otherwise:
>> >>
>> >> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
>> >>
>> > Sounds reasonable.  It sounds like we should change it to be something
>> > like this.
>> >
>> > static inline FILE *qemu_log_lock(void)
>> > {
>> >     QemuLogFile *logfile;
>> >     rcu_read_lock();
>> >     logfile = atomic_rcu_read(&qemu_logfile);
>> >     if (logfile) {
>> >         qemu_flockfile(logfile->fd);
>> >         return logfile->fd;
>> >     }
>> >     rcu_read_unlock();
>> >     return NULL;
>> > }
>> > I will make the changes.
>>
>> No I mean as you have to call qemu_log_unlock() you can to the unlock
>> there. You have to hold the lock over the usage of the resource:
>>
> OK, got it.
> We will need to make one other change to target/tilegx/translate.c
> since it conditionally unlocks depending on what qemu_log_lock()
> returns.

Hmm I'd be tempted to drop the locking all together and drop the final
log("\n") statement. The reason being the translator can longjmp out of
the loop if it attempts to translate an instruction in an inaccessible
page.

>
> It seems like the right thing to do since it makes all uses of
> qemu_log_lock() homogeneous in that they will always unconditionally
> call qemu_log_unlock().
>
> I will make the changes.
>
> Thanks,
> -Rob
>
> On Mon, 18 Nov 2019 at 08:23, Alex Bennée <alex.bennee@linaro.org> wrote:
>>
>>
>> Robert Foley <robert.foley@linaro.org> writes:
>>
>> > On Mon, 18 Nov 2019 at 07:22, Alex Bennée <alex.bennee@linaro.org> wrote:
>> >>
>> >>
>> >> > +    if (logfile) {
>> >> > +        qemu_flockfile(logfile->fd);
>> >> > +        return logfile->fd;
>> >> > +    } else {
>> >> > +        rcu_read_unlock();
>> >>
>> >> As qemu_log_lock() and unlock should be paired we can drop the unlock
>> >> here and do an unconditional unlock bellow even if a null fd is passed.
>> >>
>> >> Otherwise:
>> >>
>> >> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
>> >>
>> > Sounds reasonable.  It sounds like we should change it to be something
>> > like this.
>> >
>> > static inline FILE *qemu_log_lock(void)
>> > {
>> >     QemuLogFile *logfile;
>> >     rcu_read_lock();
>> >     logfile = atomic_rcu_read(&qemu_logfile);
>> >     if (logfile) {
>> >         qemu_flockfile(logfile->fd);
>> >         return logfile->fd;
>> >     }
>> >     rcu_read_unlock();
>> >     return NULL;
>> > }
>> > I will make the changes.
>>
>> No I mean as you have to call qemu_log_unlock() you can to the unlock
>> there. You have to hold the lock over the usage of the resource:
>>
>>   static inline FILE *qemu_log_lock(void)
>>   {
>>       QemuLogFile *logfile;
>>       rcu_read_lock();
>>       logfile = atomic_rcu_read(&qemu_logfile);
>>       if (logfile) {
>>           qemu_flockfile(logfile->fd);
>>           return logfile->fd;
>>       } else {
>>           return NULL;
>>       }
>>   }
>>
>>   static inline void qemu_log_unlock(FILE *fd)
>>   {
>>       if (fd) {
>>           qemu_funlockfile(fd);
>>       }
>>       rcu_read_unlock();
>>   }
>>
>>
>> >
>> > Thanks,
>> > -Rob
>> > On Mon, 18 Nov 2019 at 07:22, Alex Bennée <alex.bennee@linaro.org> wrote:
>> >>
>> >>
>> >> Robert Foley <robert.foley@linaro.org> writes:
>> >>
>> >> > This now allows changing the logfile while logging is active,
>> >> > and also solves the issue of a seg fault while changing the logfile.
>> >> >
>> >> > Any read access to the qemu_logfile handle will use
>> >> > the rcu_read_lock()/unlock() around the use of the handle.
>> >> > To fetch the handle we will use atomic_rcu_read().
>> >> > We also in many cases do a check for validity of the
>> >> > logfile handle before using it to deal with the case where the
>> >> > file is closed and set to NULL.
>> >> >
>> >> > The cases where we write to the qemu_logfile will use atomic_rcu_set().
>> >> > Writers will also use call_rcu() with a newly added qemu_logfile_free
>> >> > function for freeing/closing when readers have finished.
>> >> >
>> >> > Signed-off-by: Robert Foley <robert.foley@linaro.org>
>> >> > ---
>> >> > v2
>> >> >     - No specific changes, just merging in cleanup changes in qemu_set_log().
>> >> > ---
>> >> > v1
>> >> >     - Changes for review comments.
>> >> >     - Minor changes to definition of QemuLogFile.
>> >> >     - Changed qemu_log_separate() to fix unbalanced and
>> >> >       remove qemu_log_enabled() check.
>> >> >     - changed qemu_log_lock() to include else.
>> >> >     - make qemu_logfile_free static.
>> >> >     - use g_assert(logfile) in qemu_logfile_free.
>> >> >     - Relocated unlock out of if/else in qemu_log_close(), and
>> >> >       in qemu_set_log().
>> >> > ---
>> >> >  include/qemu/log.h | 42 +++++++++++++++++++++++----
>> >> >  util/log.c         | 72 ++++++++++++++++++++++++++++++++--------------
>> >> >  include/exec/log.h | 33 ++++++++++++++++++---
>> >> >  tcg/tcg.c          | 12 ++++++--
>> >> >  4 files changed, 126 insertions(+), 33 deletions(-)
>> >> >
>> >> > diff --git a/include/qemu/log.h b/include/qemu/log.h
>> >> > index a7c5b01571..528e1f9dd7 100644
>> >> > --- a/include/qemu/log.h
>> >> > +++ b/include/qemu/log.h
>> >> > @@ -3,9 +3,16 @@
>> >> >
>> >> >  /* A small part of this API is split into its own header */
>> >> >  #include "qemu/log-for-trace.h"
>> >> > +#include "qemu/rcu.h"
>> >> > +
>> >> > +typedef struct QemuLogFile {
>> >> > +    struct rcu_head rcu;
>> >> > +    FILE *fd;
>> >> > +} QemuLogFile;
>> >> >
>> >> >  /* Private global variable, don't use */
>> >> > -extern FILE *qemu_logfile;
>> >> > +extern QemuLogFile *qemu_logfile;
>> >> > +
>> >> >
>> >> >  /*
>> >> >   * The new API:
>> >> > @@ -25,7 +32,16 @@ static inline bool qemu_log_enabled(void)
>> >> >   */
>> >> >  static inline bool qemu_log_separate(void)
>> >> >  {
>> >> > -    return qemu_logfile != NULL && qemu_logfile != stderr;
>> >> > +    QemuLogFile *logfile;
>> >> > +    bool res = false;
>> >> > +
>> >> > +    rcu_read_lock();
>> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> >> > +    if (logfile && logfile->fd != stderr) {
>> >> > +        res = true;
>> >> > +    }
>> >> > +    rcu_read_unlock();
>> >> > +    return res;
>> >> >  }
>> >> >
>> >> >  #define CPU_LOG_TB_OUT_ASM (1 << 0)
>> >> > @@ -55,14 +71,23 @@ static inline bool qemu_log_separate(void)
>> >> >
>> >> >  static inline FILE *qemu_log_lock(void)
>> >> >  {
>> >> > -    qemu_flockfile(qemu_logfile);
>> >> > -    return logfile->fd;
>> >> > +    QemuLogFile *logfile;
>> >> > +    rcu_read_lock();
>> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> >> > +    if (logfile) {
>> >> > +        qemu_flockfile(logfile->fd);
>> >> > +        return logfile->fd;
>> >> > +    } else {
>> >> > +        rcu_read_unlock();
>> >>
>> >> As qemu_log_lock() and unlock should be paired we can drop the unlock
>> >> here and do an unconditional unlock bellow even if a null fd is passed.
>> >>
>> >> Otherwise:
>> >>
>> >> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
>> >>
>> >> > +        return NULL;
>> >> > +    }
>> >> >  }
>> >> >
>> >> >  static inline void qemu_log_unlock(FILE *fd)
>> >> >  {
>> >> >      if (fd) {
>> >> >          qemu_funlockfile(fd);
>> >> > +        rcu_read_unlock();
>> >> >      }
>> >> >  }
>> >> >
>> >> > @@ -73,9 +98,14 @@ static inline void qemu_log_unlock(FILE *fd)
>> >> >  static inline void GCC_FMT_ATTR(1, 0)
>> >> >  qemu_log_vprintf(const char *fmt, va_list va)
>> >> >  {
>> >> > -    if (qemu_logfile) {
>> >> > -        vfprintf(qemu_logfile, fmt, va);
>> >> > +    QemuLogFile *logfile;
>> >> > +
>> >> > +    rcu_read_lock();
>> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> >> > +    if (logfile) {
>> >> > +        vfprintf(logfile->fd, fmt, va);
>> >> >      }
>> >> > +    rcu_read_unlock();
>> >> >  }
>> >> >
>> >> >  /* log only if a bit is set on the current loglevel mask:
>> >> > diff --git a/util/log.c b/util/log.c
>> >> > index 91ebb5c924..9f9b6b74b7 100644
>> >> > --- a/util/log.c
>> >> > +++ b/util/log.c
>> >> > @@ -28,7 +28,7 @@
>> >> >
>> >> >  static char *logfilename;
>> >> >  static QemuMutex qemu_logfile_mutex;
>> >> > -FILE *qemu_logfile;
>> >> > +QemuLogFile *qemu_logfile;
>> >> >  int qemu_loglevel;
>> >> >  static int log_append = 0;
>> >> >  static GArray *debug_regions;
>> >> > @@ -37,10 +37,14 @@ static GArray *debug_regions;
>> >> >  int qemu_log(const char *fmt, ...)
>> >> >  {
>> >> >      int ret = 0;
>> >> > -    if (qemu_logfile) {
>> >> > +    QemuLogFile *logfile;
>> >> > +
>> >> > +    rcu_read_lock();
>> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> >> > +    if (logfile) {
>> >> >          va_list ap;
>> >> >          va_start(ap, fmt);
>> >> > -        ret = vfprintf(qemu_logfile, fmt, ap);
>> >> > +        ret = vfprintf(logfile->fd, fmt, ap);
>> >> >          va_end(ap);
>> >> >
>> >> >          /* Don't pass back error results.  */
>> >> > @@ -48,6 +52,7 @@ int qemu_log(const char *fmt, ...)
>> >> >              ret = 0;
>> >> >          }
>> >> >      }
>> >> > +    rcu_read_unlock();
>> >> >      return ret;
>> >> >  }
>> >> >
>> >> > @@ -56,12 +61,24 @@ static void __attribute__((__constructor__)) qemu_logfile_init(void)
>> >> >      qemu_mutex_init(&qemu_logfile_mutex);
>> >> >  }
>> >> >
>> >> > +static void qemu_logfile_free(QemuLogFile *logfile)
>> >> > +{
>> >> > +    g_assert(logfile);
>> >> > +
>> >> > +    if (logfile->fd != stderr) {
>> >> > +        fclose(logfile->fd);
>> >> > +    }
>> >> > +    g_free(logfile);
>> >> > +}
>> >> > +
>> >> >  static bool log_uses_own_buffers;
>> >> >
>> >> >  /* enable or disable low levels log */
>> >> >  void qemu_set_log(int log_flags)
>> >> >  {
>> >> >      bool need_to_open_file = false;
>> >> > +    QemuLogFile *logfile;
>> >> > +
>> >> >      qemu_loglevel = log_flags;
>> >> >  #ifdef CONFIG_TRACE_LOG
>> >> >      qemu_loglevel |= LOG_TRACE;
>> >> > @@ -80,43 +97,47 @@ void qemu_set_log(int log_flags)
>> >> >      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();
>> >> > +        logfile = qemu_logfile;
>> >> > +        atomic_rcu_set(&qemu_logfile, NULL);
>> >> > +        call_rcu(logfile, qemu_logfile_free, rcu);
>> >> >      } else if (!qemu_logfile && need_to_open_file) {
>> >> > +        logfile = g_new0(QemuLogFile, 1);
>> >> >          if (logfilename) {
>> >> > -            qemu_logfile = fopen(logfilename, log_append ? "a" : "w");
>> >> > -            if (!qemu_logfile) {
>> >> > +            logfile->fd = fopen(logfilename, log_append ? "a" : "w");
>> >> > +            if (!logfile->fd) {
>> >> > +                g_free(logfile);
>> >> >                  perror(logfilename);
>> >> >                  _exit(1);
>> >> >              }
>> >> >              /* In case we are a daemon redirect stderr to logfile */
>> >> >              if (is_daemonized()) {
>> >> > -                dup2(fileno(qemu_logfile), STDERR_FILENO);
>> >> > -                fclose(qemu_logfile);
>> >> > +                dup2(fileno(logfile->fd), STDERR_FILENO);
>> >> > +                fclose(logfile->fd);
>> >> >                  /* This will skip closing logfile in qemu_log_close() */
>> >> > -                qemu_logfile = stderr;
>> >> > +                logfile->fd = stderr;
>> >> >              }
>> >> >          } else {
>> >> >              /* Default to stderr if no log file specified */
>> >> >              assert(!is_daemonized());
>> >> > -            qemu_logfile = stderr;
>> >> > +            logfile->fd = stderr;
>> >> >          }
>> >> >          /* must avoid mmap() usage of glibc by setting a buffer "by hand" */
>> >> >          if (log_uses_own_buffers) {
>> >> >              static char logfile_buf[4096];
>> >> >
>> >> > -            setvbuf(qemu_logfile, logfile_buf, _IOLBF, sizeof(logfile_buf));
>> >> > +            setvbuf(logfile->fd, logfile_buf, _IOLBF, sizeof(logfile_buf));
>> >> >          } else {
>> >> >  #if defined(_WIN32)
>> >> >              /* Win32 doesn't support line-buffering, so use unbuffered output. */
>> >> > -            setvbuf(qemu_logfile, NULL, _IONBF, 0);
>> >> > +            setvbuf(logfile->fd, NULL, _IONBF, 0);
>> >> >  #else
>> >> > -            setvbuf(qemu_logfile, NULL, _IOLBF, 0);
>> >> > +            setvbuf(logfile->fd, NULL, _IOLBF, 0);
>> >> >  #endif
>> >> >              log_append = 1;
>> >> >          }
>> >> > -        qemu_mutex_unlock(&qemu_logfile_mutex);
>> >> > +        atomic_rcu_set(&qemu_logfile, logfile);
>> >> >      }
>> >> > +    qemu_mutex_unlock(&qemu_logfile_mutex);
>> >> >  }
>> >> >
>> >> >  void qemu_log_needs_buffers(void)
>> >> > @@ -245,19 +266,28 @@ out:
>> >> >  /* fflush() the log file */
>> >> >  void qemu_log_flush(void)
>> >> >  {
>> >> > -    fflush(qemu_logfile);
>> >> > +    QemuLogFile *logfile;
>> >> > +
>> >> > +    rcu_read_lock();
>> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> >> > +    if (logfile) {
>> >> > +        fflush(logfile->fd);
>> >> > +    }
>> >> > +    rcu_read_unlock();
>> >> >  }
>> >> >
>> >> >  /* Close the log file */
>> >> >  void qemu_log_close(void)
>> >> >  {
>> >> > +    QemuLogFile *logfile;
>> >> > +
>> >> >      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;
>> >> > +    logfile = qemu_logfile;
>> >> > +
>> >> > +    if (logfile) {
>> >> > +        atomic_rcu_set(&qemu_logfile, NULL);
>> >> > +        call_rcu(logfile, qemu_logfile_free, rcu);
>> >> >      }
>> >> >      qemu_mutex_unlock(&qemu_logfile_mutex);
>> >> >  }
>> >> >  diff --git a/include/exec/log.h b/include/exec/log.h
>> >> > index e2cfd436e6..9bd1e4aa20 100644
>> >> > --- a/include/exec/log.h
>> >> > +++ b/include/exec/log.h
>> >> > @@ -15,8 +15,15 @@
>> >> >   */
>> >> >  static inline void log_cpu_state(CPUState *cpu, int flags)
>> >> >  {
>> >> > +    QemuLogFile *logfile;
>> >> > +
>> >> >      if (qemu_log_enabled()) {
>> >> > -        cpu_dump_state(cpu, qemu_logfile, flags);
>> >> > +        rcu_read_lock();
>> >> > +        logfile = atomic_rcu_read(&qemu_logfile);
>> >> > +        if (logfile) {
>> >> > +            cpu_dump_state(cpu, logfile->fd, flags);
>> >> > +        }
>> >> > +        rcu_read_unlock();
>> >> >      }
>> >> >  }
>> >> >
>> >> > @@ -40,19 +47,37 @@ static inline void log_cpu_state_mask(int mask, CPUState *cpu, int flags)
>> >> >  static inline void log_target_disas(CPUState *cpu, target_ulong start,
>> >> >                                      target_ulong len)
>> >> >  {
>> >> > -    target_disas(qemu_logfile, cpu, start, len);
>> >> > +    QemuLogFile *logfile;
>> >> > +    rcu_read_lock();
>> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> >> > +    if (logfile) {
>> >> > +        target_disas(logfile->fd, cpu, start, len);
>> >> > +    }
>> >> > +    rcu_read_unlock();
>> >> >  }
>> >> >
>> >> >  static inline void log_disas(void *code, unsigned long size)
>> >> >  {
>> >> > -    disas(qemu_logfile, code, size);
>> >> > +    QemuLogFile *logfile;
>> >> > +    rcu_read_lock();
>> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> >> > +    if (logfile) {
>> >> > +        disas(logfile->fd, code, size);
>> >> > +    }
>> >> > +    rcu_read_unlock();
>> >> >  }
>> >> >
>> >> >  #if defined(CONFIG_USER_ONLY)
>> >> >  /* page_dump() output to the log file: */
>> >> >  static inline void log_page_dump(void)
>> >> >  {
>> >> > -    page_dump(qemu_logfile);
>> >> > +    QemuLogFile *logfile;
>> >> > +    rcu_read_lock();
>> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
>> >> > +    if (logfile) {
>> >> > +        page_dump(logfile->fd);
>> >> > +    }
>> >> > +    rcu_read_unlock();
>> >> >  }
>> >> >  #endif
>> >> >  #endif
>> >> > diff --git a/tcg/tcg.c b/tcg/tcg.c
>> >> > index 0511266d85..4f616ba38b 100644
>> >> > --- a/tcg/tcg.c
>> >> > +++ b/tcg/tcg.c
>> >> > @@ -2114,9 +2114,17 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
>> >> >          }
>> >> >
>> >> >          if (have_prefs || op->life) {
>> >> > -            for (; col < 40; ++col) {
>> >> > -                putc(' ', qemu_logfile);
>> >> > +
>> >> > +            QemuLogFile *logfile;
>> >> > +
>> >> > +            rcu_read_lock();
>> >> > +            logfile = atomic_rcu_read(&qemu_logfile);
>> >> > +            if (logfile) {
>> >> > +                for (; col < 40; ++col) {
>> >> > +                    putc(' ', logfile->fd);
>> >> > +                }
>> >> >              }
>> >> > +            rcu_read_unlock();
>> >> >          }
>> >> >
>> >> >          if (op->life) {
>> >>
>> >>
>> >> --
>> >> Alex Bennée
>>
>>
>> --
>> Alex Bennée


--
Alex Bennée

Re: [PATCH v2 5/6] Add use of RCU for qemu_logfile.

[Robert Foley]

On Mon, 18 Nov 2019 at 11:41, Alex Bennée <alex.bennee@linaro.org> wrote:
>
>
> >>
> > OK, got it.
> > We will need to make one other change to target/tilegx/translate.c
> > since it conditionally unlocks depending on what qemu_log_lock()
> > returns.
>
> Hmm I'd be tempted to drop the locking all together and drop the final
> log("\n") statement. The reason being the translator can longjmp out of
> the loop if it attempts to translate an instruction in an inaccessible
> page.
>
Good point.  Makes sense to remove the locking and final log("\n").
Will make this change.

Thanks,
-Rob

On Mon, 18 Nov 2019 at 11:41, Alex Bennée <alex.bennee@linaro.org> wrote:
>
>
> Robert Foley <robert.foley@linaro.org> writes:
>
> > On Mon, 18 Nov 2019 at 08:23, Alex Bennée <alex.bennee@linaro.org> wrote:
> >>
> >>
> >> Robert Foley <robert.foley@linaro.org> writes:
> >>
> >> > On Mon, 18 Nov 2019 at 07:22, Alex Bennée <alex.bennee@linaro.org> wrote:
> >> >>
> >> >>
> >> >> > +    if (logfile) {
> >> >> > +        qemu_flockfile(logfile->fd);
> >> >> > +        return logfile->fd;
> >> >> > +    } else {
> >> >> > +        rcu_read_unlock();
> >> >>
> >> >> As qemu_log_lock() and unlock should be paired we can drop the unlock
> >> >> here and do an unconditional unlock bellow even if a null fd is passed.
> >> >>
> >> >> Otherwise:
> >> >>
> >> >> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
> >> >>
> >> > Sounds reasonable.  It sounds like we should change it to be something
> >> > like this.
> >> >
> >> > static inline FILE *qemu_log_lock(void)
> >> > {
> >> >     QemuLogFile *logfile;
> >> >     rcu_read_lock();
> >> >     logfile = atomic_rcu_read(&qemu_logfile);
> >> >     if (logfile) {
> >> >         qemu_flockfile(logfile->fd);
> >> >         return logfile->fd;
> >> >     }
> >> >     rcu_read_unlock();
> >> >     return NULL;
> >> > }
> >> > I will make the changes.
> >>
> >> No I mean as you have to call qemu_log_unlock() you can to the unlock
> >> there. You have to hold the lock over the usage of the resource:
> >>
> > OK, got it.
> > We will need to make one other change to target/tilegx/translate.c
> > since it conditionally unlocks depending on what qemu_log_lock()
> > returns.
>
> Hmm I'd be tempted to drop the locking all together and drop the final
> log("\n") statement. The reason being the translator can longjmp out of
> the loop if it attempts to translate an instruction in an inaccessible
> page.
>
> >
> > It seems like the right thing to do since it makes all uses of
> > qemu_log_lock() homogeneous in that they will always unconditionally
> > call qemu_log_unlock().
> >
> > I will make the changes.
> >
> > Thanks,
> > -Rob
> >
> > On Mon, 18 Nov 2019 at 08:23, Alex Bennée <alex.bennee@linaro.org> wrote:
> >>
> >>
> >> Robert Foley <robert.foley@linaro.org> writes:
> >>
> >> > On Mon, 18 Nov 2019 at 07:22, Alex Bennée <alex.bennee@linaro.org> wrote:
> >> >>
> >> >>
> >> >> > +    if (logfile) {
> >> >> > +        qemu_flockfile(logfile->fd);
> >> >> > +        return logfile->fd;
> >> >> > +    } else {
> >> >> > +        rcu_read_unlock();
> >> >>
> >> >> As qemu_log_lock() and unlock should be paired we can drop the unlock
> >> >> here and do an unconditional unlock bellow even if a null fd is passed.
> >> >>
> >> >> Otherwise:
> >> >>
> >> >> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
> >> >>
> >> > Sounds reasonable.  It sounds like we should change it to be something
> >> > like this.
> >> >
> >> > static inline FILE *qemu_log_lock(void)
> >> > {
> >> >     QemuLogFile *logfile;
> >> >     rcu_read_lock();
> >> >     logfile = atomic_rcu_read(&qemu_logfile);
> >> >     if (logfile) {
> >> >         qemu_flockfile(logfile->fd);
> >> >         return logfile->fd;
> >> >     }
> >> >     rcu_read_unlock();
> >> >     return NULL;
> >> > }
> >> > I will make the changes.
> >>
> >> No I mean as you have to call qemu_log_unlock() you can to the unlock
> >> there. You have to hold the lock over the usage of the resource:
> >>
> >>   static inline FILE *qemu_log_lock(void)
> >>   {
> >>       QemuLogFile *logfile;
> >>       rcu_read_lock();
> >>       logfile = atomic_rcu_read(&qemu_logfile);
> >>       if (logfile) {
> >>           qemu_flockfile(logfile->fd);
> >>           return logfile->fd;
> >>       } else {
> >>           return NULL;
> >>       }
> >>   }
> >>
> >>   static inline void qemu_log_unlock(FILE *fd)
> >>   {
> >>       if (fd) {
> >>           qemu_funlockfile(fd);
> >>       }
> >>       rcu_read_unlock();
> >>   }
> >>
> >>
> >> >
> >> > Thanks,
> >> > -Rob
> >> > On Mon, 18 Nov 2019 at 07:22, Alex Bennée <alex.bennee@linaro.org> wrote:
> >> >>
> >> >>
> >> >> Robert Foley <robert.foley@linaro.org> writes:
> >> >>
> >> >> > This now allows changing the logfile while logging is active,
> >> >> > and also solves the issue of a seg fault while changing the logfile.
> >> >> >
> >> >> > Any read access to the qemu_logfile handle will use
> >> >> > the rcu_read_lock()/unlock() around the use of the handle.
> >> >> > To fetch the handle we will use atomic_rcu_read().
> >> >> > We also in many cases do a check for validity of the
> >> >> > logfile handle before using it to deal with the case where the
> >> >> > file is closed and set to NULL.
> >> >> >
> >> >> > The cases where we write to the qemu_logfile will use atomic_rcu_set().
> >> >> > Writers will also use call_rcu() with a newly added qemu_logfile_free
> >> >> > function for freeing/closing when readers have finished.
> >> >> >
> >> >> > Signed-off-by: Robert Foley <robert.foley@linaro.org>
> >> >> > ---
> >> >> > v2
> >> >> >     - No specific changes, just merging in cleanup changes in qemu_set_log().
> >> >> > ---
> >> >> > v1
> >> >> >     - Changes for review comments.
> >> >> >     - Minor changes to definition of QemuLogFile.
> >> >> >     - Changed qemu_log_separate() to fix unbalanced and
> >> >> >       remove qemu_log_enabled() check.
> >> >> >     - changed qemu_log_lock() to include else.
> >> >> >     - make qemu_logfile_free static.
> >> >> >     - use g_assert(logfile) in qemu_logfile_free.
> >> >> >     - Relocated unlock out of if/else in qemu_log_close(), and
> >> >> >       in qemu_set_log().
> >> >> > ---
> >> >> >  include/qemu/log.h | 42 +++++++++++++++++++++++----
> >> >> >  util/log.c         | 72 ++++++++++++++++++++++++++++++++--------------
> >> >> >  include/exec/log.h | 33 ++++++++++++++++++---
> >> >> >  tcg/tcg.c          | 12 ++++++--
> >> >> >  4 files changed, 126 insertions(+), 33 deletions(-)
> >> >> >
> >> >> > diff --git a/include/qemu/log.h b/include/qemu/log.h
> >> >> > index a7c5b01571..528e1f9dd7 100644
> >> >> > --- a/include/qemu/log.h
> >> >> > +++ b/include/qemu/log.h
> >> >> > @@ -3,9 +3,16 @@
> >> >> >
> >> >> >  /* A small part of this API is split into its own header */
> >> >> >  #include "qemu/log-for-trace.h"
> >> >> > +#include "qemu/rcu.h"
> >> >> > +
> >> >> > +typedef struct QemuLogFile {
> >> >> > +    struct rcu_head rcu;
> >> >> > +    FILE *fd;
> >> >> > +} QemuLogFile;
> >> >> >
> >> >> >  /* Private global variable, don't use */
> >> >> > -extern FILE *qemu_logfile;
> >> >> > +extern QemuLogFile *qemu_logfile;
> >> >> > +
> >> >> >
> >> >> >  /*
> >> >> >   * The new API:
> >> >> > @@ -25,7 +32,16 @@ static inline bool qemu_log_enabled(void)
> >> >> >   */
> >> >> >  static inline bool qemu_log_separate(void)
> >> >> >  {
> >> >> > -    return qemu_logfile != NULL && qemu_logfile != stderr;
> >> >> > +    QemuLogFile *logfile;
> >> >> > +    bool res = false;
> >> >> > +
> >> >> > +    rcu_read_lock();
> >> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> >> > +    if (logfile && logfile->fd != stderr) {
> >> >> > +        res = true;
> >> >> > +    }
> >> >> > +    rcu_read_unlock();
> >> >> > +    return res;
> >> >> >  }
> >> >> >
> >> >> >  #define CPU_LOG_TB_OUT_ASM (1 << 0)
> >> >> > @@ -55,14 +71,23 @@ static inline bool qemu_log_separate(void)
> >> >> >
> >> >> >  static inline FILE *qemu_log_lock(void)
> >> >> >  {
> >> >> > -    qemu_flockfile(qemu_logfile);
> >> >> > -    return logfile->fd;
> >> >> > +    QemuLogFile *logfile;
> >> >> > +    rcu_read_lock();
> >> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> >> > +    if (logfile) {
> >> >> > +        qemu_flockfile(logfile->fd);
> >> >> > +        return logfile->fd;
> >> >> > +    } else {
> >> >> > +        rcu_read_unlock();
> >> >>
> >> >> As qemu_log_lock() and unlock should be paired we can drop the unlock
> >> >> here and do an unconditional unlock bellow even if a null fd is passed.
> >> >>
> >> >> Otherwise:
> >> >>
> >> >> Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
> >> >>
> >> >> > +        return NULL;
> >> >> > +    }
> >> >> >  }
> >> >> >
> >> >> >  static inline void qemu_log_unlock(FILE *fd)
> >> >> >  {
> >> >> >      if (fd) {
> >> >> >          qemu_funlockfile(fd);
> >> >> > +        rcu_read_unlock();
> >> >> >      }
> >> >> >  }
> >> >> >
> >> >> > @@ -73,9 +98,14 @@ static inline void qemu_log_unlock(FILE *fd)
> >> >> >  static inline void GCC_FMT_ATTR(1, 0)
> >> >> >  qemu_log_vprintf(const char *fmt, va_list va)
> >> >> >  {
> >> >> > -    if (qemu_logfile) {
> >> >> > -        vfprintf(qemu_logfile, fmt, va);
> >> >> > +    QemuLogFile *logfile;
> >> >> > +
> >> >> > +    rcu_read_lock();
> >> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> >> > +    if (logfile) {
> >> >> > +        vfprintf(logfile->fd, fmt, va);
> >> >> >      }
> >> >> > +    rcu_read_unlock();
> >> >> >  }
> >> >> >
> >> >> >  /* log only if a bit is set on the current loglevel mask:
> >> >> > diff --git a/util/log.c b/util/log.c
> >> >> > index 91ebb5c924..9f9b6b74b7 100644
> >> >> > --- a/util/log.c
> >> >> > +++ b/util/log.c
> >> >> > @@ -28,7 +28,7 @@
> >> >> >
> >> >> >  static char *logfilename;
> >> >> >  static QemuMutex qemu_logfile_mutex;
> >> >> > -FILE *qemu_logfile;
> >> >> > +QemuLogFile *qemu_logfile;
> >> >> >  int qemu_loglevel;
> >> >> >  static int log_append = 0;
> >> >> >  static GArray *debug_regions;
> >> >> > @@ -37,10 +37,14 @@ static GArray *debug_regions;
> >> >> >  int qemu_log(const char *fmt, ...)
> >> >> >  {
> >> >> >      int ret = 0;
> >> >> > -    if (qemu_logfile) {
> >> >> > +    QemuLogFile *logfile;
> >> >> > +
> >> >> > +    rcu_read_lock();
> >> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> >> > +    if (logfile) {
> >> >> >          va_list ap;
> >> >> >          va_start(ap, fmt);
> >> >> > -        ret = vfprintf(qemu_logfile, fmt, ap);
> >> >> > +        ret = vfprintf(logfile->fd, fmt, ap);
> >> >> >          va_end(ap);
> >> >> >
> >> >> >          /* Don't pass back error results.  */
> >> >> > @@ -48,6 +52,7 @@ int qemu_log(const char *fmt, ...)
> >> >> >              ret = 0;
> >> >> >          }
> >> >> >      }
> >> >> > +    rcu_read_unlock();
> >> >> >      return ret;
> >> >> >  }
> >> >> >
> >> >> > @@ -56,12 +61,24 @@ static void __attribute__((__constructor__)) qemu_logfile_init(void)
> >> >> >      qemu_mutex_init(&qemu_logfile_mutex);
> >> >> >  }
> >> >> >
> >> >> > +static void qemu_logfile_free(QemuLogFile *logfile)
> >> >> > +{
> >> >> > +    g_assert(logfile);
> >> >> > +
> >> >> > +    if (logfile->fd != stderr) {
> >> >> > +        fclose(logfile->fd);
> >> >> > +    }
> >> >> > +    g_free(logfile);
> >> >> > +}
> >> >> > +
> >> >> >  static bool log_uses_own_buffers;
> >> >> >
> >> >> >  /* enable or disable low levels log */
> >> >> >  void qemu_set_log(int log_flags)
> >> >> >  {
> >> >> >      bool need_to_open_file = false;
> >> >> > +    QemuLogFile *logfile;
> >> >> > +
> >> >> >      qemu_loglevel = log_flags;
> >> >> >  #ifdef CONFIG_TRACE_LOG
> >> >> >      qemu_loglevel |= LOG_TRACE;
> >> >> > @@ -80,43 +97,47 @@ void qemu_set_log(int log_flags)
> >> >> >      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();
> >> >> > +        logfile = qemu_logfile;
> >> >> > +        atomic_rcu_set(&qemu_logfile, NULL);
> >> >> > +        call_rcu(logfile, qemu_logfile_free, rcu);
> >> >> >      } else if (!qemu_logfile && need_to_open_file) {
> >> >> > +        logfile = g_new0(QemuLogFile, 1);
> >> >> >          if (logfilename) {
> >> >> > -            qemu_logfile = fopen(logfilename, log_append ? "a" : "w");
> >> >> > -            if (!qemu_logfile) {
> >> >> > +            logfile->fd = fopen(logfilename, log_append ? "a" : "w");
> >> >> > +            if (!logfile->fd) {
> >> >> > +                g_free(logfile);
> >> >> >                  perror(logfilename);
> >> >> >                  _exit(1);
> >> >> >              }
> >> >> >              /* In case we are a daemon redirect stderr to logfile */
> >> >> >              if (is_daemonized()) {
> >> >> > -                dup2(fileno(qemu_logfile), STDERR_FILENO);
> >> >> > -                fclose(qemu_logfile);
> >> >> > +                dup2(fileno(logfile->fd), STDERR_FILENO);
> >> >> > +                fclose(logfile->fd);
> >> >> >                  /* This will skip closing logfile in qemu_log_close() */
> >> >> > -                qemu_logfile = stderr;
> >> >> > +                logfile->fd = stderr;
> >> >> >              }
> >> >> >          } else {
> >> >> >              /* Default to stderr if no log file specified */
> >> >> >              assert(!is_daemonized());
> >> >> > -            qemu_logfile = stderr;
> >> >> > +            logfile->fd = stderr;
> >> >> >          }
> >> >> >          /* must avoid mmap() usage of glibc by setting a buffer "by hand" */
> >> >> >          if (log_uses_own_buffers) {
> >> >> >              static char logfile_buf[4096];
> >> >> >
> >> >> > -            setvbuf(qemu_logfile, logfile_buf, _IOLBF, sizeof(logfile_buf));
> >> >> > +            setvbuf(logfile->fd, logfile_buf, _IOLBF, sizeof(logfile_buf));
> >> >> >          } else {
> >> >> >  #if defined(_WIN32)
> >> >> >              /* Win32 doesn't support line-buffering, so use unbuffered output. */
> >> >> > -            setvbuf(qemu_logfile, NULL, _IONBF, 0);
> >> >> > +            setvbuf(logfile->fd, NULL, _IONBF, 0);
> >> >> >  #else
> >> >> > -            setvbuf(qemu_logfile, NULL, _IOLBF, 0);
> >> >> > +            setvbuf(logfile->fd, NULL, _IOLBF, 0);
> >> >> >  #endif
> >> >> >              log_append = 1;
> >> >> >          }
> >> >> > -        qemu_mutex_unlock(&qemu_logfile_mutex);
> >> >> > +        atomic_rcu_set(&qemu_logfile, logfile);
> >> >> >      }
> >> >> > +    qemu_mutex_unlock(&qemu_logfile_mutex);
> >> >> >  }
> >> >> >
> >> >> >  void qemu_log_needs_buffers(void)
> >> >> > @@ -245,19 +266,28 @@ out:
> >> >> >  /* fflush() the log file */
> >> >> >  void qemu_log_flush(void)
> >> >> >  {
> >> >> > -    fflush(qemu_logfile);
> >> >> > +    QemuLogFile *logfile;
> >> >> > +
> >> >> > +    rcu_read_lock();
> >> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> >> > +    if (logfile) {
> >> >> > +        fflush(logfile->fd);
> >> >> > +    }
> >> >> > +    rcu_read_unlock();
> >> >> >  }
> >> >> >
> >> >> >  /* Close the log file */
> >> >> >  void qemu_log_close(void)
> >> >> >  {
> >> >> > +    QemuLogFile *logfile;
> >> >> > +
> >> >> >      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;
> >> >> > +    logfile = qemu_logfile;
> >> >> > +
> >> >> > +    if (logfile) {
> >> >> > +        atomic_rcu_set(&qemu_logfile, NULL);
> >> >> > +        call_rcu(logfile, qemu_logfile_free, rcu);
> >> >> >      }
> >> >> >      qemu_mutex_unlock(&qemu_logfile_mutex);
> >> >> >  }
> >> >> >  diff --git a/include/exec/log.h b/include/exec/log.h
> >> >> > index e2cfd436e6..9bd1e4aa20 100644
> >> >> > --- a/include/exec/log.h
> >> >> > +++ b/include/exec/log.h
> >> >> > @@ -15,8 +15,15 @@
> >> >> >   */
> >> >> >  static inline void log_cpu_state(CPUState *cpu, int flags)
> >> >> >  {
> >> >> > +    QemuLogFile *logfile;
> >> >> > +
> >> >> >      if (qemu_log_enabled()) {
> >> >> > -        cpu_dump_state(cpu, qemu_logfile, flags);
> >> >> > +        rcu_read_lock();
> >> >> > +        logfile = atomic_rcu_read(&qemu_logfile);
> >> >> > +        if (logfile) {
> >> >> > +            cpu_dump_state(cpu, logfile->fd, flags);
> >> >> > +        }
> >> >> > +        rcu_read_unlock();
> >> >> >      }
> >> >> >  }
> >> >> >
> >> >> > @@ -40,19 +47,37 @@ static inline void log_cpu_state_mask(int mask, CPUState *cpu, int flags)
> >> >> >  static inline void log_target_disas(CPUState *cpu, target_ulong start,
> >> >> >                                      target_ulong len)
> >> >> >  {
> >> >> > -    target_disas(qemu_logfile, cpu, start, len);
> >> >> > +    QemuLogFile *logfile;
> >> >> > +    rcu_read_lock();
> >> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> >> > +    if (logfile) {
> >> >> > +        target_disas(logfile->fd, cpu, start, len);
> >> >> > +    }
> >> >> > +    rcu_read_unlock();
> >> >> >  }
> >> >> >
> >> >> >  static inline void log_disas(void *code, unsigned long size)
> >> >> >  {
> >> >> > -    disas(qemu_logfile, code, size);
> >> >> > +    QemuLogFile *logfile;
> >> >> > +    rcu_read_lock();
> >> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> >> > +    if (logfile) {
> >> >> > +        disas(logfile->fd, code, size);
> >> >> > +    }
> >> >> > +    rcu_read_unlock();
> >> >> >  }
> >> >> >
> >> >> >  #if defined(CONFIG_USER_ONLY)
> >> >> >  /* page_dump() output to the log file: */
> >> >> >  static inline void log_page_dump(void)
> >> >> >  {
> >> >> > -    page_dump(qemu_logfile);
> >> >> > +    QemuLogFile *logfile;
> >> >> > +    rcu_read_lock();
> >> >> > +    logfile = atomic_rcu_read(&qemu_logfile);
> >> >> > +    if (logfile) {
> >> >> > +        page_dump(logfile->fd);
> >> >> > +    }
> >> >> > +    rcu_read_unlock();
> >> >> >  }
> >> >> >  #endif
> >> >> >  #endif
> >> >> > diff --git a/tcg/tcg.c b/tcg/tcg.c
> >> >> > index 0511266d85..4f616ba38b 100644
> >> >> > --- a/tcg/tcg.c
> >> >> > +++ b/tcg/tcg.c
> >> >> > @@ -2114,9 +2114,17 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
> >> >> >          }
> >> >> >
> >> >> >          if (have_prefs || op->life) {
> >> >> > -            for (; col < 40; ++col) {
> >> >> > -                putc(' ', qemu_logfile);
> >> >> > +
> >> >> > +            QemuLogFile *logfile;
> >> >> > +
> >> >> > +            rcu_read_lock();
> >> >> > +            logfile = atomic_rcu_read(&qemu_logfile);
> >> >> > +            if (logfile) {
> >> >> > +                for (; col < 40; ++col) {
> >> >> > +                    putc(' ', logfile->fd);
> >> >> > +                }
> >> >> >              }
> >> >> > +            rcu_read_unlock();
> >> >> >          }
> >> >> >
> >> >> >          if (op->life) {
> >> >>
> >> >>
> >> >> --
> >> >> Alex Bennée
> >>
> >>
> >> --
> >> Alex Bennée
>
>
> --
> Alex Bennée

[PATCH v2 6/6] Added tests for close and change of logfile.

[Robert Foley]

One test ensures that the logfile handle is still valid even if
the logfile is changed during logging.
The other test validates that the logfile handle remains valid under
the logfile lock even if the logfile is closed.

Signed-off-by: Robert Foley <robert.foley@linaro.org>
Reviewed-by: Alex Bennée <alex.bennee@linaro.org>

---
v1
    - Changes for first round of code review comments.
    - Added in use of g_autofree, removed the g_free()s.
    - Added in use of logfile2 and changed sequence of asserts.
---
 tests/test-logging.c | 80 ++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 80 insertions(+)

diff --git a/tests/test-logging.c b/tests/test-logging.c
index a12585f70a..1e646f045d 100644
--- a/tests/test-logging.c
+++ b/tests/test-logging.c
@@ -108,6 +108,82 @@ static void test_parse_path(gconstpointer data)
     error_free_or_abort(&err);
 }
 
+static void test_logfile_write(gconstpointer data)
+{
+    QemuLogFile *logfile;
+    QemuLogFile *logfile2;
+    gchar const *dir = data;
+    Error *err = NULL;
+    g_autofree gchar *file_path;
+    g_autofree gchar *file_path1;
+    FILE *orig_fd;
+
+    /*
+     * Before starting test, set log flags, to ensure the file gets
+     * opened below with the call to qemu_set_log_filename().
+     * In cases where a logging backend other than log is used,
+     * this is needed.
+     */
+    qemu_set_log(CPU_LOG_TB_OUT_ASM);
+    file_path = g_build_filename(dir, "qemu_test_log_write0.log", NULL);
+    file_path1 = g_build_filename(dir, "qemu_test_log_write1.log", NULL);
+
+    /*
+     * Test that even if an open file handle is changed,
+     * our handle remains valid due to RCU.
+     */
+    qemu_set_log_filename(file_path, &err);
+    g_assert(!err);
+    rcu_read_lock();
+    logfile = atomic_rcu_read(&qemu_logfile);
+    orig_fd = logfile->fd;
+    g_assert(logfile && logfile->fd);
+    fprintf(logfile->fd, "%s 1st write to file\n", __func__);
+    fflush(logfile->fd);
+
+    /* Change the logfile and ensure that the handle is still valid. */
+    qemu_set_log_filename(file_path1, &err);
+    g_assert(!err);
+    logfile2 = atomic_rcu_read(&qemu_logfile);
+    g_assert(logfile->fd == orig_fd);
+    g_assert(logfile2->fd != logfile->fd);
+    fprintf(logfile->fd, "%s 2nd write to file\n", __func__);
+    fflush(logfile->fd);
+    rcu_read_unlock();
+}
+
+static void test_logfile_lock(gconstpointer data)
+{
+    FILE *logfile;
+    gchar const *dir = data;
+    Error *err = NULL;
+    g_autofree gchar *file_path;
+
+    file_path = g_build_filename(dir, "qemu_test_logfile_lock0.log", NULL);
+
+    /*
+     * Test the use of the logfile lock, such
+     * that even if an open file handle is closed,
+     * our handle remains valid for use due to RCU.
+     */
+    qemu_set_log_filename(file_path, &err);
+    logfile = qemu_log_lock();
+    g_assert(logfile);
+    fprintf(logfile, "%s 1st write to file\n", __func__);
+    fflush(logfile);
+
+    /*
+     * Initiate a close file and make sure our handle remains
+     * valid since we still have the logfile lock.
+     */
+    qemu_log_close();
+    fprintf(logfile, "%s 2nd write to file\n", __func__);
+    fflush(logfile);
+    qemu_log_unlock(logfile);
+
+    g_assert(!err);
+}
+
 /* Remove a directory and all its entries (non-recursive). */
 static void rmdir_full(gchar const *root)
 {
@@ -134,6 +210,10 @@ int main(int argc, char **argv)
 
     g_test_add_func("/logging/parse_range", test_parse_range);
     g_test_add_data_func("/logging/parse_path", tmp_path, test_parse_path);
+    g_test_add_data_func("/logging/logfile_write_path",
+                         tmp_path, test_logfile_write);
+    g_test_add_data_func("/logging/logfile_lock_path",
+                         tmp_path, test_logfile_lock);
 
     rc = g_test_run();
 
-- 
2.17.1