From fc59d2d870caddf5cd9c85836ee4a8c59ffe7617 Mon Sep 17 00:00:00 2001 From: Robert Foley Date: Mon, 18 Nov 2019 16:15:26 -0500 Subject: qemu_log_lock/unlock now preserves the qemu_logfile handle. 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. Also in target/tilegx/translate.c removed the qemu_log_lock()/unlock() calls (and the log("\n")), since the translator can longjmp out of the loop if it attempts to translate an instruction in an inaccessible page. Signed-off-by: Robert Foley Reviewed-by: Alex Bennée Reviewed-by: Richard Henderson Signed-off-by: Alex Bennée Message-Id: <20191118211528.3221-5-robert.foley@linaro.org> --- include/qemu/log.h | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) (limited to 'include') 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: */ -- cgit v1.2.3-55-g7522 From 7606488c0efa8f631d31ab9ff8d33b7cf3e2a4c9 Mon Sep 17 00:00:00 2001 From: Robert Foley Date: Mon, 18 Nov 2019 16:15:27 -0500 Subject: Add use of RCU for qemu_logfile. 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 Reviewed-by: Alex Bennée Signed-off-by: Alex Bennée Message-Id: <20191118211528.3221-6-robert.foley@linaro.org> --- include/exec/log.h | 33 ++++++++++++++++++++++--- include/qemu/log.h | 41 ++++++++++++++++++++++++++----- tcg/tcg.c | 12 +++++++-- util/log.c | 72 ++++++++++++++++++++++++++++++++++++++---------------- 4 files changed, 125 insertions(+), 33 deletions(-) (limited to 'include') 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/include/qemu/log.h b/include/qemu/log.h index a7c5b01571..e0f4e40628 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,8 +71,15 @@ 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 { + return NULL; + } } static inline void qemu_log_unlock(FILE *fd) @@ -64,6 +87,7 @@ static inline void qemu_log_unlock(FILE *fd) if (fd) { qemu_funlockfile(fd); } + rcu_read_unlock(); } /* Logging functions: */ @@ -73,9 +97,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/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) { diff --git a/util/log.c b/util/log.c index 953a66b5a8..867264da8d 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; @@ -79,43 +96,47 @@ void qemu_set_log(int log_flags) } 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) @@ -244,18 +265,27 @@ 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; + 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); } -- cgit v1.2.3-55-g7522 From 10d0d505de750590c21a78c0652bf5a9c142302a Mon Sep 17 00:00:00 2001 From: Alex Bennée Date: Thu, 5 Dec 2019 12:25:15 +0000 Subject: linux-user: log page table changes under -d page The CPU_LOG_PAGE flag is woefully underused and could stand to do extra duty tracking page changes. If the user doesn't want to see the details as things change they still have the tracepoints available. We push the locking into log_page_dump and pass a reason for the banner text. Signed-off-by: Alex Bennée Reviewed-by: Richard Henderson Reviewed-by: Laurent Vivier Message-Id: <20191205122518.10010-5-alex.bennee@linaro.org> --- bsd-user/main.c | 2 +- include/exec/log.h | 11 +++++------ linux-user/main.c | 2 +- linux-user/mmap.c | 8 ++++---- 4 files changed, 11 insertions(+), 12 deletions(-) (limited to 'include') diff --git a/bsd-user/main.c b/bsd-user/main.c index 470a8bf79e..7f4e3cd627 100644 --- a/bsd-user/main.c +++ b/bsd-user/main.c @@ -963,7 +963,7 @@ int main(int argc, char **argv) if (qemu_loglevel_mask(CPU_LOG_PAGE)) { qemu_log("guest_base 0x%lx\n", guest_base); - log_page_dump(); + log_page_dump("binary load"); qemu_log("start_brk 0x" TARGET_ABI_FMT_lx "\n", info->start_brk); qemu_log("end_code 0x" TARGET_ABI_FMT_lx "\n", info->end_code); diff --git a/include/exec/log.h b/include/exec/log.h index 9bd1e4aa20..fcc7b9e00b 100644 --- a/include/exec/log.h +++ b/include/exec/log.h @@ -69,15 +69,14 @@ static inline void log_disas(void *code, unsigned long size) #if defined(CONFIG_USER_ONLY) /* page_dump() output to the log file: */ -static inline void log_page_dump(void) +static inline void log_page_dump(const char *operation) { - QemuLogFile *logfile; - rcu_read_lock(); - logfile = atomic_rcu_read(&qemu_logfile); + FILE *logfile = qemu_log_lock(); if (logfile) { - page_dump(logfile->fd); + qemu_log("page layout changed following %s\n", operation); + page_dump(logfile); } - rcu_read_unlock(); + qemu_log_unlock(logfile); } #endif #endif diff --git a/linux-user/main.c b/linux-user/main.c index 6ff7851e86..8718d03ee2 100644 --- a/linux-user/main.c +++ b/linux-user/main.c @@ -826,7 +826,7 @@ int main(int argc, char **argv, char **envp) if (qemu_loglevel_mask(CPU_LOG_PAGE)) { qemu_log("guest_base 0x%lx\n", guest_base); - log_page_dump(); + log_page_dump("binary load"); qemu_log("start_brk 0x" TARGET_ABI_FMT_lx "\n", info->start_brk); qemu_log("end_code 0x" TARGET_ABI_FMT_lx "\n", info->end_code); diff --git a/linux-user/mmap.c b/linux-user/mmap.c index 0b1b43ac3c..3d90fa459c 100644 --- a/linux-user/mmap.c +++ b/linux-user/mmap.c @@ -18,6 +18,7 @@ */ #include "qemu/osdep.h" #include "trace.h" +#include "exec/log.h" #include "qemu.h" //#define DEBUG_MMAP @@ -539,10 +540,9 @@ abi_long target_mmap(abi_ulong start, abi_ulong len, int prot, page_set_flags(start, start + len, prot | PAGE_VALID); the_end: trace_target_mmap_complete(start); -#ifdef DEBUG_MMAP - page_dump(stdout); - printf("\n"); -#endif + if (qemu_loglevel_mask(CPU_LOG_PAGE)) { + log_page_dump(__func__); + } tb_invalidate_phys_range(start, start + len); mmap_unlock(); return start; -- cgit v1.2.3-55-g7522