[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: [PATCH v2 39/39] util/log: Support per-thread log files
From: |
Alex Bennée |
Subject: |
Re: [PATCH v2 39/39] util/log: Support per-thread log files |
Date: |
Thu, 14 Apr 2022 16:35:02 +0100 |
User-agent: |
mu4e 1.7.12; emacs 28.1.50 |
Richard Henderson <richard.henderson@linaro.org> writes:
> Add a new log flag, tid, to turn this feature on.
> Require the log filename to be set, and to contain %d.
>
> Do not allow tid to be turned off once it is on, nor let
> the filename be change thereafter. This avoids the need
> for signalling each thread to re-open on a name change.
>
> Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
> ---
> v2: Make use of CONFIG_GETTID, and fallback to SYS_gettid.
> ---
> include/qemu/log.h | 1 +
> util/log.c | 149 ++++++++++++++++++++++++++++++++++-----------
> 2 files changed, 115 insertions(+), 35 deletions(-)
>
> diff --git a/include/qemu/log.h b/include/qemu/log.h
> index a325bca661..c5643d8dd5 100644
> --- a/include/qemu/log.h
> +++ b/include/qemu/log.h
> @@ -34,6 +34,7 @@ bool qemu_log_separate(void);
> #define CPU_LOG_PLUGIN (1 << 18)
> /* LOG_STRACE is used for user-mode strace logging. */
> #define LOG_STRACE (1 << 19)
> +#define LOG_PER_THREAD (1 << 20)
>
> /* Lock/unlock output. */
>
> diff --git a/util/log.c b/util/log.c
> index df0710720f..0bb2233788 100644
> --- a/util/log.c
> +++ b/util/log.c
> @@ -27,6 +27,9 @@
> #include "qemu/thread.h"
> #include "qemu/lockable.h"
> #include "qemu/rcu.h"
> +#ifdef CONFIG_LINUX
> +#include <sys/syscall.h>
> +#endif
>
>
> typedef struct RCUCloseFILE {
> @@ -38,22 +41,36 @@ typedef struct RCUCloseFILE {
> static QemuMutex global_mutex;
> static char *global_filename;
> static FILE *global_file;
> +static __thread FILE *thread_file;
>
> int qemu_loglevel;
> -static int log_append = 0;
> +static bool log_append;
> +static bool log_per_thread;
> static GArray *debug_regions;
>
> /* Returns true if qemu_log() will really write somewhere. */
> bool qemu_log_enabled(void)
> {
> - return qatomic_read(&global_file) != NULL;
> + return log_per_thread || qatomic_read(&global_file) != NULL;
> }
>
> /* Returns true if qemu_log() will write somewhere other than stderr. */
> bool qemu_log_separate(void)
> {
> FILE *logfile = qatomic_read(&global_file);
> - return logfile && logfile != stderr;
> + return log_per_thread || (logfile && logfile != stderr);
> +}
> +
> +static int log_thread_id(void)
> +{
> +#ifdef CONFIG_GETTID
> + return gettid();
> +#elif defined(SYS_gettid)
> + return syscall(SYS_gettid);
> +#else
> + static int counter;
> + return qatomic_fetch_inc(&counter);
> +#endif
> }
>
> /* Lock/unlock output. */
> @@ -62,20 +79,34 @@ FILE *qemu_log_trylock(void)
> {
> FILE *logfile;
>
> - rcu_read_lock();
> - /*
> - * FIXME: typeof_strip_qual, as used by qatomic_rcu_read,
> - * does not work with pointers to undefined structures,
> - * such as we have with struct _IO_FILE and musl libc.
> - * Since all we want is a read of a pointer, cast to void**,
> - * which does work with typeof_strip_qual.
> - */
> - logfile = qatomic_rcu_read((void **)&global_file);
> - if (logfile) {
> - qemu_flockfile(logfile);
> - } else {
> - rcu_read_unlock();
> + logfile = thread_file;
> + if (!logfile) {
> + if (log_per_thread) {
> + g_autofree char *filename
> + = g_strdup_printf(global_filename, log_thread_id());
> + logfile = fopen(filename, "w");
> + if (!logfile) {
> + return NULL;
> + }
> + thread_file = logfile;
> + } else {
> + rcu_read_lock();
> + /*
> + * FIXME: typeof_strip_qual, as used by qatomic_rcu_read,
> + * does not work with pointers to undefined structures,
> + * such as we have with struct _IO_FILE and musl libc.
> + * Since all we want is a read of a pointer, cast to void**,
> + * which does work with typeof_strip_qual.
> + */
> + logfile = qatomic_rcu_read((void **)&global_file);
> + if (!logfile) {
> + rcu_read_unlock();
> + return NULL;
> + }
> + }
> }
> +
> + qemu_flockfile(logfile);
> return logfile;
> }
>
> @@ -84,7 +115,9 @@ void qemu_log_unlock(FILE *logfile)
> if (logfile) {
> fflush(logfile);
> qemu_funlockfile(logfile);
> - rcu_read_unlock();
> + if (!log_per_thread) {
> + rcu_read_unlock();
> + }
> }
> }
>
> @@ -112,40 +145,74 @@ static void rcu_close_file(RCUCloseFILE *r)
> g_free(r);
> }
>
> +/**
> + * valid_filename_template:
> + *
> + * Validate the filename template. Require %d if per_thread, allow it
> + * otherwise; require no other % within the template.
> + * Return 0 if invalid, 1 if stderr, 2 if strdup, 3 if pid printf.
>From a neatness point of view having an enum would make it easier to
read in the switch down bellow...
> + */
> +static int valid_filename_template(const char *filename,
> + bool per_thread, Error **errp)
> +{
> + if (filename) {
> + char *pidstr = strstr(filename, "%");
> +
> + if (pidstr) {
> + /* We only accept one %d, no other format strings */
> + if (pidstr[1] != 'd' || strchr(pidstr + 2, '%')) {
> + error_setg(errp, "Bad logfile template: %s", filename);
> + return 0;
> + }
> + return per_thread ? 2 : 3;
> + }
> + }
> + if (per_thread) {
> + error_setg(errp, "Filename template with '%%d' required for 'tid'");
> + return 0;
> + }
> + return filename ? 2 : 1;
> +}
> +
> /* enable or disable low levels log */
> static bool qemu_set_log_internal(const char *filename, bool changed_name,
> int log_flags, Error **errp)
> {
> bool need_to_open_file;
> bool daemonized;
> + bool per_thread;
> FILE *logfile;
>
> QEMU_LOCK_GUARD(&global_mutex);
> logfile = global_file;
>
> + per_thread = log_flags & LOG_PER_THREAD;
> +
> if (changed_name) {
> char *newname = NULL;
>
> /*
> - * Allow the user to include %d in their logfile which will be
> - * substituted with the current PID. This is useful for debugging
> many
> - * nested linux-user tasks but will result in lots of logs.
> - *
> - * filename may be NULL. In that case, log output is sent to stderr
> + * Once threads start opening their own log files, we have no
> + * easy mechanism to tell them all to close and re-open.
> + * There seems little cause to do so either -- this option
> + * will most often be used at user-only startup.
> */
> - if (filename) {
> - char *pidstr = strstr(filename, "%");
> + if (log_per_thread) {
> + error_setg(errp, "Cannot change log filename after setting
> 'tid'");
> + return false;
> + }
>
> - if (pidstr) {
> - /* We only accept one %d, no other format strings */
> - if (pidstr[1] != 'd' || strchr(pidstr + 2, '%')) {
> - error_setg(errp, "Bad logfile format: %s", filename);
> - return false;
> - }
> - newname = g_strdup_printf(filename, getpid());
> - } else {
> - newname = g_strdup(filename);
> - }
> + switch (valid_filename_template(filename, per_thread, errp)) {
> + case 0:
> + return false; /* error */
> + case 1:
> + break; /* stderr */
> + case 2:
> + newname = g_strdup(filename);
> + break;
> + case 3:
> + newname = g_strdup_printf(filename, getpid());
> + break;
default: g_assert_not_reached?
> }
>
> g_free(global_filename);
> @@ -153,8 +220,17 @@ static bool qemu_set_log_internal(const char *filename,
> bool changed_name,
> filename = newname;
> } else {
> filename = global_filename;
> + if (per_thread && !valid_filename_template(filename, true, errp)) {
> + return false; /* error */
> + }
> }
>
> + /* Once the per-thread flag is set, it cannot be unset. */
> + if (per_thread) {
> + log_per_thread = true;
> + }
> + /* The flag itself is not relevant for need_to_open_file. */
> + log_flags &= ~LOG_PER_THREAD;
> #ifdef CONFIG_TRACE_LOG
> log_flags |= LOG_TRACE;
> #endif
> @@ -163,12 +239,13 @@ static bool qemu_set_log_internal(const char *filename,
> bool changed_name,
> /*
> * In all cases we only log if qemu_loglevel is set.
> * Also:
> + * If per-thread, open the file for each thread in qemu_log_lock.
> * If not daemonized we will always log either to stderr
> * or to a file (if there is a filename).
> * If we are daemonized, we will only log if there is a filename.
> */
> daemonized = is_daemonized();
> - need_to_open_file = log_flags && (!daemonized || filename);
> + need_to_open_file = log_flags && !per_thread && (!daemonized ||
> filename);
>
> if (logfile && (!need_to_open_file || changed_name)) {
> qatomic_rcu_set(&global_file, NULL);
> @@ -354,6 +431,8 @@ const QEMULogItem qemu_log_items[] = {
> #endif
> { LOG_STRACE, "strace",
> "log every user-mode syscall, its input, and its result" },
> + { LOG_PER_THREAD, "tid",
> + "open a separate log file per thread; filename must contain '%d'" },
> { 0, NULL, NULL },
> };
Otherwise:
Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
--
Alex Bennée
- Re: [PATCH v2 39/39] util/log: Support per-thread log files,
Alex Bennée <=