[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: [PATCH 2/4] Add use of RCU for qemu_logfile.
From: |
Alex Bennée |
Subject: |
Re: [PATCH 2/4] Add use of RCU for qemu_logfile. |
Date: |
Thu, 07 Nov 2019 16:23:59 +0000 |
User-agent: |
mu4e 1.3.5; emacs 27.0.50 |
Robert Foley <address@hidden> 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 <address@hidden>
> ---
> include/qemu/log.h | 47 ++++++++++++++++++++++++----
> util/log.c | 78 ++++++++++++++++++++++++++++++++++------------
> include/exec/log.h | 33 +++++++++++++++++---
> tcg/tcg.c | 12 +++++--
> 4 files changed, 138 insertions(+), 32 deletions(-)
>
> diff --git a/include/qemu/log.h b/include/qemu/log.h
> index a91105b2ad..975de18e23 100644
> --- a/include/qemu/log.h
> +++ b/include/qemu/log.h
> @@ -3,9 +3,17 @@
>
> /* A small part of this API is split into its own header */
> #include "qemu/log-for-trace.h"
> +#include "qemu/rcu.h"
> +
> +struct QemuLogFile {
> + struct rcu_head rcu;
> + FILE *fd;
> +};
> +typedef struct QemuLogFile QemuLogFile;
If you are declaring a typedef then do it in one:
typedef struct QemuLogFile { ...
We only really use the second form for opaque structs where the handle
is passed around but the contents hidden from the rest of QEMU.
>
> /* Private global variable, don't use */
> -extern FILE *qemu_logfile;
> +extern QemuLogFile *qemu_logfile;
> +
Do we need multiple
>
> /*
> * The new API:
> @@ -25,7 +33,17 @@ static inline bool qemu_log_enabled(void)
> */
> static inline bool qemu_log_separate(void)
> {
> - return qemu_logfile != NULL && qemu_logfile != stderr;
> + QemuLogFile *logfile;
> +
> + if (qemu_log_enabled()) {
> + rcu_read_lock();
> + logfile = atomic_rcu_read(&qemu_logfile);
> + if (logfile && logfile->fd != stderr) {
> + return true;
> + }
> + rcu_read_unlock();
> + }
> + return false;
This is unbalanced as you'll have incremented the reader count. Also
qemu_log_enabled() is also synonymous with logfile existing so you could
fold that into:
bool res = false;
rcu_read_lock();
*logfile = atomic_rcu_read(&qemu_logfile);
if (logfile && logfile->fd != stderr) {
res = true;
}
rcu_read_unlock();
return res;
There is technically a race there as the answer may become invalid after
qemu_log_separate() returns. However given the users I don't see what
could fail afterwards.
> }
>
> #define CPU_LOG_TB_OUT_ASM (1 << 0)
> @@ -55,12 +73,23 @@ static inline bool qemu_log_separate(void)
>
> static inline void qemu_log_lock(void)
> {
> - qemu_flockfile(qemu_logfile);
> + QemuLogFile *logfile;
> + rcu_read_lock();
> + logfile = atomic_rcu_read(&qemu_logfile);
> + if (logfile) {
> + qemu_flockfile(logfile->fd);
> + }
> + rcu_read_unlock();
> }
static inline FILE *fd qemu_log_lock(void)
{
FILE *fd;
rcu_read_lock();
fd = atomic_rcu_read(&qemu_logfile);
if (fd) {
qemu_flockfile(fd);
return fd;
} else {
rcu_read_unlock();
return NULL;
}
}
static inline qemu_log_unlock(FILE *fd)
{
if (fd) {
qemu_funlockfile(fd);
rcu_read_unlock();
}
}
While the rcu_read_lock() is in progress then we won't ever finish with
the fd - which we don't want to do until the file locking is finished.
<snip>
>
> /* Logging functions: */
> @@ -70,9 +99,14 @@ static inline void qemu_log_unlock(void)
> 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:
> @@ -129,5 +163,6 @@ void qemu_print_log_usage(FILE *f);
> void qemu_log_flush(void);
> /* Close the log file */
> void qemu_log_close(void);
> +void qemu_logfile_free(QemuLogFile *logfile);
>
> #endif
> diff --git a/util/log.c b/util/log.c
> index dff2f98c8c..d409532b8f 100644
> --- a/util/log.c
> +++ b/util/log.c
> @@ -29,7 +29,7 @@
> static char *logfilename;
> static bool qemu_logfile_initialized;
> static QemuMutex qemu_logfile_mutex;
> -FILE *qemu_logfile;
> +QemuLogFile *qemu_logfile;
> int qemu_loglevel;
> static int log_append = 0;
> static GArray *debug_regions;
> @@ -38,10 +38,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. */
> @@ -49,6 +53,7 @@ int qemu_log(const char *fmt, ...)
> ret = 0;
> }
> }
> + rcu_read_unlock();
> return ret;
> }
>
> @@ -65,6 +70,8 @@ static bool log_uses_own_buffers;
> /* enable or disable low levels log */
> void qemu_set_log(int log_flags)
> {
> + QemuLogFile *logfile;
> +
> qemu_loglevel = log_flags;
> #ifdef CONFIG_TRACE_LOG
> qemu_loglevel |= LOG_TRACE;
> @@ -77,43 +84,51 @@ void qemu_set_log(int log_flags)
> qemu_mutex_lock(&qemu_logfile_mutex);
> if (!qemu_logfile &&
> (is_daemonized() ? logfilename != NULL : qemu_loglevel)) {
> + logfile = g_new0(QemuLogFile, 1);
> if (logfilename) {
You can assume logfilename exists as glib memory allocations would
abort() otherwise.
> - 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;
> }
> + atomic_rcu_set(&qemu_logfile, logfile);
> }
> - qemu_mutex_unlock(&qemu_logfile_mutex);
> + logfile = qemu_logfile;
> +
> if (qemu_logfile &&
> (is_daemonized() ? logfilename == NULL : !qemu_loglevel)) {
> - qemu_log_close();
> + atomic_rcu_set(&qemu_logfile, NULL);
> + qemu_mutex_unlock(&qemu_logfile_mutex);
> + call_rcu(logfile, qemu_logfile_free, rcu);
> + } else {
> + qemu_mutex_unlock(&qemu_logfile_mutex);
> }
> }
>
> @@ -247,17 +262,40 @@ 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();
> +}
> +
> +void qemu_logfile_free(QemuLogFile *logfile)
This can be static as it's internal to log.c
> +{
> + if (logfile) {
g_assert(logfile) instead of the if?
> + if (logfile->fd != stderr) {
> + fclose(logfile->fd);
> + }
> + g_free(logfile);
> + }
> }
>
> /* Close the log file */
> void qemu_log_close(void)
> {
> - if (qemu_logfile) {
> - if (qemu_logfile != stderr) {
> - fclose(qemu_logfile);
> - }
> - qemu_logfile = NULL;
> + QemuLogFile *logfile;
> +
> + qemu_mutex_lock(&qemu_logfile_mutex);
> + logfile = qemu_logfile;
> +
> + if (logfile) {
> + atomic_rcu_set(&qemu_logfile, NULL);
> + qemu_mutex_unlock(&qemu_logfile_mutex);
I think you can move the both the unlocks out of the if/else and drop
the else.
> + call_rcu(logfile, qemu_logfile_free, rcu);
> + } else {
> + 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 5475d49ed1..220eaac7c7 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);
This can probably be a qemu_log_lock() instead given interleaving output
is going to be confusing.
> + if (logfile) {
> + for (; col < 40; ++col) {
> + putc(' ', logfile->fd);
> + }
> }
> + rcu_read_unlock();
and qemu_log_unlock();
This cleanup could even be in a separate patch.
> }
>
> if (op->life) {
--
Alex Bennée
[PATCH 3/4] qemu_log_lock/unlock now preserves the qemu_logfile handle., Robert Foley, 2019/11/07