All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH v3 00/39] Logging cleanup and per-thread logfiles
@ 2022-04-17 18:29 Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 01/39] util/log: Drop manual log buffering Richard Henderson
                   ` (38 more replies)
  0 siblings, 39 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Most of the changes here reduce the amount of locking involved
in logging, due to repeated qemu_log calls, each of which takes
and releases the rcu_read_lock.

This makes more use of qemu_log_lock/unlock around code blocks,
which both keeps the output together in the face of threads and
also plays the rcu_read_lock game only once for the block.

Finally, add a -d tid option to open per-thread logfiles.
This can be extremely helpful in debugging user-only threads.

Changes for v3:
  * Updates for review:
    - use 0x%x
    - use enum for valid_filename_template

Changes for v2:
  * Rename qemu_log_lock to qemu_log_trylock to emphasize that
    the call is not guaranteed to succeed.
  * Work around a musl compilation error, caused by our own
    typeof_strip_qual macro not working with incomplete structs.
  * Use CONFIG_GETTID properly.

Patches lacking review:
  24-include-exec-log-Do-not-reference-QemuLogFile-dir.patch
  27-util-log-Introduce-qemu_set_log_filename_flags.patch


r~


Richard Henderson (39):
  util/log: Drop manual log buffering
  target/hexagon: Remove qemu_set_log in hexagon_translate_init
  util/log: Return bool from qemu_set_log_filename
  util/log: Pass Error pointer to qemu_set_log
  os-posix: Use qemu_log_enabled
  util/log: Move qemu_log_lock, qemu_log_unlock out of line
  util/log: Rename qemu_log_lock to qemu_log_trylock
  hw/xen: Split out xen_pv_output_msg
  *: Use fprintf between qemu_log_trylock/unlock
  util/log: Remove qemu_log_vprintf
  tcg: Pass the locked filepointer to tcg_dump_ops
  exec/translator: Pass the locked filepointer to disas_log hook
  exec/log: Remove log_disas and log_target_disas
  accel/tcg: Use cpu_dump_state between qemu_log_trylock/unlock
  target/nios2: Remove log_cpu_state from reset
  util/log: Use qemu_log_trylock/unlock in qemu_log
  util/log: Drop return value from qemu_log
  util/log: Mark qemu_log_trylock as G_GNUC_WARN_UNUSED_RESULT
  util/log: Remove qemu_log_flush
  util/log: Drop call to setvbuf
  bsd-user: Expand log_page_dump inline
  linux-user: Expand log_page_dump inline
  tests/unit: Do not reference QemuLogFile directly
  include/exec/log: Do not reference QemuLogFile directly
  include/qemu/log: Move entire implementation out-of-line
  sysemu/os-win32: Test for and use _lock_file/_unlock_file
  util/log: Introduce qemu_set_log_filename_flags
  bsd-user: Use qemu_set_log_filename_flags
  linux-user: Use qemu_set_log_filename_flags
  softmmu: Use qemu_set_log_filename_flags
  util/log: Remove qemu_log_close
  util/log: Rename logfilename to global_filename
  util/log: Rename qemu_logfile to global_file
  util/log: Rename qemu_logfile_mutex to global_mutex
  util/log: Hoist the eval of is_daemonized in qemu_set_log_internal
  util/log: Combine two logfile closes
  util/log: Rename QemuLogFile to RCUCloseFILE
  util/log: Limit RCUCloseFILE to file closing
  util/log: Support per-thread log files

 meson.build                          |  12 +
 include/exec/log.h                   |  52 +---
 include/exec/translator.h            |   2 +-
 include/qemu/log-for-trace.h         |   2 +-
 include/qemu/log.h                   |  93 +------
 include/sysemu/os-win32.h            |  16 +-
 accel/tcg/cpu-exec.c                 |  18 +-
 accel/tcg/translate-all.c            | 118 +++++----
 accel/tcg/translator.c               |  12 +-
 bsd-user/main.c                      |  54 ++--
 cpu.c                                |  16 +-
 hw/net/can/can_sja1000.c             |  25 +-
 hw/xen/xen_pvdev.c                   |  45 ++--
 linux-user/main.c                    |  55 ++--
 linux-user/mmap.c                    |   7 +-
 monitor/misc.c                       |   9 +-
 net/can/can_socketcan.c              |  24 +-
 os-posix.c                           |   2 +-
 qemu-img.c                           |   2 +-
 qemu-io.c                            |   2 +-
 qemu-nbd.c                           |   2 +-
 scsi/qemu-pr-helper.c                |   2 +-
 softmmu/vl.c                         |  21 +-
 storage-daemon/qemu-storage-daemon.c |   2 +-
 target/alpha/translate.c             |   7 +-
 target/arm/translate-a64.c           |   6 +-
 target/arm/translate.c               |   7 +-
 target/avr/translate.c               |   7 +-
 target/cris/translate.c              |   7 +-
 target/hexagon/translate.c           |  13 +-
 target/hppa/translate.c              |  15 +-
 target/i386/tcg/translate.c          |  22 +-
 target/m68k/translate.c              |   7 +-
 target/microblaze/translate.c        |   7 +-
 target/mips/tcg/translate.c          |   7 +-
 target/nios2/cpu.c                   |   5 -
 target/nios2/translate.c             |   7 +-
 target/openrisc/translate.c          |   7 +-
 target/ppc/translate.c               |   7 +-
 target/riscv/translate.c             |  10 +-
 target/rx/translate.c                |   7 +-
 target/s390x/tcg/translate.c         |  11 +-
 target/sh4/translate.c               |   7 +-
 target/sparc/translate.c             |   7 +-
 target/tricore/translate.c           |   7 +-
 target/xtensa/translate.c            |   7 +-
 tcg/tcg.c                            | 184 ++++++-------
 tests/unit/test-logging.c            |  42 ++-
 util/log.c                           | 377 +++++++++++++++++----------
 49 files changed, 724 insertions(+), 659 deletions(-)

-- 
2.25.1



^ permalink raw reply	[flat|nested] 41+ messages in thread

* [PATCH v3 01/39] util/log: Drop manual log buffering
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 02/39] target/hexagon: Remove qemu_set_log in hexagon_translate_init Richard Henderson
                   ` (37 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

This buffering was introduced during the Paleozoic: 9fa3e853531.

There has never been an explanation as to why we may not allow
glibc to allocate the file buffer itself.  We certainly have
many other uses of mmap and malloc during user-only startup,
so presumably whatever the issue was, it has been fixed during
the preceeding 18 years.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/qemu/log.h |  1 -
 bsd-user/main.c    |  1 -
 linux-user/main.c  |  1 -
 util/log.c         | 21 ++++-----------------
 4 files changed, 4 insertions(+), 20 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index 5739c7e6d8..ed59ebd4a2 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -148,7 +148,6 @@ typedef struct QEMULogItem {
 extern const QEMULogItem qemu_log_items[];
 
 void qemu_set_log(int log_flags);
-void qemu_log_needs_buffers(void);
 void qemu_set_log_filename(const char *filename, Error **errp);
 void qemu_set_dfilter_ranges(const char *ranges, Error **errp);
 bool qemu_log_in_addr_range(uint64_t addr);
diff --git a/bsd-user/main.c b/bsd-user/main.c
index 88d347d05e..08f43af235 100644
--- a/bsd-user/main.c
+++ b/bsd-user/main.c
@@ -405,7 +405,6 @@ int main(int argc, char **argv)
     }
 
     /* init debug */
-    qemu_log_needs_buffers();
     qemu_set_log_filename(log_file, &error_fatal);
     if (log_mask) {
         int mask;
diff --git a/linux-user/main.c b/linux-user/main.c
index fbc9bcfd5f..2b06350688 100644
--- a/linux-user/main.c
+++ b/linux-user/main.c
@@ -679,7 +679,6 @@ int main(int argc, char **argv, char **envp)
 
     log_mask = last_log_mask | (enable_strace ? LOG_STRACE : 0);
     if (log_mask) {
-        qemu_log_needs_buffers();
         qemu_set_log(log_mask);
     }
 
diff --git a/util/log.c b/util/log.c
index 2ee1500bee..ffa66a267e 100644
--- a/util/log.c
+++ b/util/log.c
@@ -72,8 +72,6 @@ static void qemu_logfile_free(QemuLogFile *logfile)
     g_free(logfile);
 }
 
-static bool log_uses_own_buffers;
-
 /* enable or disable low levels log */
 void qemu_set_log(int log_flags)
 {
@@ -121,29 +119,18 @@ void qemu_set_log(int log_flags)
             assert(!is_daemonized());
             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(logfile->fd, logfile_buf, _IOLBF, sizeof(logfile_buf));
-        } else {
 #if defined(_WIN32)
-            /* Win32 doesn't support line-buffering, so use unbuffered output. */
-            setvbuf(logfile->fd, NULL, _IONBF, 0);
+        /* Win32 doesn't support line-buffering, so use unbuffered output. */
+        setvbuf(logfile->fd, NULL, _IONBF, 0);
 #else
-            setvbuf(logfile->fd, NULL, _IOLBF, 0);
+        setvbuf(logfile->fd, NULL, _IOLBF, 0);
 #endif
-            log_append = 1;
-        }
+        log_append = 1;
         qatomic_rcu_set(&qemu_logfile, logfile);
     }
 }
 
-void qemu_log_needs_buffers(void)
-{
-    log_uses_own_buffers = true;
-}
-
 /*
  * Allow the user to include %d in their logfile which will be
  * substituted with the current PID. This is useful for debugging many
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 02/39] target/hexagon: Remove qemu_set_log in hexagon_translate_init
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 01/39] util/log: Drop manual log buffering Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 03/39] util/log: Return bool from qemu_set_log_filename Richard Henderson
                   ` (36 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

This code appears to be trying to make sure there is a logfile.
But that's already true -- the logfile will either be set by -D,
or will be stderr.  In either case, not appropriate here.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 target/hexagon/translate.c | 6 ------
 1 file changed, 6 deletions(-)

diff --git a/target/hexagon/translate.c b/target/hexagon/translate.c
index b6f541ecb2..98f1452cad 100644
--- a/target/hexagon/translate.c
+++ b/target/hexagon/translate.c
@@ -874,12 +874,6 @@ void hexagon_translate_init(void)
 
     opcode_init();
 
-    if (HEX_DEBUG) {
-        if (!qemu_logfile) {
-            qemu_set_log(qemu_loglevel);
-        }
-    }
-
     for (i = 0; i < TOTAL_PER_THREAD_REGS; i++) {
         hex_gpr[i] = tcg_global_mem_new(cpu_env,
             offsetof(CPUHexagonState, gpr[i]),
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 03/39] util/log: Return bool from qemu_set_log_filename
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 01/39] util/log: Drop manual log buffering Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 02/39] target/hexagon: Remove qemu_set_log in hexagon_translate_init Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 04/39] util/log: Pass Error pointer to qemu_set_log Richard Henderson
                   ` (35 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Per the recommendations in qapi/error.h, return false on failure.

Use the return value in the monitor, the only place we aren't
already passing error_fatal or error_abort.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/qemu/log.h | 2 +-
 monitor/misc.c     | 3 +--
 util/log.c         | 5 +++--
 3 files changed, 5 insertions(+), 5 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index ed59ebd4a2..fabfbe41da 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -148,7 +148,7 @@ typedef struct QEMULogItem {
 extern const QEMULogItem qemu_log_items[];
 
 void qemu_set_log(int log_flags);
-void qemu_set_log_filename(const char *filename, Error **errp);
+bool qemu_set_log_filename(const char *filename, Error **errp);
 void qemu_set_dfilter_ranges(const char *ranges, Error **errp);
 bool qemu_log_in_addr_range(uint64_t addr);
 int qemu_str_to_log_mask(const char *str);
diff --git a/monitor/misc.c b/monitor/misc.c
index a756dbd6db..04ec0711da 100644
--- a/monitor/misc.c
+++ b/monitor/misc.c
@@ -419,8 +419,7 @@ static void hmp_logfile(Monitor *mon, const QDict *qdict)
 {
     Error *err = NULL;
 
-    qemu_set_log_filename(qdict_get_str(qdict, "filename"), &err);
-    if (err) {
+    if (!qemu_set_log_filename(qdict_get_str(qdict, "filename"), &err)) {
         error_report_err(err);
     }
 }
diff --git a/util/log.c b/util/log.c
index ffa66a267e..a838686a18 100644
--- a/util/log.c
+++ b/util/log.c
@@ -138,7 +138,7 @@ void qemu_set_log(int log_flags)
  *
  * filename may be NULL. In that case, log output is sent to stderr
  */
-void qemu_set_log_filename(const char *filename, Error **errp)
+bool qemu_set_log_filename(const char *filename, Error **errp)
 {
     g_free(logfilename);
     logfilename = NULL;
@@ -149,7 +149,7 @@ void qemu_set_log_filename(const char *filename, Error **errp)
                 /* 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;
+                    return false;
                 } else {
                     logfilename = g_strdup_printf(filename, getpid());
                 }
@@ -160,6 +160,7 @@ void qemu_set_log_filename(const char *filename, Error **errp)
 
     qemu_log_close();
     qemu_set_log(qemu_loglevel);
+    return true;
 }
 
 /* Returns true if addr is in our debug filter or no filter defined
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 04/39] util/log: Pass Error pointer to qemu_set_log
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (2 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 03/39] util/log: Return bool from qemu_set_log_filename Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 05/39] os-posix: Use qemu_log_enabled Richard Henderson
                   ` (34 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Do not force exit within qemu_set_log; return bool and pass
an Error value back up the stack as per usual.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
v2: Return bool, per recommendations in qapi/error.h (phil).
---
 include/qemu/log.h                   |  2 +-
 bsd-user/main.c                      |  2 +-
 linux-user/main.c                    |  2 +-
 monitor/misc.c                       |  6 +++++-
 qemu-img.c                           |  2 +-
 qemu-io.c                            |  2 +-
 qemu-nbd.c                           |  2 +-
 scsi/qemu-pr-helper.c                |  2 +-
 softmmu/vl.c                         |  4 ++--
 storage-daemon/qemu-storage-daemon.c |  2 +-
 tests/unit/test-logging.c            |  2 +-
 util/log.c                           | 12 ++++++------
 12 files changed, 22 insertions(+), 18 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index fabfbe41da..0b892f5e90 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -147,7 +147,7 @@ typedef struct QEMULogItem {
 
 extern const QEMULogItem qemu_log_items[];
 
-void qemu_set_log(int log_flags);
+bool qemu_set_log(int log_flags, Error **errp);
 bool qemu_set_log_filename(const char *filename, Error **errp);
 void qemu_set_dfilter_ranges(const char *ranges, Error **errp);
 bool qemu_log_in_addr_range(uint64_t addr);
diff --git a/bsd-user/main.c b/bsd-user/main.c
index 08f43af235..0c8aa1ae90 100644
--- a/bsd-user/main.c
+++ b/bsd-user/main.c
@@ -414,7 +414,7 @@ int main(int argc, char **argv)
             qemu_print_log_usage(stdout);
             exit(1);
         }
-        qemu_set_log(mask);
+        qemu_set_log(mask, &error_fatal);
     }
 
     if (optind >= argc) {
diff --git a/linux-user/main.c b/linux-user/main.c
index 2b06350688..6aed4929ab 100644
--- a/linux-user/main.c
+++ b/linux-user/main.c
@@ -679,7 +679,7 @@ int main(int argc, char **argv, char **envp)
 
     log_mask = last_log_mask | (enable_strace ? LOG_STRACE : 0);
     if (log_mask) {
-        qemu_set_log(log_mask);
+        qemu_set_log(log_mask, &error_fatal);
     }
 
     if (!trace_init_backends()) {
diff --git a/monitor/misc.c b/monitor/misc.c
index 04ec0711da..b16334b75a 100644
--- a/monitor/misc.c
+++ b/monitor/misc.c
@@ -428,6 +428,7 @@ static void hmp_log(Monitor *mon, const QDict *qdict)
 {
     int mask;
     const char *items = qdict_get_str(qdict, "items");
+    Error *err = NULL;
 
     if (!strcmp(items, "none")) {
         mask = 0;
@@ -438,7 +439,10 @@ static void hmp_log(Monitor *mon, const QDict *qdict)
             return;
         }
     }
-    qemu_set_log(mask);
+
+    if (!qemu_set_log(mask, &err)) {
+        error_report_err(err);
+    }
 }
 
 static void hmp_singlestep(Monitor *mon, const QDict *qdict)
diff --git a/qemu-img.c b/qemu-img.c
index 1caddfb23a..9c05c6275d 100644
--- a/qemu-img.c
+++ b/qemu-img.c
@@ -5442,7 +5442,7 @@ int main(int argc, char **argv)
         exit(1);
     }
     trace_init_file();
-    qemu_set_log(LOG_TRACE);
+    qemu_set_log(LOG_TRACE, &error_fatal);
 
     /* find the command */
     for (cmd = img_cmds; cmd->name != NULL; cmd++) {
diff --git a/qemu-io.c b/qemu-io.c
index eb8afc8b41..38321a27a3 100644
--- a/qemu-io.c
+++ b/qemu-io.c
@@ -634,7 +634,7 @@ int main(int argc, char **argv)
         exit(1);
     }
     trace_init_file();
-    qemu_set_log(LOG_TRACE);
+    qemu_set_log(LOG_TRACE, &error_fatal);
 
     /* initialize commands */
     qemuio_add_command(&quit_cmd);
diff --git a/qemu-nbd.c b/qemu-nbd.c
index 713e7557a9..bf9c5fedce 100644
--- a/qemu-nbd.c
+++ b/qemu-nbd.c
@@ -804,7 +804,7 @@ int main(int argc, char **argv)
         exit(1);
     }
     trace_init_file();
-    qemu_set_log(LOG_TRACE);
+    qemu_set_log(LOG_TRACE, &error_fatal);
 
     socket_activation = check_socket_activation();
     if (socket_activation == 0) {
diff --git a/scsi/qemu-pr-helper.c b/scsi/qemu-pr-helper.c
index f281daeced..1f2a84c534 100644
--- a/scsi/qemu-pr-helper.c
+++ b/scsi/qemu-pr-helper.c
@@ -1001,7 +1001,7 @@ int main(int argc, char **argv)
         exit(EXIT_FAILURE);
     }
     trace_init_file();
-    qemu_set_log(LOG_TRACE);
+    qemu_set_log(LOG_TRACE, &error_fatal);
 
 #ifdef CONFIG_MPATH
     dm_init();
diff --git a/softmmu/vl.c b/softmmu/vl.c
index 6f646531a0..a74d0a44a2 100644
--- a/softmmu/vl.c
+++ b/softmmu/vl.c
@@ -2569,9 +2569,9 @@ static void qemu_process_early_options(void)
             qemu_print_log_usage(stdout);
             exit(1);
         }
-        qemu_set_log(mask);
+        qemu_set_log(mask, &error_fatal);
     } else {
-        qemu_set_log(0);
+        qemu_set_log(0, &error_fatal);
     }
 
     qemu_add_default_firmwarepath();
diff --git a/storage-daemon/qemu-storage-daemon.c b/storage-daemon/qemu-storage-daemon.c
index eb72407257..1398f0443d 100644
--- a/storage-daemon/qemu-storage-daemon.c
+++ b/storage-daemon/qemu-storage-daemon.c
@@ -392,7 +392,7 @@ int main(int argc, char *argv[])
     if (!trace_init_backends()) {
         return EXIT_FAILURE;
     }
-    qemu_set_log(LOG_TRACE);
+    qemu_set_log(LOG_TRACE, &error_fatal);
 
     qemu_init_main_loop(&error_fatal);
     process_options(argc, argv, false);
diff --git a/tests/unit/test-logging.c b/tests/unit/test-logging.c
index ccb819f193..93c6d666e8 100644
--- a/tests/unit/test-logging.c
+++ b/tests/unit/test-logging.c
@@ -123,7 +123,7 @@ static void test_logfile_write(gconstpointer data)
      * In cases where a logging backend other than log is used,
      * this is needed.
      */
-    qemu_set_log(CPU_LOG_TB_OUT_ASM);
+    qemu_set_log(CPU_LOG_TB_OUT_ASM, &error_abort);
     file_path = g_build_filename(dir, "qemu_test_log_write0.log", NULL);
     file_path1 = g_build_filename(dir, "qemu_test_log_write1.log", NULL);
 
diff --git a/util/log.c b/util/log.c
index a838686a18..bab4d29ecb 100644
--- a/util/log.c
+++ b/util/log.c
@@ -73,7 +73,7 @@ static void qemu_logfile_free(QemuLogFile *logfile)
 }
 
 /* enable or disable low levels log */
-void qemu_set_log(int log_flags)
+bool qemu_set_log(int log_flags, Error **errp)
 {
     bool need_to_open_file = false;
     QemuLogFile *logfile;
@@ -103,9 +103,9 @@ void qemu_set_log(int log_flags)
         if (logfilename) {
             logfile->fd = fopen(logfilename, log_append ? "a" : "w");
             if (!logfile->fd) {
-                g_free(logfile);
-                perror(logfilename);
-                _exit(1);
+                error_setg_errno(errp, errno, "Error opening logfile %s",
+                                 logfilename);
+                return false;
             }
             /* In case we are a daemon redirect stderr to logfile */
             if (is_daemonized()) {
@@ -129,6 +129,7 @@ void qemu_set_log(int log_flags)
         log_append = 1;
         qatomic_rcu_set(&qemu_logfile, logfile);
     }
+    return true;
 }
 
 /*
@@ -159,8 +160,7 @@ bool qemu_set_log_filename(const char *filename, Error **errp)
     }
 
     qemu_log_close();
-    qemu_set_log(qemu_loglevel);
-    return true;
+    return qemu_set_log(qemu_loglevel, errp);
 }
 
 /* Returns true if addr is in our debug filter or no filter defined
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 05/39] os-posix: Use qemu_log_enabled
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (3 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 04/39] util/log: Pass Error pointer to qemu_set_log Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 06/39] util/log: Move qemu_log_lock, qemu_log_unlock out of line Richard Henderson
                   ` (33 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee, Philippe Mathieu-Daudé

Do not reference qemu_logfile directly;
use the predicate provided by qemu/log.h.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 os-posix.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/os-posix.c b/os-posix.c
index 24692c8593..20d31fc518 100644
--- a/os-posix.c
+++ b/os-posix.c
@@ -292,7 +292,7 @@ void os_setup_post(void)
         dup2(fd, 0);
         dup2(fd, 1);
         /* In case -D is given do not redirect stderr to /dev/null */
-        if (!qemu_logfile) {
+        if (!qemu_log_enabled()) {
             dup2(fd, 2);
         }
 
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 06/39] util/log: Move qemu_log_lock, qemu_log_unlock out of line
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (4 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 05/39] os-posix: Use qemu_log_enabled Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 07/39] util/log: Rename qemu_log_lock to qemu_log_trylock Richard Henderson
                   ` (32 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee, Philippe Mathieu-Daudé

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/qemu/log.h | 28 +++-------------------------
 util/log.c         | 23 +++++++++++++++++++++++
 2 files changed, 26 insertions(+), 25 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index 0b892f5e90..6a6b1efce5 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -65,32 +65,10 @@ static inline bool qemu_log_separate(void)
 /* LOG_STRACE is used for user-mode strace logging. */
 #define LOG_STRACE         (1 << 19)
 
-/* Lock output for a series of related logs.  Since this is not needed
- * for a single qemu_log / qemu_log_mask / qemu_log_mask_and_addr, we
- * assume that qemu_loglevel_mask has already been tested, and that
- * qemu_loglevel is never set when qemu_logfile is unset.
- */
+/* Lock/unlock output. */
 
-static inline FILE *qemu_log_lock(void)
-{
-    QemuLogFile *logfile;
-    rcu_read_lock();
-    logfile = qatomic_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();
-}
+FILE *qemu_log_lock(void);
+void qemu_log_unlock(FILE *fd);
 
 /* Logging functions: */
 
diff --git a/util/log.c b/util/log.c
index bab4d29ecb..1a3121610a 100644
--- a/util/log.c
+++ b/util/log.c
@@ -34,6 +34,29 @@ int qemu_loglevel;
 static int log_append = 0;
 static GArray *debug_regions;
 
+/* Lock/unlock output. */
+
+FILE *qemu_log_lock(void)
+{
+    QemuLogFile *logfile;
+    rcu_read_lock();
+    logfile = qatomic_rcu_read(&qemu_logfile);
+    if (logfile) {
+        qemu_flockfile(logfile->fd);
+        return logfile->fd;
+    } else {
+        return NULL;
+    }
+}
+
+void qemu_log_unlock(FILE *fd)
+{
+    if (fd) {
+        qemu_funlockfile(fd);
+    }
+    rcu_read_unlock();
+}
+
 /* Return the number of characters emitted.  */
 int qemu_log(const char *fmt, ...)
 {
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 07/39] util/log: Rename qemu_log_lock to qemu_log_trylock
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (5 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 06/39] util/log: Move qemu_log_lock, qemu_log_unlock out of line Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 08/39] hw/xen: Split out xen_pv_output_msg Richard Henderson
                   ` (31 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

This function can fail, which makes it more like ftrylockfile
or pthread_mutex_trylock than flockfile or pthread_mutex_lock,
so rename it.

To closer match the other trylock functions, release rcu_read_lock
along the failure path, so that qemu_log_unlock need not be called
on failure.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
v2: Rename the function as well as change the semantics, so drop r-b.
---
 include/exec/log.h          | 2 +-
 include/qemu/log.h          | 2 +-
 accel/tcg/cpu-exec.c        | 2 +-
 accel/tcg/translate-all.c   | 2 +-
 accel/tcg/translator.c      | 2 +-
 cpu.c                       | 2 +-
 hw/net/can/can_sja1000.c    | 2 +-
 net/can/can_socketcan.c     | 2 +-
 target/i386/tcg/translate.c | 2 +-
 tcg/tcg.c                   | 8 ++++----
 tests/unit/test-logging.c   | 2 +-
 util/log.c                  | 6 ++++--
 12 files changed, 18 insertions(+), 16 deletions(-)

diff --git a/include/exec/log.h b/include/exec/log.h
index 3c7fa65ead..fb595d1eb7 100644
--- a/include/exec/log.h
+++ b/include/exec/log.h
@@ -71,7 +71,7 @@ static inline void log_disas(const void *code, unsigned long size)
 /* page_dump() output to the log file: */
 static inline void log_page_dump(const char *operation)
 {
-    FILE *logfile = qemu_log_lock();
+    FILE *logfile = qemu_log_trylock();
     if (logfile) {
         qemu_log("page layout changed following %s\n", operation);
         page_dump(logfile);
diff --git a/include/qemu/log.h b/include/qemu/log.h
index 6a6b1efce5..d090faf22a 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -67,7 +67,7 @@ static inline bool qemu_log_separate(void)
 
 /* Lock/unlock output. */
 
-FILE *qemu_log_lock(void);
+FILE *qemu_log_trylock(void);
 void qemu_log_unlock(FILE *fd);
 
 /* Logging functions: */
diff --git a/accel/tcg/cpu-exec.c b/accel/tcg/cpu-exec.c
index c997c2e8e0..8d0315de75 100644
--- a/accel/tcg/cpu-exec.c
+++ b/accel/tcg/cpu-exec.c
@@ -215,7 +215,7 @@ static inline void log_cpu_exec(target_ulong pc, CPUState *cpu,
 
 #if defined(DEBUG_DISAS)
         if (qemu_loglevel_mask(CPU_LOG_TB_CPU)) {
-            FILE *logfile = qemu_log_lock();
+            FILE *logfile = qemu_log_trylock();
             int flags = 0;
 
             if (qemu_loglevel_mask(CPU_LOG_TB_FPU)) {
diff --git a/accel/tcg/translate-all.c b/accel/tcg/translate-all.c
index 5971cd53ab..71ab863c18 100644
--- a/accel/tcg/translate-all.c
+++ b/accel/tcg/translate-all.c
@@ -1528,7 +1528,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)) {
-        FILE *logfile = qemu_log_lock();
+        FILE *logfile = qemu_log_trylock();
         int code_size, data_size;
         const tcg_target_ulong *rx_data_gen_ptr;
         size_t chunk_start;
diff --git a/accel/tcg/translator.c b/accel/tcg/translator.c
index f06c314266..1506755f3c 100644
--- a/accel/tcg/translator.c
+++ b/accel/tcg/translator.c
@@ -139,7 +139,7 @@ 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)) {
-        FILE *logfile = qemu_log_lock();
+        FILE *logfile = qemu_log_trylock();
         qemu_log("----------------\n");
         ops->disas_log(db, cpu);
         qemu_log("\n");
diff --git a/cpu.c b/cpu.c
index be1f8b074c..ddcbfc724d 100644
--- a/cpu.c
+++ b/cpu.c
@@ -400,7 +400,7 @@ 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()) {
-        FILE *logfile = qemu_log_lock();
+        FILE *logfile = qemu_log_trylock();
         qemu_log("qemu: fatal: ");
         qemu_log_vprintf(fmt, ap2);
         qemu_log("\n");
diff --git a/hw/net/can/can_sja1000.c b/hw/net/can/can_sja1000.c
index 3ba803e947..300313dfb8 100644
--- a/hw/net/can/can_sja1000.c
+++ b/hw/net/can/can_sja1000.c
@@ -247,7 +247,7 @@ 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();
+    FILE *logfile = qemu_log_trylock();
 
     qemu_log("%s%03X [%01d] %s %s",
              prefix,
diff --git a/net/can/can_socketcan.c b/net/can/can_socketcan.c
index 4b68f60c6b..4a505643e9 100644
--- a/net/can/can_socketcan.c
+++ b/net/can/can_socketcan.c
@@ -76,7 +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;
-    FILE *logfile = qemu_log_lock();
+    FILE *logfile = qemu_log_trylock();
     qemu_log("[cansocketcan]: %03X [%01d] %s %s",
              msg->can_id & QEMU_CAN_EFF_MASK,
              msg->can_dlc,
diff --git a/target/i386/tcg/translate.c b/target/i386/tcg/translate.c
index c393913fe0..3fb8b530d8 100644
--- a/target/i386/tcg/translate.c
+++ b/target/i386/tcg/translate.c
@@ -2580,7 +2580,7 @@ static void gen_unknown_opcode(CPUX86State *env, DisasContext *s)
     gen_illegal_opcode(s);
 
     if (qemu_loglevel_mask(LOG_UNIMP)) {
-        FILE *logfile = qemu_log_lock();
+        FILE *logfile = qemu_log_trylock();
         target_ulong pc = s->pc_start, end = s->pc;
 
         qemu_log("ILLOPC: " TARGET_FMT_lx ":", pc);
diff --git a/tcg/tcg.c b/tcg/tcg.c
index 33a97eabdb..2f09114bf9 100644
--- a/tcg/tcg.c
+++ b/tcg/tcg.c
@@ -756,7 +756,7 @@ void tcg_prologue_init(TCGContext *s)
 
 #ifdef DEBUG_DISAS
     if (qemu_loglevel_mask(CPU_LOG_TB_OUT_ASM)) {
-        FILE *logfile = qemu_log_lock();
+        FILE *logfile = qemu_log_trylock();
         qemu_log("PROLOGUE: [size=%zu]\n", prologue_size);
         if (s->data_gen_ptr) {
             size_t code_size = s->data_gen_ptr - s->code_gen_ptr;
@@ -4200,7 +4200,7 @@ 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))) {
-        FILE *logfile = qemu_log_lock();
+        FILE *logfile = qemu_log_trylock();
         qemu_log("OP:\n");
         tcg_dump_ops(s, false);
         qemu_log("\n");
@@ -4245,7 +4245,7 @@ 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))) {
-            FILE *logfile = qemu_log_lock();
+            FILE *logfile = qemu_log_trylock();
             qemu_log("OP before indirect lowering:\n");
             tcg_dump_ops(s, false);
             qemu_log("\n");
@@ -4266,7 +4266,7 @@ 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))) {
-        FILE *logfile = qemu_log_lock();
+        FILE *logfile = qemu_log_trylock();
         qemu_log("OP after optimization and liveness analysis:\n");
         tcg_dump_ops(s, true);
         qemu_log("\n");
diff --git a/tests/unit/test-logging.c b/tests/unit/test-logging.c
index 93c6d666e8..54d7e8e33b 100644
--- a/tests/unit/test-logging.c
+++ b/tests/unit/test-logging.c
@@ -163,7 +163,7 @@ static void test_logfile_lock(gconstpointer data)
      * our handle remains valid for use due to RCU.
      */
     qemu_set_log_filename(file_path, &error_abort);
-    logfile = qemu_log_lock();
+    logfile = qemu_log_trylock();
     g_assert(logfile);
     fprintf(logfile, "%s 1st write to file\n", __func__);
     fflush(logfile);
diff --git a/util/log.c b/util/log.c
index 1a3121610a..6b7b358573 100644
--- a/util/log.c
+++ b/util/log.c
@@ -36,15 +36,17 @@ static GArray *debug_regions;
 
 /* Lock/unlock output. */
 
-FILE *qemu_log_lock(void)
+FILE *qemu_log_trylock(void)
 {
     QemuLogFile *logfile;
+
     rcu_read_lock();
     logfile = qatomic_rcu_read(&qemu_logfile);
     if (logfile) {
         qemu_flockfile(logfile->fd);
         return logfile->fd;
     } else {
+        rcu_read_unlock();
         return NULL;
     }
 }
@@ -53,8 +55,8 @@ void qemu_log_unlock(FILE *fd)
 {
     if (fd) {
         qemu_funlockfile(fd);
+        rcu_read_unlock();
     }
-    rcu_read_unlock();
 }
 
 /* Return the number of characters emitted.  */
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 08/39] hw/xen: Split out xen_pv_output_msg
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (6 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 07/39] util/log: Rename qemu_log_lock to qemu_log_trylock Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 09/39] *: Use fprintf between qemu_log_trylock/unlock Richard Henderson
                   ` (30 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Do not replicate the individual logging statements.
Use qemu_log_trylock/unlock instead of qemu_log directly.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 hw/xen/xen_pvdev.c | 44 ++++++++++++++++++++++++--------------------
 1 file changed, 24 insertions(+), 20 deletions(-)

diff --git a/hw/xen/xen_pvdev.c b/hw/xen/xen_pvdev.c
index 8ab458922a..0423c61158 100644
--- a/hw/xen/xen_pvdev.c
+++ b/hw/xen/xen_pvdev.c
@@ -196,34 +196,38 @@ const char *xenbus_strstate(enum xenbus_state state)
  *  2 == noisy debug messages (logfile only).
  *  3 == will flood your log (logfile only).
  */
+static void xen_pv_output_msg(struct XenLegacyDevice *xendev,
+                              FILE *f, const char *fmt, va_list args)
+{
+    if (xendev) {
+        fprintf(f, "xen be: %s: ", xendev->name);
+    } else {
+        fprintf(f, "xen be core: ");
+    }
+    vfprintf(f, fmt, args);
+}
+
 void xen_pv_printf(struct XenLegacyDevice *xendev, int msg_level,
                    const char *fmt, ...)
 {
+    FILE *logfile;
     va_list args;
 
-    if (xendev) {
-        if (msg_level > xendev->debug) {
-            return;
-        }
-        qemu_log("xen be: %s: ", xendev->name);
-        if (msg_level == 0) {
-            fprintf(stderr, "xen be: %s: ", xendev->name);
-        }
-    } else {
-        if (msg_level > debug) {
-            return;
-        }
-        qemu_log("xen be core: ");
-        if (msg_level == 0) {
-            fprintf(stderr, "xen be core: ");
-        }
+    if (msg_level > (xendev ? xendev->debug : debug)) {
+        return;
     }
-    va_start(args, fmt);
-    qemu_log_vprintf(fmt, args);
-    va_end(args);
+
+    logfile = qemu_log_trylock();
+    if (logfile) {
+        va_start(args, fmt);
+        xen_pv_output_msg(xendev, logfile, fmt, args);
+        va_end(args);
+        qemu_log_unlock(logfile);
+    }
+
     if (msg_level == 0) {
         va_start(args, fmt);
-        vfprintf(stderr, fmt, args);
+        xen_pv_output_msg(xendev, stderr, fmt, args);
         va_end(args);
     }
     qemu_log_flush();
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 09/39] *: Use fprintf between qemu_log_trylock/unlock
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (7 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 08/39] hw/xen: Split out xen_pv_output_msg Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 10/39] util/log: Remove qemu_log_vprintf Richard Henderson
                   ` (29 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Inside qemu_log, we perform qemu_log_trylock/unlock, which need
not be done if we have already performed the lock beforehand.

Always check the result of qemu_log_trylock -- only checking
qemu_loglevel_mask races with the acquisition of the lock on
the logfile.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/exec/log.h          |   2 +-
 accel/tcg/cpu-exec.c        |  16 ++---
 accel/tcg/translate-all.c   | 117 +++++++++++++++++++-----------------
 accel/tcg/translator.c      |  10 +--
 cpu.c                       |  14 +++--
 hw/net/can/can_sja1000.c    |  24 ++++----
 net/can/can_socketcan.c     |  23 ++++---
 target/i386/tcg/translate.c |  14 +++--
 tcg/tcg.c                   |  74 +++++++++++++----------
 9 files changed, 162 insertions(+), 132 deletions(-)

diff --git a/include/exec/log.h b/include/exec/log.h
index fb595d1eb7..648f4d2263 100644
--- a/include/exec/log.h
+++ b/include/exec/log.h
@@ -73,7 +73,7 @@ static inline void log_page_dump(const char *operation)
 {
     FILE *logfile = qemu_log_trylock();
     if (logfile) {
-        qemu_log("page layout changed following %s\n", operation);
+        fprintf(logfile, "page layout changed following %s\n", operation);
         page_dump(logfile);
     }
     qemu_log_unlock(logfile);
diff --git a/accel/tcg/cpu-exec.c b/accel/tcg/cpu-exec.c
index 8d0315de75..8a896e772d 100644
--- a/accel/tcg/cpu-exec.c
+++ b/accel/tcg/cpu-exec.c
@@ -216,16 +216,18 @@ static inline void log_cpu_exec(target_ulong pc, CPUState *cpu,
 #if defined(DEBUG_DISAS)
         if (qemu_loglevel_mask(CPU_LOG_TB_CPU)) {
             FILE *logfile = qemu_log_trylock();
-            int flags = 0;
+            if (logfile) {
+                int flags = 0;
 
-            if (qemu_loglevel_mask(CPU_LOG_TB_FPU)) {
-                flags |= CPU_DUMP_FPU;
-            }
+                if (qemu_loglevel_mask(CPU_LOG_TB_FPU)) {
+                    flags |= CPU_DUMP_FPU;
+                }
 #if defined(TARGET_I386)
-            flags |= CPU_DUMP_CCOP;
+                flags |= CPU_DUMP_CCOP;
 #endif
-            log_cpu_state(cpu, flags);
-            qemu_log_unlock(logfile);
+                log_cpu_state(cpu, flags);
+                qemu_log_unlock(logfile);
+            }
         }
 #endif /* DEBUG_DISAS */
     }
diff --git a/accel/tcg/translate-all.c b/accel/tcg/translate-all.c
index 71ab863c18..4812619f00 100644
--- a/accel/tcg/translate-all.c
+++ b/accel/tcg/translate-all.c
@@ -1529,68 +1529,75 @@ TranslationBlock *tb_gen_code(CPUState *cpu,
     if (qemu_loglevel_mask(CPU_LOG_TB_OUT_ASM) &&
         qemu_log_in_addr_range(tb->pc)) {
         FILE *logfile = qemu_log_trylock();
-        int code_size, data_size;
-        const tcg_target_ulong *rx_data_gen_ptr;
-        size_t chunk_start;
-        int insn = 0;
+        if (logfile) {
+            int code_size, data_size;
+            const tcg_target_ulong *rx_data_gen_ptr;
+            size_t chunk_start;
+            int insn = 0;
 
-        if (tcg_ctx->data_gen_ptr) {
-            rx_data_gen_ptr = tcg_splitwx_to_rx(tcg_ctx->data_gen_ptr);
-            code_size = (const void *)rx_data_gen_ptr - tb->tc.ptr;
-            data_size = gen_code_size - code_size;
-        } else {
-            rx_data_gen_ptr = 0;
-            code_size = gen_code_size;
-            data_size = 0;
-        }
-
-        /* Dump header and the first instruction */
-        qemu_log("OUT: [size=%d]\n", gen_code_size);
-        qemu_log("  -- guest addr 0x" TARGET_FMT_lx " + tb prologue\n",
-                 tcg_ctx->gen_insn_data[insn][0]);
-        chunk_start = tcg_ctx->gen_insn_end_off[insn];
-        log_disas(tb->tc.ptr, chunk_start);
-
-        /*
-         * Dump each instruction chunk, wrapping up empty chunks into
-         * the next instruction. The whole array is offset so the
-         * first entry is the beginning of the 2nd instruction.
-         */
-        while (insn < tb->icount) {
-            size_t chunk_end = tcg_ctx->gen_insn_end_off[insn];
-            if (chunk_end > chunk_start) {
-                qemu_log("  -- guest addr 0x" TARGET_FMT_lx "\n",
-                         tcg_ctx->gen_insn_data[insn][0]);
-                log_disas(tb->tc.ptr + chunk_start, chunk_end - chunk_start);
-                chunk_start = chunk_end;
+            if (tcg_ctx->data_gen_ptr) {
+                rx_data_gen_ptr = tcg_splitwx_to_rx(tcg_ctx->data_gen_ptr);
+                code_size = (const void *)rx_data_gen_ptr - tb->tc.ptr;
+                data_size = gen_code_size - code_size;
+            } else {
+                rx_data_gen_ptr = 0;
+                code_size = gen_code_size;
+                data_size = 0;
             }
-            insn++;
-        }
 
-        if (chunk_start < code_size) {
-            qemu_log("  -- tb slow paths + alignment\n");
-            log_disas(tb->tc.ptr + chunk_start, code_size - chunk_start);
-        }
+            /* Dump header and the first instruction */
+            fprintf(logfile, "OUT: [size=%d]\n", gen_code_size);
+            fprintf(logfile,
+                    "  -- guest addr 0x" TARGET_FMT_lx " + tb prologue\n",
+                    tcg_ctx->gen_insn_data[insn][0]);
+            chunk_start = tcg_ctx->gen_insn_end_off[insn];
+            disas(logfile, tb->tc.ptr, chunk_start);
 
-        /* Finally dump any data we may have after the block */
-        if (data_size) {
-            int i;
-            qemu_log("  data: [size=%d]\n", data_size);
-            for (i = 0; i < data_size / sizeof(tcg_target_ulong); i++) {
-                if (sizeof(tcg_target_ulong) == 8) {
-                    qemu_log("0x%08" PRIxPTR ":  .quad  0x%016" TCG_PRIlx "\n",
-                             (uintptr_t)&rx_data_gen_ptr[i], rx_data_gen_ptr[i]);
-                } else if (sizeof(tcg_target_ulong) == 4) {
-                    qemu_log("0x%08" PRIxPTR ":  .long  0x%08" TCG_PRIlx "\n",
-                             (uintptr_t)&rx_data_gen_ptr[i], rx_data_gen_ptr[i]);
-                } else {
-                    qemu_build_not_reached();
+            /*
+             * Dump each instruction chunk, wrapping up empty chunks into
+             * the next instruction. The whole array is offset so the
+             * first entry is the beginning of the 2nd instruction.
+             */
+            while (insn < tb->icount) {
+                size_t chunk_end = tcg_ctx->gen_insn_end_off[insn];
+                if (chunk_end > chunk_start) {
+                    fprintf(logfile, "  -- guest addr 0x" TARGET_FMT_lx "\n",
+                            tcg_ctx->gen_insn_data[insn][0]);
+                    disas(logfile, tb->tc.ptr + chunk_start,
+                          chunk_end - chunk_start);
+                    chunk_start = chunk_end;
+                }
+                insn++;
+            }
+
+            if (chunk_start < code_size) {
+                fprintf(logfile, "  -- tb slow paths + alignment\n");
+                disas(logfile, tb->tc.ptr + chunk_start,
+                      code_size - chunk_start);
+            }
+
+            /* Finally dump any data we may have after the block */
+            if (data_size) {
+                int i;
+                fprintf(logfile, "  data: [size=%d]\n", data_size);
+                for (i = 0; i < data_size / sizeof(tcg_target_ulong); i++) {
+                    if (sizeof(tcg_target_ulong) == 8) {
+                        fprintf(logfile,
+                                "0x%08" PRIxPTR ":  .quad  0x%016" TCG_PRIlx "\n",
+                                (uintptr_t)&rx_data_gen_ptr[i], rx_data_gen_ptr[i]);
+                    } else if (sizeof(tcg_target_ulong) == 4) {
+                        fprintf(logfile,
+                                "0x%08" PRIxPTR ":  .long  0x%08" TCG_PRIlx "\n",
+                                (uintptr_t)&rx_data_gen_ptr[i], rx_data_gen_ptr[i]);
+                    } else {
+                        qemu_build_not_reached();
+                    }
                 }
             }
+            fprintf(logfile, "\n");
+            qemu_log_flush();
+            qemu_log_unlock(logfile);
         }
-        qemu_log("\n");
-        qemu_log_flush();
-        qemu_log_unlock(logfile);
     }
 #endif
 
diff --git a/accel/tcg/translator.c b/accel/tcg/translator.c
index 1506755f3c..af8798f98b 100644
--- a/accel/tcg/translator.c
+++ b/accel/tcg/translator.c
@@ -140,10 +140,12 @@ void translator_loop(const TranslatorOps *ops, DisasContextBase *db,
     if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM)
         && qemu_log_in_addr_range(db->pc_first)) {
         FILE *logfile = qemu_log_trylock();
-        qemu_log("----------------\n");
-        ops->disas_log(db, cpu);
-        qemu_log("\n");
-        qemu_log_unlock(logfile);
+        if (logfile) {
+            fprintf(logfile, "----------------\n");
+            ops->disas_log(db, cpu);
+            fprintf(logfile, "\n");
+            qemu_log_unlock(logfile);
+        }
     }
 #endif
 }
diff --git a/cpu.c b/cpu.c
index ddcbfc724d..3340bb7538 100644
--- a/cpu.c
+++ b/cpu.c
@@ -401,12 +401,14 @@ void cpu_abort(CPUState *cpu, const char *fmt, ...)
     cpu_dump_state(cpu, stderr, CPU_DUMP_FPU | CPU_DUMP_CCOP);
     if (qemu_log_separate()) {
         FILE *logfile = qemu_log_trylock();
-        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(logfile);
+        if (logfile) {
+            fprintf(logfile, "qemu: fatal: ");
+            vfprintf(logfile, fmt, ap2);
+            fprintf(logfile, "\n");
+            cpu_dump_state(cpu, logfile, CPU_DUMP_FPU | CPU_DUMP_CCOP);
+            qemu_log_flush();
+            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 300313dfb8..23d634af6f 100644
--- a/hw/net/can/can_sja1000.c
+++ b/hw/net/can/can_sja1000.c
@@ -249,19 +249,21 @@ static void can_display_msg(const char *prefix, const qemu_can_frame *msg)
     int i;
     FILE *logfile = qemu_log_trylock();
 
-    qemu_log("%s%03X [%01d] %s %s",
-             prefix,
-             msg->can_id & QEMU_CAN_EFF_MASK,
-             msg->can_dlc,
-             msg->can_id & QEMU_CAN_EFF_FLAG ? "EFF" : "SFF",
-             msg->can_id & QEMU_CAN_RTR_FLAG ? "RTR" : "DAT");
+    if (logfile) {
+        fprintf(logfile, "%s%03X [%01d] %s %s",
+                prefix,
+                msg->can_id & QEMU_CAN_EFF_MASK,
+                msg->can_dlc,
+                msg->can_id & QEMU_CAN_EFF_FLAG ? "EFF" : "SFF",
+                msg->can_id & QEMU_CAN_RTR_FLAG ? "RTR" : "DAT");
 
-    for (i = 0; i < msg->can_dlc; i++) {
-        qemu_log(" %02X", msg->data[i]);
+        for (i = 0; i < msg->can_dlc; i++) {
+            fprintf(logfile, " %02X", msg->data[i]);
+        }
+        fprintf(logfile, "\n");
+        qemu_log_flush();
+        qemu_log_unlock(logfile);
     }
-    qemu_log("\n");
-    qemu_log_flush();
-    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 4a505643e9..a6388563c3 100644
--- a/net/can/can_socketcan.c
+++ b/net/can/can_socketcan.c
@@ -77,18 +77,21 @@ static void can_host_socketcan_display_msg(struct qemu_can_frame *msg)
 {
     int i;
     FILE *logfile = qemu_log_trylock();
-    qemu_log("[cansocketcan]: %03X [%01d] %s %s",
-             msg->can_id & QEMU_CAN_EFF_MASK,
-             msg->can_dlc,
-             msg->can_id & QEMU_CAN_EFF_FLAG ? "EFF" : "SFF",
-             msg->can_id & QEMU_CAN_RTR_FLAG ? "RTR" : "DAT");
 
-    for (i = 0; i < msg->can_dlc; i++) {
-        qemu_log(" %02X", msg->data[i]);
+    if (logfile) {
+        fprintf(logfile, "[cansocketcan]: %03X [%01d] %s %s",
+                msg->can_id & QEMU_CAN_EFF_MASK,
+                msg->can_dlc,
+                msg->can_id & QEMU_CAN_EFF_FLAG ? "EFF" : "SFF",
+                msg->can_id & QEMU_CAN_RTR_FLAG ? "RTR" : "DAT");
+
+        for (i = 0; i < msg->can_dlc; i++) {
+            fprintf(logfile, " %02X", msg->data[i]);
+        }
+        fprintf(logfile, "\n");
+        qemu_log_flush();
+        qemu_log_unlock(logfile);
     }
-    qemu_log("\n");
-    qemu_log_flush();
-    qemu_log_unlock(logfile);
 }
 
 static void can_host_socketcan_read(void *opaque)
diff --git a/target/i386/tcg/translate.c b/target/i386/tcg/translate.c
index 3fb8b530d8..d71bd2b0f4 100644
--- a/target/i386/tcg/translate.c
+++ b/target/i386/tcg/translate.c
@@ -2581,14 +2581,16 @@ static void gen_unknown_opcode(CPUX86State *env, DisasContext *s)
 
     if (qemu_loglevel_mask(LOG_UNIMP)) {
         FILE *logfile = qemu_log_trylock();
-        target_ulong pc = s->pc_start, end = s->pc;
+        if (logfile) {
+            target_ulong pc = s->pc_start, end = s->pc;
 
-        qemu_log("ILLOPC: " TARGET_FMT_lx ":", pc);
-        for (; pc < end; ++pc) {
-            qemu_log(" %02x", cpu_ldub_code(env, pc));
+            fprintf(logfile, "ILLOPC: " TARGET_FMT_lx ":", pc);
+            for (; pc < end; ++pc) {
+                fprintf(logfile, " %02x", cpu_ldub_code(env, pc));
+            }
+            fprintf(logfile, "\n");
+            qemu_log_unlock(logfile);
         }
-        qemu_log("\n");
-        qemu_log_unlock(logfile);
     }
 }
 
diff --git a/tcg/tcg.c b/tcg/tcg.c
index 2f09114bf9..892f640fce 100644
--- a/tcg/tcg.c
+++ b/tcg/tcg.c
@@ -757,31 +757,35 @@ void tcg_prologue_init(TCGContext *s)
 #ifdef DEBUG_DISAS
     if (qemu_loglevel_mask(CPU_LOG_TB_OUT_ASM)) {
         FILE *logfile = qemu_log_trylock();
-        qemu_log("PROLOGUE: [size=%zu]\n", prologue_size);
-        if (s->data_gen_ptr) {
-            size_t code_size = s->data_gen_ptr - s->code_gen_ptr;
-            size_t data_size = prologue_size - code_size;
-            size_t i;
+        if (logfile) {
+            fprintf(logfile, "PROLOGUE: [size=%zu]\n", prologue_size);
+            if (s->data_gen_ptr) {
+                size_t code_size = s->data_gen_ptr - s->code_gen_ptr;
+                size_t data_size = prologue_size - code_size;
+                size_t i;
 
-            log_disas(s->code_gen_ptr, code_size);
+                disas(logfile, s->code_gen_ptr, code_size);
 
-            for (i = 0; i < data_size; i += sizeof(tcg_target_ulong)) {
-                if (sizeof(tcg_target_ulong) == 8) {
-                    qemu_log("0x%08" PRIxPTR ":  .quad  0x%016" PRIx64 "\n",
-                             (uintptr_t)s->data_gen_ptr + i,
-                             *(uint64_t *)(s->data_gen_ptr + i));
-                } else {
-                    qemu_log("0x%08" PRIxPTR ":  .long  0x%08x\n",
-                             (uintptr_t)s->data_gen_ptr + i,
-                             *(uint32_t *)(s->data_gen_ptr + i));
+                for (i = 0; i < data_size; i += sizeof(tcg_target_ulong)) {
+                    if (sizeof(tcg_target_ulong) == 8) {
+                        fprintf(logfile,
+                                "0x%08" PRIxPTR ":  .quad  0x%016" PRIx64 "\n",
+                                (uintptr_t)s->data_gen_ptr + i,
+                                *(uint64_t *)(s->data_gen_ptr + i));
+                    } else {
+                        fprintf(logfile,
+                                "0x%08" PRIxPTR ":  .long  0x%08x\n",
+                                (uintptr_t)s->data_gen_ptr + i,
+                                *(uint32_t *)(s->data_gen_ptr + i));
+                    }
                 }
+            } else {
+                disas(logfile, s->code_gen_ptr, prologue_size);
             }
-        } else {
-            log_disas(s->code_gen_ptr, prologue_size);
+            fprintf(logfile, "\n");
+            qemu_log_flush();
+            qemu_log_unlock(logfile);
         }
-        qemu_log("\n");
-        qemu_log_flush();
-        qemu_log_unlock(logfile);
     }
 #endif
 
@@ -4201,10 +4205,12 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
     if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP)
                  && qemu_log_in_addr_range(tb->pc))) {
         FILE *logfile = qemu_log_trylock();
-        qemu_log("OP:\n");
-        tcg_dump_ops(s, false);
-        qemu_log("\n");
-        qemu_log_unlock(logfile);
+        if (logfile) {
+            fprintf(logfile, "OP:\n");
+            tcg_dump_ops(s, false);
+            fprintf(logfile, "\n");
+            qemu_log_unlock(logfile);
+        }
     }
 #endif
 
@@ -4246,10 +4252,12 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
         if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP_IND)
                      && qemu_log_in_addr_range(tb->pc))) {
             FILE *logfile = qemu_log_trylock();
-            qemu_log("OP before indirect lowering:\n");
-            tcg_dump_ops(s, false);
-            qemu_log("\n");
-            qemu_log_unlock(logfile);
+            if (logfile) {
+                fprintf(logfile, "OP before indirect lowering:\n");
+                tcg_dump_ops(s, false);
+                fprintf(logfile, "\n");
+                qemu_log_unlock(logfile);
+            }
         }
 #endif
         /* Replace indirect temps with direct temps.  */
@@ -4267,10 +4275,12 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
     if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP_OPT)
                  && qemu_log_in_addr_range(tb->pc))) {
         FILE *logfile = qemu_log_trylock();
-        qemu_log("OP after optimization and liveness analysis:\n");
-        tcg_dump_ops(s, true);
-        qemu_log("\n");
-        qemu_log_unlock(logfile);
+        if (logfile) {
+            fprintf(logfile, "OP after optimization and liveness analysis:\n");
+            tcg_dump_ops(s, true);
+            fprintf(logfile, "\n");
+            qemu_log_unlock(logfile);
+        }
     }
 #endif
 
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 10/39] util/log: Remove qemu_log_vprintf
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (8 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 09/39] *: Use fprintf between qemu_log_trylock/unlock Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 11/39] tcg: Pass the locked filepointer to tcg_dump_ops Richard Henderson
                   ` (28 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

This function is no longer used.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/qemu/log.h | 15 ---------------
 1 file changed, 15 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index d090faf22a..2d9455dc85 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -72,21 +72,6 @@ void qemu_log_unlock(FILE *fd);
 
 /* Logging functions: */
 
-/* vfprintf-like logging function
- */
-static inline void G_GNUC_PRINTF(1, 0)
-qemu_log_vprintf(const char *fmt, va_list va)
-{
-    QemuLogFile *logfile;
-
-    rcu_read_lock();
-    logfile = qatomic_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:
  * @mask: bit to check in the mask
  * @fmt: printf-style format string
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 11/39] tcg: Pass the locked filepointer to tcg_dump_ops
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (9 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 10/39] util/log: Remove qemu_log_vprintf Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 12/39] exec/translator: Pass the locked filepointer to disas_log hook Richard Henderson
                   ` (27 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

We have already looked up and locked the filepointer.
Use fprintf instead of qemu_log directly for output
in and around tcg_dump_ops.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 tcg/tcg.c | 109 ++++++++++++++++++++++++++----------------------------
 1 file changed, 52 insertions(+), 57 deletions(-)

diff --git a/tcg/tcg.c b/tcg/tcg.c
index 892f640fce..70f3b52482 100644
--- a/tcg/tcg.c
+++ b/tcg/tcg.c
@@ -1808,7 +1808,11 @@ static inline TCGReg tcg_regset_first(TCGRegSet d)
     }
 }
 
-static void tcg_dump_ops(TCGContext *s, bool have_prefs)
+/* Return only the number of characters output -- no error return. */
+#define ne_fprintf(...) \
+    ({ int ret_ = fprintf(__VA_ARGS__); ret_ >= 0 ? ret_ : 0; })
+
+static void tcg_dump_ops(TCGContext *s, FILE *f, bool have_prefs)
 {
     char buf[128];
     TCGOp *op;
@@ -1824,7 +1828,7 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
 
         if (c == INDEX_op_insn_start) {
             nb_oargs = 0;
-            col += qemu_log("\n ----");
+            col += ne_fprintf(f, "\n ----");
 
             for (i = 0; i < TARGET_INSN_START_WORDS; ++i) {
                 target_ulong a;
@@ -1833,7 +1837,7 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
 #else
                 a = op->args[i];
 #endif
-                col += qemu_log(" " TARGET_FMT_lx, a);
+                col += ne_fprintf(f, " " TARGET_FMT_lx, a);
             }
         } else if (c == INDEX_op_call) {
             const TCGHelperInfo *info = tcg_call_info(op);
@@ -1844,7 +1848,7 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
             nb_iargs = TCGOP_CALLI(op);
             nb_cargs = def->nb_cargs;
 
-            col += qemu_log(" %s ", def->name);
+            col += ne_fprintf(f, " %s ", def->name);
 
             /*
              * Print the function name from TCGHelperInfo, if available.
@@ -1852,15 +1856,15 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
              * but the actual function pointer comes from the plugin.
              */
             if (func == info->func) {
-                col += qemu_log("%s", info->name);
+                col += ne_fprintf(f, "%s", info->name);
             } else {
-                col += qemu_log("plugin(%p)", func);
+                col += ne_fprintf(f, "plugin(%p)", func);
             }
 
-            col += qemu_log(",$0x%x,$%d", info->flags, nb_oargs);
+            col += ne_fprintf(f, ",$0x%x,$%d", info->flags, nb_oargs);
             for (i = 0; i < nb_oargs; i++) {
-                col += qemu_log(",%s", tcg_get_arg_str(s, buf, sizeof(buf),
-                                                       op->args[i]));
+                col += ne_fprintf(f, ",%s", tcg_get_arg_str(s, buf, sizeof(buf),
+                                                            op->args[i]));
             }
             for (i = 0; i < nb_iargs; i++) {
                 TCGArg arg = op->args[nb_oargs + i];
@@ -1868,34 +1872,32 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
                 if (arg != TCG_CALL_DUMMY_ARG) {
                     t = tcg_get_arg_str(s, buf, sizeof(buf), arg);
                 }
-                col += qemu_log(",%s", t);
+                col += ne_fprintf(f, ",%s", t);
             }
         } else {
-            col += qemu_log(" %s ", def->name);
+            col += ne_fprintf(f, " %s ", def->name);
 
             nb_oargs = def->nb_oargs;
             nb_iargs = def->nb_iargs;
             nb_cargs = def->nb_cargs;
 
             if (def->flags & TCG_OPF_VECTOR) {
-                col += qemu_log("v%d,e%d,", 64 << TCGOP_VECL(op),
-                                8 << TCGOP_VECE(op));
+                col += ne_fprintf(f, "v%d,e%d,", 64 << TCGOP_VECL(op),
+                                  8 << TCGOP_VECE(op));
             }
 
             k = 0;
             for (i = 0; i < nb_oargs; i++) {
-                if (k != 0) {
-                    col += qemu_log(",");
-                }
-                col += qemu_log("%s", tcg_get_arg_str(s, buf, sizeof(buf),
-                                                      op->args[k++]));
+                const char *sep =  k ? "," : "";
+                col += ne_fprintf(f, "%s%s", sep,
+                                  tcg_get_arg_str(s, buf, sizeof(buf),
+                                                  op->args[k++]));
             }
             for (i = 0; i < nb_iargs; i++) {
-                if (k != 0) {
-                    col += qemu_log(",");
-                }
-                col += qemu_log("%s", tcg_get_arg_str(s, buf, sizeof(buf),
-                                                      op->args[k++]));
+                const char *sep =  k ? "," : "";
+                col += ne_fprintf(f, "%s%s", sep,
+                                  tcg_get_arg_str(s, buf, sizeof(buf),
+                                                  op->args[k++]));
             }
             switch (c) {
             case INDEX_op_brcond_i32:
@@ -1910,9 +1912,9 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
             case INDEX_op_cmpsel_vec:
                 if (op->args[k] < ARRAY_SIZE(cond_name)
                     && cond_name[op->args[k]]) {
-                    col += qemu_log(",%s", cond_name[op->args[k++]]);
+                    col += ne_fprintf(f, ",%s", cond_name[op->args[k++]]);
                 } else {
-                    col += qemu_log(",$0x%" TCG_PRIlx, op->args[k++]);
+                    col += ne_fprintf(f, ",$0x%" TCG_PRIlx, op->args[k++]);
                 }
                 i = 1;
                 break;
@@ -1927,12 +1929,12 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
                     unsigned ix = get_mmuidx(oi);
 
                     if (op & ~(MO_AMASK | MO_BSWAP | MO_SSIZE)) {
-                        col += qemu_log(",$0x%x,%u", op, ix);
+                        col += ne_fprintf(f, ",$0x%x,%u", op, ix);
                     } else {
                         const char *s_al, *s_op;
                         s_al = alignment_name[(op & MO_AMASK) >> MO_ASHIFT];
                         s_op = ldst_name[op & (MO_BSWAP | MO_SSIZE)];
-                        col += qemu_log(",%s%s,%u", s_al, s_op, ix);
+                        col += ne_fprintf(f, ",%s%s,%u", s_al, s_op, ix);
                     }
                     i = 1;
                 }
@@ -1950,9 +1952,9 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
                         name = bswap_flag_name[flags];
                     }
                     if (name) {
-                        col += qemu_log(",%s", name);
+                        col += ne_fprintf(f, ",%s", name);
                     } else {
-                        col += qemu_log(",$0x%" TCG_PRIlx, flags);
+                        col += ne_fprintf(f, ",$0x%" TCG_PRIlx, flags);
                     }
                     i = k = 1;
                 }
@@ -1967,49 +1969,42 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
             case INDEX_op_brcond_i32:
             case INDEX_op_brcond_i64:
             case INDEX_op_brcond2_i32:
-                col += qemu_log("%s$L%d", k ? "," : "",
-                                arg_label(op->args[k])->id);
+                col += ne_fprintf(f, "%s$L%d", k ? "," : "",
+                                  arg_label(op->args[k])->id);
                 i++, k++;
                 break;
             default:
                 break;
             }
             for (; i < nb_cargs; i++, k++) {
-                col += qemu_log("%s$0x%" TCG_PRIlx, k ? "," : "", op->args[k]);
+                col += ne_fprintf(f, "%s$0x%" TCG_PRIlx, k ? "," : "",
+                                  op->args[k]);
             }
         }
 
         if (have_prefs || op->life) {
-
-            QemuLogFile *logfile;
-
-            rcu_read_lock();
-            logfile = qatomic_rcu_read(&qemu_logfile);
-            if (logfile) {
-                for (; col < 40; ++col) {
-                    putc(' ', logfile->fd);
-                }
+            for (; col < 40; ++col) {
+                putc(' ', f);
             }
-            rcu_read_unlock();
         }
 
         if (op->life) {
             unsigned life = op->life;
 
             if (life & (SYNC_ARG * 3)) {
-                qemu_log("  sync:");
+                ne_fprintf(f, "  sync:");
                 for (i = 0; i < 2; ++i) {
                     if (life & (SYNC_ARG << i)) {
-                        qemu_log(" %d", i);
+                        ne_fprintf(f, " %d", i);
                     }
                 }
             }
             life /= DEAD_ARG;
             if (life) {
-                qemu_log("  dead:");
+                ne_fprintf(f, "  dead:");
                 for (i = 0; life; ++i, life >>= 1) {
                     if (life & 1) {
-                        qemu_log(" %d", i);
+                        ne_fprintf(f, " %d", i);
                     }
                 }
             }
@@ -2020,28 +2015,28 @@ static void tcg_dump_ops(TCGContext *s, bool have_prefs)
                 TCGRegSet set = op->output_pref[i];
 
                 if (i == 0) {
-                    qemu_log("  pref=");
+                    ne_fprintf(f, "  pref=");
                 } else {
-                    qemu_log(",");
+                    ne_fprintf(f, ",");
                 }
                 if (set == 0) {
-                    qemu_log("none");
+                    ne_fprintf(f, "none");
                 } else if (set == MAKE_64BIT_MASK(0, TCG_TARGET_NB_REGS)) {
-                    qemu_log("all");
+                    ne_fprintf(f, "all");
 #ifdef CONFIG_DEBUG_TCG
                 } else if (tcg_regset_single(set)) {
                     TCGReg reg = tcg_regset_first(set);
-                    qemu_log("%s", tcg_target_reg_names[reg]);
+                    ne_fprintf(f, "%s", tcg_target_reg_names[reg]);
 #endif
                 } else if (TCG_TARGET_NB_REGS <= 32) {
-                    qemu_log("%#x", (uint32_t)set);
+                    ne_fprintf(f, "0x%x", (uint32_t)set);
                 } else {
-                    qemu_log("%#" PRIx64, (uint64_t)set);
+                    ne_fprintf(f, "0x%" PRIx64, (uint64_t)set);
                 }
             }
         }
 
-        qemu_log("\n");
+        putc('\n', f);
     }
 }
 
@@ -4207,7 +4202,7 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
         FILE *logfile = qemu_log_trylock();
         if (logfile) {
             fprintf(logfile, "OP:\n");
-            tcg_dump_ops(s, false);
+            tcg_dump_ops(s, logfile, false);
             fprintf(logfile, "\n");
             qemu_log_unlock(logfile);
         }
@@ -4254,7 +4249,7 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
             FILE *logfile = qemu_log_trylock();
             if (logfile) {
                 fprintf(logfile, "OP before indirect lowering:\n");
-                tcg_dump_ops(s, false);
+                tcg_dump_ops(s, logfile, false);
                 fprintf(logfile, "\n");
                 qemu_log_unlock(logfile);
             }
@@ -4277,7 +4272,7 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
         FILE *logfile = qemu_log_trylock();
         if (logfile) {
             fprintf(logfile, "OP after optimization and liveness analysis:\n");
-            tcg_dump_ops(s, true);
+            tcg_dump_ops(s, logfile, true);
             fprintf(logfile, "\n");
             qemu_log_unlock(logfile);
         }
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 12/39] exec/translator: Pass the locked filepointer to disas_log hook
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (10 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 11/39] tcg: Pass the locked filepointer to tcg_dump_ops Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 13/39] exec/log: Remove log_disas and log_target_disas Richard Henderson
                   ` (26 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

We have fetched and locked the logfile in translator_loop.
Pass the filepointer down to the disas_log hook so that it
need not be fetched and locked again.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/exec/translator.h     |  2 +-
 accel/tcg/translator.c        |  2 +-
 target/alpha/translate.c      |  7 ++++---
 target/arm/translate-a64.c    |  6 +++---
 target/arm/translate.c        |  7 ++++---
 target/avr/translate.c        |  7 ++++---
 target/cris/translate.c       |  7 ++++---
 target/hexagon/translate.c    |  7 ++++---
 target/hppa/translate.c       | 15 ++++++++-------
 target/i386/tcg/translate.c   |  6 +++---
 target/m68k/translate.c       |  7 ++++---
 target/microblaze/translate.c |  7 ++++---
 target/mips/tcg/translate.c   |  7 ++++---
 target/nios2/translate.c      |  7 ++++---
 target/openrisc/translate.c   |  7 ++++---
 target/ppc/translate.c        |  7 ++++---
 target/riscv/translate.c      | 10 ++++++----
 target/rx/translate.c         |  7 ++++---
 target/s390x/tcg/translate.c  | 11 ++++++-----
 target/sh4/translate.c        |  7 ++++---
 target/sparc/translate.c      |  7 ++++---
 target/tricore/translate.c    |  7 ++++---
 target/xtensa/translate.c     |  7 ++++---
 23 files changed, 92 insertions(+), 72 deletions(-)

diff --git a/include/exec/translator.h b/include/exec/translator.h
index 9bc46eda59..31d3fa76ff 100644
--- a/include/exec/translator.h
+++ b/include/exec/translator.h
@@ -118,7 +118,7 @@ typedef struct TranslatorOps {
     void (*insn_start)(DisasContextBase *db, CPUState *cpu);
     void (*translate_insn)(DisasContextBase *db, CPUState *cpu);
     void (*tb_stop)(DisasContextBase *db, CPUState *cpu);
-    void (*disas_log)(const DisasContextBase *db, CPUState *cpu);
+    void (*disas_log)(const DisasContextBase *db, CPUState *cpu, FILE *f);
 } TranslatorOps;
 
 /**
diff --git a/accel/tcg/translator.c b/accel/tcg/translator.c
index af8798f98b..fe7af9b943 100644
--- a/accel/tcg/translator.c
+++ b/accel/tcg/translator.c
@@ -142,7 +142,7 @@ void translator_loop(const TranslatorOps *ops, DisasContextBase *db,
         FILE *logfile = qemu_log_trylock();
         if (logfile) {
             fprintf(logfile, "----------------\n");
-            ops->disas_log(db, cpu);
+            ops->disas_log(db, cpu, logfile);
             fprintf(logfile, "\n");
             qemu_log_unlock(logfile);
         }
diff --git a/target/alpha/translate.c b/target/alpha/translate.c
index 66768ab47a..b1f78cff53 100644
--- a/target/alpha/translate.c
+++ b/target/alpha/translate.c
@@ -3027,10 +3027,11 @@ static void alpha_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu)
     }
 }
 
-static void alpha_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu)
+static void alpha_tr_disas_log(const DisasContextBase *dcbase,
+                               CPUState *cpu, FILE *logfile)
 {
-    qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first));
-    log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
+    target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size);
 }
 
 static const TranslatorOps alpha_tr_ops = {
diff --git a/target/arm/translate-a64.c b/target/arm/translate-a64.c
index 9333d7be41..19c09c3b53 100644
--- a/target/arm/translate-a64.c
+++ b/target/arm/translate-a64.c
@@ -14967,12 +14967,12 @@ static void aarch64_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu)
 }
 
 static void aarch64_tr_disas_log(const DisasContextBase *dcbase,
-                                      CPUState *cpu)
+                                 CPUState *cpu, FILE *logfile)
 {
     DisasContext *dc = container_of(dcbase, DisasContext, base);
 
-    qemu_log("IN: %s\n", lookup_symbol(dc->base.pc_first));
-    log_target_disas(cpu, dc->base.pc_first, dc->base.tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dc->base.pc_first));
+    target_disas(logfile, cpu, dc->base.pc_first, dc->base.tb->size);
 }
 
 const TranslatorOps aarch64_translator_ops = {
diff --git a/target/arm/translate.c b/target/arm/translate.c
index bf2196b9e2..783a43b4ae 100644
--- a/target/arm/translate.c
+++ b/target/arm/translate.c
@@ -9891,12 +9891,13 @@ static void arm_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu)
     }
 }
 
-static void arm_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu)
+static void arm_tr_disas_log(const DisasContextBase *dcbase,
+                             CPUState *cpu, FILE *logfile)
 {
     DisasContext *dc = container_of(dcbase, DisasContext, base);
 
-    qemu_log("IN: %s\n", lookup_symbol(dc->base.pc_first));
-    log_target_disas(cpu, dc->base.pc_first, dc->base.tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dc->base.pc_first));
+    target_disas(logfile, cpu, dc->base.pc_first, dc->base.tb->size);
 }
 
 static const TranslatorOps arm_translator_ops = {
diff --git a/target/avr/translate.c b/target/avr/translate.c
index af8a3e0f9c..dc9c3d6bcc 100644
--- a/target/avr/translate.c
+++ b/target/avr/translate.c
@@ -3015,10 +3015,11 @@ static void avr_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs)
     }
 }
 
-static void avr_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs)
+static void avr_tr_disas_log(const DisasContextBase *dcbase,
+                             CPUState *cs, FILE *logfile)
 {
-    qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first));
-    log_target_disas(cs, dcbase->pc_first, dcbase->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
+    target_disas(logfile, cs, dcbase->pc_first, dcbase->tb->size);
 }
 
 static const TranslatorOps avr_tr_ops = {
diff --git a/target/cris/translate.c b/target/cris/translate.c
index 3656cd6db1..ac101344a3 100644
--- a/target/cris/translate.c
+++ b/target/cris/translate.c
@@ -3268,11 +3268,12 @@ static void cris_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu)
     }
 }
 
-static void cris_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu)
+static void cris_tr_disas_log(const DisasContextBase *dcbase,
+                              CPUState *cpu, FILE *logfile)
 {
     if (!DISAS_CRIS) {
-        qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first));
-        log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size);
+        fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
+        target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size);
     }
 }
 
diff --git a/target/hexagon/translate.c b/target/hexagon/translate.c
index 98f1452cad..d4fc92f7e9 100644
--- a/target/hexagon/translate.c
+++ b/target/hexagon/translate.c
@@ -833,10 +833,11 @@ static void hexagon_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu)
     }
 }
 
-static void hexagon_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu)
+static void hexagon_tr_disas_log(const DisasContextBase *dcbase,
+                                 CPUState *cpu, FILE *logfile)
 {
-    qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first));
-    log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
+    target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size);
 }
 
 
diff --git a/target/hppa/translate.c b/target/hppa/translate.c
index 5c0b1eb274..c24d3ce3b8 100644
--- a/target/hppa/translate.c
+++ b/target/hppa/translate.c
@@ -4305,29 +4305,30 @@ static void hppa_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs)
     }
 }
 
-static void hppa_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs)
+static void hppa_tr_disas_log(const DisasContextBase *dcbase,
+                              CPUState *cs, FILE *logfile)
 {
     target_ulong pc = dcbase->pc_first;
 
 #ifdef CONFIG_USER_ONLY
     switch (pc) {
     case 0x00:
-        qemu_log("IN:\n0x00000000:  (null)\n");
+        fprintf(logfile, "IN:\n0x00000000:  (null)\n");
         return;
     case 0xb0:
-        qemu_log("IN:\n0x000000b0:  light-weight-syscall\n");
+        fprintf(logfile, "IN:\n0x000000b0:  light-weight-syscall\n");
         return;
     case 0xe0:
-        qemu_log("IN:\n0x000000e0:  set-thread-pointer-syscall\n");
+        fprintf(logfile, "IN:\n0x000000e0:  set-thread-pointer-syscall\n");
         return;
     case 0x100:
-        qemu_log("IN:\n0x00000100:  syscall\n");
+        fprintf(logfile, "IN:\n0x00000100:  syscall\n");
         return;
     }
 #endif
 
-    qemu_log("IN: %s\n", lookup_symbol(pc));
-    log_target_disas(cs, pc, dcbase->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(pc));
+    target_disas(logfile, cs, pc, dcbase->tb->size);
 }
 
 static const TranslatorOps hppa_tr_ops = {
diff --git a/target/i386/tcg/translate.c b/target/i386/tcg/translate.c
index d71bd2b0f4..4659a212b2 100644
--- a/target/i386/tcg/translate.c
+++ b/target/i386/tcg/translate.c
@@ -8690,12 +8690,12 @@ static void i386_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu)
 }
 
 static void i386_tr_disas_log(const DisasContextBase *dcbase,
-                              CPUState *cpu)
+                              CPUState *cpu, FILE *logfile)
 {
     DisasContext *dc = container_of(dcbase, DisasContext, base);
 
-    qemu_log("IN: %s\n", lookup_symbol(dc->base.pc_first));
-    log_target_disas(cpu, dc->base.pc_first, dc->base.tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dc->base.pc_first));
+    target_disas(logfile, cpu, dc->base.pc_first, dc->base.tb->size);
 }
 
 static const TranslatorOps i386_tr_ops = {
diff --git a/target/m68k/translate.c b/target/m68k/translate.c
index af43c8eab8..4026572ed8 100644
--- a/target/m68k/translate.c
+++ b/target/m68k/translate.c
@@ -6257,10 +6257,11 @@ static void m68k_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu)
     }
 }
 
-static void m68k_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu)
+static void m68k_tr_disas_log(const DisasContextBase *dcbase,
+                              CPUState *cpu, FILE *logfile)
 {
-    qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first));
-    log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
+    target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size);
 }
 
 static const TranslatorOps m68k_tr_ops = {
diff --git a/target/microblaze/translate.c b/target/microblaze/translate.c
index 2561b904b9..bf01384d33 100644
--- a/target/microblaze/translate.c
+++ b/target/microblaze/translate.c
@@ -1833,10 +1833,11 @@ static void mb_tr_tb_stop(DisasContextBase *dcb, CPUState *cs)
     }
 }
 
-static void mb_tr_disas_log(const DisasContextBase *dcb, CPUState *cs)
+static void mb_tr_disas_log(const DisasContextBase *dcb,
+                            CPUState *cs, FILE *logfile)
 {
-    qemu_log("IN: %s\n", lookup_symbol(dcb->pc_first));
-    log_target_disas(cs, dcb->pc_first, dcb->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcb->pc_first));
+    target_disas(logfile, cs, dcb->pc_first, dcb->tb->size);
 }
 
 static const TranslatorOps mb_tr_ops = {
diff --git a/target/mips/tcg/translate.c b/target/mips/tcg/translate.c
index b82a7ec6ad..6de5b66650 100644
--- a/target/mips/tcg/translate.c
+++ b/target/mips/tcg/translate.c
@@ -16141,10 +16141,11 @@ static void mips_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs)
     }
 }
 
-static void mips_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs)
+static void mips_tr_disas_log(const DisasContextBase *dcbase,
+                              CPUState *cs, FILE *logfile)
 {
-    qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first));
-    log_target_disas(cs, dcbase->pc_first, dcbase->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
+    target_disas(logfile, cs, dcbase->pc_first, dcbase->tb->size);
 }
 
 static const TranslatorOps mips_tr_ops = {
diff --git a/target/nios2/translate.c b/target/nios2/translate.c
index f89271dbed..89b97ef520 100644
--- a/target/nios2/translate.c
+++ b/target/nios2/translate.c
@@ -833,10 +833,11 @@ static void nios2_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs)
     }
 }
 
-static void nios2_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu)
+static void nios2_tr_disas_log(const DisasContextBase *dcbase,
+                               CPUState *cpu, FILE *logfile)
 {
-    qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first));
-    log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
+    target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size);
 }
 
 static const TranslatorOps nios2_tr_ops = {
diff --git a/target/openrisc/translate.c b/target/openrisc/translate.c
index ca79e609da..7b8ad43d5f 100644
--- a/target/openrisc/translate.c
+++ b/target/openrisc/translate.c
@@ -1687,12 +1687,13 @@ static void openrisc_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs)
     }
 }
 
-static void openrisc_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs)
+static void openrisc_tr_disas_log(const DisasContextBase *dcbase,
+                                  CPUState *cs, FILE *logfile)
 {
     DisasContext *s = container_of(dcbase, DisasContext, base);
 
-    qemu_log("IN: %s\n", lookup_symbol(s->base.pc_first));
-    log_target_disas(cs, s->base.pc_first, s->base.tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(s->base.pc_first));
+    target_disas(logfile, cs, s->base.pc_first, s->base.tb->size);
 }
 
 static const TranslatorOps openrisc_tr_ops = {
diff --git a/target/ppc/translate.c b/target/ppc/translate.c
index 408ae26173..e0c9f74da4 100644
--- a/target/ppc/translate.c
+++ b/target/ppc/translate.c
@@ -7769,10 +7769,11 @@ static void ppc_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs)
     }
 }
 
-static void ppc_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs)
+static void ppc_tr_disas_log(const DisasContextBase *dcbase,
+                             CPUState *cs, FILE *logfile)
 {
-    qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first));
-    log_target_disas(cs, dcbase->pc_first, dcbase->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
+    target_disas(logfile, cs, dcbase->pc_first, dcbase->tb->size);
 }
 
 static const TranslatorOps ppc_tr_ops = {
diff --git a/target/riscv/translate.c b/target/riscv/translate.c
index fac998a6b5..6495726302 100644
--- a/target/riscv/translate.c
+++ b/target/riscv/translate.c
@@ -1155,18 +1155,20 @@ static void riscv_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu)
     }
 }
 
-static void riscv_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu)
+static void riscv_tr_disas_log(const DisasContextBase *dcbase,
+                               CPUState *cpu, FILE *logfile)
 {
 #ifndef CONFIG_USER_ONLY
     RISCVCPU *rvcpu = RISCV_CPU(cpu);
     CPURISCVState *env = &rvcpu->env;
 #endif
 
-    qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first));
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
 #ifndef CONFIG_USER_ONLY
-    qemu_log("Priv: "TARGET_FMT_ld"; Virt: "TARGET_FMT_ld"\n", env->priv, env->virt);
+    fprintf(logfile, "Priv: "TARGET_FMT_ld"; Virt: "TARGET_FMT_ld"\n",
+            env->priv, env->virt);
 #endif
-    log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size);
+    target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size);
 }
 
 static const TranslatorOps riscv_tr_ops = {
diff --git a/target/rx/translate.c b/target/rx/translate.c
index 5db8f79a82..c8a8991a63 100644
--- a/target/rx/translate.c
+++ b/target/rx/translate.c
@@ -2342,10 +2342,11 @@ static void rx_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs)
     }
 }
 
-static void rx_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs)
+static void rx_tr_disas_log(const DisasContextBase *dcbase,
+                            CPUState *cs, FILE *logfile)
 {
-    qemu_log("IN:\n");  /* , lookup_symbol(dcbase->pc_first)); */
-    log_target_disas(cs, dcbase->pc_first, dcbase->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
+    target_disas(logfile, cs, dcbase->pc_first, dcbase->tb->size);
 }
 
 static const TranslatorOps rx_tr_ops = {
diff --git a/target/s390x/tcg/translate.c b/target/s390x/tcg/translate.c
index 5acfc0ff9b..1e7f470c4b 100644
--- a/target/s390x/tcg/translate.c
+++ b/target/s390x/tcg/translate.c
@@ -6660,16 +6660,17 @@ static void s390x_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs)
     }
 }
 
-static void s390x_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs)
+static void s390x_tr_disas_log(const DisasContextBase *dcbase,
+                               CPUState *cs, FILE *logfile)
 {
     DisasContext *dc = container_of(dcbase, DisasContext, base);
 
     if (unlikely(dc->ex_value)) {
-        /* ??? Unfortunately log_target_disas can't use host memory.  */
-        qemu_log("IN: EXECUTE %016" PRIx64, dc->ex_value);
+        /* ??? Unfortunately target_disas can't use host memory.  */
+        fprintf(logfile, "IN: EXECUTE %016" PRIx64, dc->ex_value);
     } else {
-        qemu_log("IN: %s\n", lookup_symbol(dc->base.pc_first));
-        log_target_disas(cs, dc->base.pc_first, dc->base.tb->size);
+        fprintf(logfile, "IN: %s\n", lookup_symbol(dc->base.pc_first));
+        target_disas(logfile, cs, dc->base.pc_first, dc->base.tb->size);
     }
 }
 
diff --git a/target/sh4/translate.c b/target/sh4/translate.c
index 43bc88b7b3..f1b190e7cf 100644
--- a/target/sh4/translate.c
+++ b/target/sh4/translate.c
@@ -2352,10 +2352,11 @@ static void sh4_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs)
     }
 }
 
-static void sh4_tr_disas_log(const DisasContextBase *dcbase, CPUState *cs)
+static void sh4_tr_disas_log(const DisasContextBase *dcbase,
+                             CPUState *cs, FILE *logfile)
 {
-    qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first));
-    log_target_disas(cs, dcbase->pc_first, dcbase->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
+    target_disas(logfile, cs, dcbase->pc_first, dcbase->tb->size);
 }
 
 static const TranslatorOps sh4_tr_ops = {
diff --git a/target/sparc/translate.c b/target/sparc/translate.c
index 4c7c7b5347..2e28222d31 100644
--- a/target/sparc/translate.c
+++ b/target/sparc/translate.c
@@ -5901,10 +5901,11 @@ static void sparc_tr_tb_stop(DisasContextBase *dcbase, CPUState *cs)
     }
 }
 
-static void sparc_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu)
+static void sparc_tr_disas_log(const DisasContextBase *dcbase,
+                               CPUState *cpu, FILE *logfile)
 {
-    qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first));
-    log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
+    target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size);
 }
 
 static const TranslatorOps sparc_tr_ops = {
diff --git a/target/tricore/translate.c b/target/tricore/translate.c
index 417edbd3f0..d170500fa5 100644
--- a/target/tricore/translate.c
+++ b/target/tricore/translate.c
@@ -8861,10 +8861,11 @@ static void tricore_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu)
     }
 }
 
-static void tricore_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu)
+static void tricore_tr_disas_log(const DisasContextBase *dcbase,
+                                 CPUState *cpu, FILE *logfile)
 {
-    qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first));
-    log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
+    target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size);
 }
 
 static const TranslatorOps tricore_tr_ops = {
diff --git a/target/xtensa/translate.c b/target/xtensa/translate.c
index b1491ed625..a9e69c4153 100644
--- a/target/xtensa/translate.c
+++ b/target/xtensa/translate.c
@@ -1296,10 +1296,11 @@ static void xtensa_tr_tb_stop(DisasContextBase *dcbase, CPUState *cpu)
     }
 }
 
-static void xtensa_tr_disas_log(const DisasContextBase *dcbase, CPUState *cpu)
+static void xtensa_tr_disas_log(const DisasContextBase *dcbase,
+                                CPUState *cpu, FILE *logfile)
 {
-    qemu_log("IN: %s\n", lookup_symbol(dcbase->pc_first));
-    log_target_disas(cpu, dcbase->pc_first, dcbase->tb->size);
+    fprintf(logfile, "IN: %s\n", lookup_symbol(dcbase->pc_first));
+    target_disas(logfile, cpu, dcbase->pc_first, dcbase->tb->size);
 }
 
 static const TranslatorOps xtensa_translator_ops = {
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 13/39] exec/log: Remove log_disas and log_target_disas
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (11 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 12/39] exec/translator: Pass the locked filepointer to disas_log hook Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 14/39] accel/tcg: Use cpu_dump_state between qemu_log_trylock/unlock Richard Henderson
                   ` (25 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

These functions are no longer used.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/exec/log.h | 24 ------------------------
 1 file changed, 24 deletions(-)

diff --git a/include/exec/log.h b/include/exec/log.h
index 648f4d2263..06ab9841ee 100644
--- a/include/exec/log.h
+++ b/include/exec/log.h
@@ -43,30 +43,6 @@ static inline void log_cpu_state_mask(int mask, CPUState *cpu, int flags)
 }
 
 #ifdef NEED_CPU_H
-/* disas() and target_disas() to qemu_logfile: */
-static inline void log_target_disas(CPUState *cpu, target_ulong start,
-                                    target_ulong len)
-{
-    QemuLogFile *logfile;
-    rcu_read_lock();
-    logfile = qatomic_rcu_read(&qemu_logfile);
-    if (logfile) {
-        target_disas(logfile->fd, cpu, start, len);
-    }
-    rcu_read_unlock();
-}
-
-static inline void log_disas(const void *code, unsigned long size)
-{
-    QemuLogFile *logfile;
-    rcu_read_lock();
-    logfile = qatomic_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(const char *operation)
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 14/39] accel/tcg: Use cpu_dump_state between qemu_log_trylock/unlock
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (12 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 13/39] exec/log: Remove log_disas and log_target_disas Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 15/39] target/nios2: Remove log_cpu_state from reset Richard Henderson
                   ` (24 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Inside log_cpu_state, we perform qemu_log_trylock/unlock, which need
not be done if we have already performed the lock beforehand.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 accel/tcg/cpu-exec.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/accel/tcg/cpu-exec.c b/accel/tcg/cpu-exec.c
index 8a896e772d..931643a510 100644
--- a/accel/tcg/cpu-exec.c
+++ b/accel/tcg/cpu-exec.c
@@ -225,7 +225,7 @@ static inline void log_cpu_exec(target_ulong pc, CPUState *cpu,
 #if defined(TARGET_I386)
                 flags |= CPU_DUMP_CCOP;
 #endif
-                log_cpu_state(cpu, flags);
+                cpu_dump_state(cpu, logfile, flags);
                 qemu_log_unlock(logfile);
             }
         }
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 15/39] target/nios2: Remove log_cpu_state from reset
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (13 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 14/39] accel/tcg: Use cpu_dump_state between qemu_log_trylock/unlock Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 16/39] util/log: Use qemu_log_trylock/unlock in qemu_log Richard Henderson
                   ` (23 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee, Philippe Mathieu-Daudé

This is redundant with the logging done in cpu_common_reset.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 target/nios2/cpu.c | 5 -----
 1 file changed, 5 deletions(-)

diff --git a/target/nios2/cpu.c b/target/nios2/cpu.c
index 6975ae4bdb..b0877cb39e 100644
--- a/target/nios2/cpu.c
+++ b/target/nios2/cpu.c
@@ -46,11 +46,6 @@ static void nios2_cpu_reset(DeviceState *dev)
     Nios2CPUClass *ncc = NIOS2_CPU_GET_CLASS(cpu);
     CPUNios2State *env = &cpu->env;
 
-    if (qemu_loglevel_mask(CPU_LOG_RESET)) {
-        qemu_log("CPU Reset (CPU %d)\n", cs->cpu_index);
-        log_cpu_state(cs, 0);
-    }
-
     ncc->parent_reset(dev);
 
     memset(env->regs, 0, sizeof(uint32_t) * NUM_CORE_REGS);
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 16/39] util/log: Use qemu_log_trylock/unlock in qemu_log
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (14 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 15/39] target/nios2: Remove log_cpu_state from reset Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 17/39] util/log: Drop return value from qemu_log Richard Henderson
                   ` (22 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Avoid using QemuLogFile and RCU directly.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 util/log.c | 11 +++++------
 1 file changed, 5 insertions(+), 6 deletions(-)

diff --git a/util/log.c b/util/log.c
index 6b7b358573..090bc3bc39 100644
--- a/util/log.c
+++ b/util/log.c
@@ -62,23 +62,22 @@ void qemu_log_unlock(FILE *fd)
 /* Return the number of characters emitted.  */
 int qemu_log(const char *fmt, ...)
 {
+    FILE *f = qemu_log_trylock();
     int ret = 0;
-    QemuLogFile *logfile;
 
-    rcu_read_lock();
-    logfile = qatomic_rcu_read(&qemu_logfile);
-    if (logfile) {
+    if (f) {
         va_list ap;
+
         va_start(ap, fmt);
-        ret = vfprintf(logfile->fd, fmt, ap);
+        ret = vfprintf(f, fmt, ap);
         va_end(ap);
+        qemu_log_unlock(f);
 
         /* Don't pass back error results.  */
         if (ret < 0) {
             ret = 0;
         }
     }
-    rcu_read_unlock();
     return ret;
 }
 
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 17/39] util/log: Drop return value from qemu_log
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (15 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 16/39] util/log: Use qemu_log_trylock/unlock in qemu_log Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 18/39] util/log: Mark qemu_log_trylock as G_GNUC_WARN_UNUSED_RESULT Richard Henderson
                   ` (21 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

The only user of this feature, tcg_dump_ops, has been
converted to use fprintf directly.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/qemu/log-for-trace.h |  2 +-
 util/log.c                   | 13 ++-----------
 2 files changed, 3 insertions(+), 12 deletions(-)

diff --git a/include/qemu/log-for-trace.h b/include/qemu/log-for-trace.h
index 5e41517227..d47c9cd446 100644
--- a/include/qemu/log-for-trace.h
+++ b/include/qemu/log-for-trace.h
@@ -30,6 +30,6 @@ static inline bool qemu_loglevel_mask(int mask)
 }
 
 /* main logging function */
-int G_GNUC_PRINTF(1, 2) qemu_log(const char *fmt, ...);
+void G_GNUC_PRINTF(1, 2) qemu_log(const char *fmt, ...);
 
 #endif
diff --git a/util/log.c b/util/log.c
index 090bc3bc39..2bd4dfba1b 100644
--- a/util/log.c
+++ b/util/log.c
@@ -59,26 +59,17 @@ void qemu_log_unlock(FILE *fd)
     }
 }
 
-/* Return the number of characters emitted.  */
-int qemu_log(const char *fmt, ...)
+void qemu_log(const char *fmt, ...)
 {
     FILE *f = qemu_log_trylock();
-    int ret = 0;
-
     if (f) {
         va_list ap;
 
         va_start(ap, fmt);
-        ret = vfprintf(f, fmt, ap);
+        vfprintf(f, fmt, ap);
         va_end(ap);
         qemu_log_unlock(f);
-
-        /* Don't pass back error results.  */
-        if (ret < 0) {
-            ret = 0;
-        }
     }
-    return ret;
 }
 
 static void __attribute__((__constructor__)) qemu_logfile_init(void)
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 18/39] util/log: Mark qemu_log_trylock as G_GNUC_WARN_UNUSED_RESULT
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (16 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 17/39] util/log: Drop return value from qemu_log Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:29 ` [PATCH v3 19/39] util/log: Remove qemu_log_flush Richard Henderson
                   ` (20 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Now that all uses have been updated, consider a missing
test of the result of qemu_log_trylock a bug and Werror.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/qemu/log.h | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index 2d9455dc85..3a1f3a6020 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -67,7 +67,7 @@ static inline bool qemu_log_separate(void)
 
 /* Lock/unlock output. */
 
-FILE *qemu_log_trylock(void);
+FILE *qemu_log_trylock(void) G_GNUC_WARN_UNUSED_RESULT;
 void qemu_log_unlock(FILE *fd);
 
 /* Logging functions: */
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 19/39] util/log: Remove qemu_log_flush
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (17 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 18/39] util/log: Mark qemu_log_trylock as G_GNUC_WARN_UNUSED_RESULT Richard Henderson
@ 2022-04-17 18:29 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 20/39] util/log: Drop call to setvbuf Richard Henderson
                   ` (19 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:29 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee, Philippe Mathieu-Daudé

All uses flush output immediately before or after qemu_log_unlock.
Instead of a separate call, move the flush into qemu_log_unlock.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/qemu/log.h        |  2 --
 accel/tcg/translate-all.c |  1 -
 cpu.c                     |  1 -
 hw/net/can/can_sja1000.c  |  1 -
 hw/xen/xen_pvdev.c        |  1 -
 net/can/can_socketcan.c   |  1 -
 tcg/tcg.c                 |  1 -
 util/log.c                | 14 +-------------
 8 files changed, 1 insertion(+), 21 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index 3a1f3a6020..75973111bb 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -121,8 +121,6 @@ int qemu_str_to_log_mask(const char *str);
  */
 void qemu_print_log_usage(FILE *f);
 
-/* fflush() the log file */
-void qemu_log_flush(void);
 /* Close the log file */
 void qemu_log_close(void);
 
diff --git a/accel/tcg/translate-all.c b/accel/tcg/translate-all.c
index 4812619f00..6080ea997a 100644
--- a/accel/tcg/translate-all.c
+++ b/accel/tcg/translate-all.c
@@ -1595,7 +1595,6 @@ TranslationBlock *tb_gen_code(CPUState *cpu,
                 }
             }
             fprintf(logfile, "\n");
-            qemu_log_flush();
             qemu_log_unlock(logfile);
         }
     }
diff --git a/cpu.c b/cpu.c
index 3340bb7538..bfa4db9cd8 100644
--- a/cpu.c
+++ b/cpu.c
@@ -406,7 +406,6 @@ void cpu_abort(CPUState *cpu, const char *fmt, ...)
             vfprintf(logfile, fmt, ap2);
             fprintf(logfile, "\n");
             cpu_dump_state(cpu, logfile, CPU_DUMP_FPU | CPU_DUMP_CCOP);
-            qemu_log_flush();
             qemu_log_unlock(logfile);
         }
         qemu_log_close();
diff --git a/hw/net/can/can_sja1000.c b/hw/net/can/can_sja1000.c
index 23d634af6f..e0f76d3eb3 100644
--- a/hw/net/can/can_sja1000.c
+++ b/hw/net/can/can_sja1000.c
@@ -261,7 +261,6 @@ static void can_display_msg(const char *prefix, const qemu_can_frame *msg)
             fprintf(logfile, " %02X", msg->data[i]);
         }
         fprintf(logfile, "\n");
-        qemu_log_flush();
         qemu_log_unlock(logfile);
     }
 }
diff --git a/hw/xen/xen_pvdev.c b/hw/xen/xen_pvdev.c
index 0423c61158..037152f063 100644
--- a/hw/xen/xen_pvdev.c
+++ b/hw/xen/xen_pvdev.c
@@ -230,7 +230,6 @@ void xen_pv_printf(struct XenLegacyDevice *xendev, int msg_level,
         xen_pv_output_msg(xendev, stderr, fmt, args);
         va_end(args);
     }
-    qemu_log_flush();
 }
 
 void xen_pv_evtchn_event(void *opaque)
diff --git a/net/can/can_socketcan.c b/net/can/can_socketcan.c
index a6388563c3..c1a1ad0563 100644
--- a/net/can/can_socketcan.c
+++ b/net/can/can_socketcan.c
@@ -89,7 +89,6 @@ static void can_host_socketcan_display_msg(struct qemu_can_frame *msg)
             fprintf(logfile, " %02X", msg->data[i]);
         }
         fprintf(logfile, "\n");
-        qemu_log_flush();
         qemu_log_unlock(logfile);
     }
 }
diff --git a/tcg/tcg.c b/tcg/tcg.c
index 70f3b52482..17e9ad2ede 100644
--- a/tcg/tcg.c
+++ b/tcg/tcg.c
@@ -783,7 +783,6 @@ void tcg_prologue_init(TCGContext *s)
                 disas(logfile, s->code_gen_ptr, prologue_size);
             }
             fprintf(logfile, "\n");
-            qemu_log_flush();
             qemu_log_unlock(logfile);
         }
     }
diff --git a/util/log.c b/util/log.c
index 2bd4dfba1b..cab0642a7f 100644
--- a/util/log.c
+++ b/util/log.c
@@ -54,6 +54,7 @@ FILE *qemu_log_trylock(void)
 void qemu_log_unlock(FILE *fd)
 {
     if (fd) {
+        fflush(fd);
         qemu_funlockfile(fd);
         rcu_read_unlock();
     }
@@ -269,19 +270,6 @@ out:
     g_strfreev(ranges);
 }
 
-/* fflush() the log file */
-void qemu_log_flush(void)
-{
-    QemuLogFile *logfile;
-
-    rcu_read_lock();
-    logfile = qatomic_rcu_read(&qemu_logfile);
-    if (logfile) {
-        fflush(logfile->fd);
-    }
-    rcu_read_unlock();
-}
-
 /* Close the log file */
 void qemu_log_close(void)
 {
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 20/39] util/log: Drop call to setvbuf
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (18 preceding siblings ...)
  2022-04-17 18:29 ` [PATCH v3 19/39] util/log: Remove qemu_log_flush Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 21/39] bsd-user: Expand log_page_dump inline Richard Henderson
                   ` (18 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Now that the log buffer is flushed after every qemu_log_unlock,
which includes every call to qemu_log, we do not need to force
line buffering (or unbuffering for windows).  Block buffer the
entire loggable unit.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 util/log.c | 6 ------
 1 file changed, 6 deletions(-)

diff --git a/util/log.c b/util/log.c
index cab0642a7f..caa38e707b 100644
--- a/util/log.c
+++ b/util/log.c
@@ -136,12 +136,6 @@ bool qemu_set_log(int log_flags, Error **errp)
             logfile->fd = stderr;
         }
 
-#if defined(_WIN32)
-        /* Win32 doesn't support line-buffering, so use unbuffered output. */
-        setvbuf(logfile->fd, NULL, _IONBF, 0);
-#else
-        setvbuf(logfile->fd, NULL, _IOLBF, 0);
-#endif
         log_append = 1;
         qatomic_rcu_set(&qemu_logfile, logfile);
     }
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 21/39] bsd-user: Expand log_page_dump inline
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (19 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 20/39] util/log: Drop call to setvbuf Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 22/39] linux-user: " Richard Henderson
                   ` (17 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

We have extra stuff to log at the same time.
Hoist the qemu_log_trylock/unlock to the caller and use fprintf.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 bsd-user/main.c | 35 ++++++++++++++++++++++-------------
 1 file changed, 22 insertions(+), 13 deletions(-)

diff --git a/bsd-user/main.c b/bsd-user/main.c
index 0c8aa1ae90..ed26fc5acb 100644
--- a/bsd-user/main.c
+++ b/bsd-user/main.c
@@ -503,20 +503,29 @@ int main(int argc, char **argv)
     g_free(target_environ);
 
     if (qemu_loglevel_mask(CPU_LOG_PAGE)) {
-        qemu_log("guest_base  %p\n", (void *)guest_base);
-        log_page_dump("binary load");
+        FILE *f = qemu_log_trylock();
+        if (f) {
+            fprintf(f, "guest_base  %p\n", (void *)guest_base);
+            fprintf(f, "page layout changed following binary load\n");
+            page_dump(f);
 
-        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);
-        qemu_log("start_code  0x" TARGET_ABI_FMT_lx "\n",
-                 info->start_code);
-        qemu_log("start_data  0x" TARGET_ABI_FMT_lx "\n",
-                 info->start_data);
-        qemu_log("end_data    0x" TARGET_ABI_FMT_lx "\n", info->end_data);
-        qemu_log("start_stack 0x" TARGET_ABI_FMT_lx "\n",
-                 info->start_stack);
-        qemu_log("brk         0x" TARGET_ABI_FMT_lx "\n", info->brk);
-        qemu_log("entry       0x" TARGET_ABI_FMT_lx "\n", info->entry);
+            fprintf(f, "start_brk   0x" TARGET_ABI_FMT_lx "\n",
+                    info->start_brk);
+            fprintf(f, "end_code    0x" TARGET_ABI_FMT_lx "\n",
+                    info->end_code);
+            fprintf(f, "start_code  0x" TARGET_ABI_FMT_lx "\n",
+                    info->start_code);
+            fprintf(f, "start_data  0x" TARGET_ABI_FMT_lx "\n",
+                    info->start_data);
+            fprintf(f, "end_data    0x" TARGET_ABI_FMT_lx "\n",
+                    info->end_data);
+            fprintf(f, "start_stack 0x" TARGET_ABI_FMT_lx "\n",
+                    info->start_stack);
+            fprintf(f, "brk         0x" TARGET_ABI_FMT_lx "\n", info->brk);
+            fprintf(f, "entry       0x" TARGET_ABI_FMT_lx "\n", info->entry);
+
+            qemu_log_unlock(f);
+        }
     }
 
     /* build Task State */
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 22/39] linux-user: Expand log_page_dump inline
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (20 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 21/39] bsd-user: Expand log_page_dump inline Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 23/39] tests/unit: Do not reference QemuLogFile directly Richard Henderson
                   ` (16 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

We have extra stuff to log at the same time.
Hoist the qemu_log_lock/unlock to the caller and use fprintf.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/exec/log.h | 15 ---------------
 linux-user/main.c  | 43 +++++++++++++++++++++++++++++--------------
 linux-user/mmap.c  |  7 ++++++-
 3 files changed, 35 insertions(+), 30 deletions(-)

diff --git a/include/exec/log.h b/include/exec/log.h
index 06ab9841ee..ad0a40cfeb 100644
--- a/include/exec/log.h
+++ b/include/exec/log.h
@@ -42,19 +42,4 @@ static inline void log_cpu_state_mask(int mask, CPUState *cpu, int flags)
     }
 }
 
-#ifdef NEED_CPU_H
-#if defined(CONFIG_USER_ONLY)
-/* page_dump() output to the log file: */
-static inline void log_page_dump(const char *operation)
-{
-    FILE *logfile = qemu_log_trylock();
-    if (logfile) {
-        fprintf(logfile, "page layout changed following %s\n", operation);
-        page_dump(logfile);
-    }
-    qemu_log_unlock(logfile);
-}
-#endif
-#endif
-
 #endif
diff --git a/linux-user/main.c b/linux-user/main.c
index 6aed4929ab..d263b2a669 100644
--- a/linux-user/main.c
+++ b/linux-user/main.c
@@ -857,21 +857,36 @@ int main(int argc, char **argv, char **envp)
     g_free(target_environ);
 
     if (qemu_loglevel_mask(CPU_LOG_PAGE)) {
-        qemu_log("guest_base  %p\n", (void *)guest_base);
-        log_page_dump("binary load");
+        FILE *f = qemu_log_trylock();
+        if (f) {
+            fprintf(f, "guest_base  %p\n", (void *)guest_base);
+            fprintf(f, "page layout changed following binary load\n");
+            page_dump(f);
 
-        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);
-        qemu_log("start_code  0x" TARGET_ABI_FMT_lx "\n", info->start_code);
-        qemu_log("start_data  0x" TARGET_ABI_FMT_lx "\n", info->start_data);
-        qemu_log("end_data    0x" TARGET_ABI_FMT_lx "\n", info->end_data);
-        qemu_log("start_stack 0x" TARGET_ABI_FMT_lx "\n", info->start_stack);
-        qemu_log("brk         0x" TARGET_ABI_FMT_lx "\n", info->brk);
-        qemu_log("entry       0x" TARGET_ABI_FMT_lx "\n", info->entry);
-        qemu_log("argv_start  0x" TARGET_ABI_FMT_lx "\n", info->arg_start);
-        qemu_log("env_start   0x" TARGET_ABI_FMT_lx "\n",
-                 info->arg_end + (abi_ulong)sizeof(abi_ulong));
-        qemu_log("auxv_start  0x" TARGET_ABI_FMT_lx "\n", info->saved_auxv);
+            fprintf(f, "start_brk   0x" TARGET_ABI_FMT_lx "\n",
+                    info->start_brk);
+            fprintf(f, "end_code    0x" TARGET_ABI_FMT_lx "\n",
+                    info->end_code);
+            fprintf(f, "start_code  0x" TARGET_ABI_FMT_lx "\n",
+                    info->start_code);
+            fprintf(f, "start_data  0x" TARGET_ABI_FMT_lx "\n",
+                    info->start_data);
+            fprintf(f, "end_data    0x" TARGET_ABI_FMT_lx "\n",
+                    info->end_data);
+            fprintf(f, "start_stack 0x" TARGET_ABI_FMT_lx "\n",
+                    info->start_stack);
+            fprintf(f, "brk         0x" TARGET_ABI_FMT_lx "\n",
+                    info->brk);
+            fprintf(f, "entry       0x" TARGET_ABI_FMT_lx "\n",
+                    info->entry);
+            fprintf(f, "argv_start  0x" TARGET_ABI_FMT_lx "\n",
+                    info->arg_start);
+            fprintf(f, "env_start   0x" TARGET_ABI_FMT_lx "\n",
+                    info->arg_end + (abi_ulong)sizeof(abi_ulong));
+            fprintf(f, "auxv_start  0x" TARGET_ABI_FMT_lx "\n",
+                    info->saved_auxv);
+            qemu_log_unlock(f);
+        }
     }
 
     target_set_brk(info->brk);
diff --git a/linux-user/mmap.c b/linux-user/mmap.c
index c125031b90..bbb2c2e178 100644
--- a/linux-user/mmap.c
+++ b/linux-user/mmap.c
@@ -630,7 +630,12 @@ abi_long target_mmap(abi_ulong start, abi_ulong len, int target_prot,
  the_end:
     trace_target_mmap_complete(start);
     if (qemu_loglevel_mask(CPU_LOG_PAGE)) {
-        log_page_dump(__func__);
+        FILE *f = qemu_log_trylock();
+        if (f) {
+            fprintf(f, "page layout changed following mmap\n");
+            page_dump(f);
+            qemu_log_unlock(f);
+        }
     }
     tb_invalidate_phys_range(start, start + len);
     mmap_unlock();
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 23/39] tests/unit: Do not reference QemuLogFile directly
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (21 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 22/39] linux-user: " Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 24/39] include/exec/log: " Richard Henderson
                   ` (15 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Use qemu_log_lock/unlock instead of the raw rcu_read.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 tests/unit/test-logging.c | 33 +++++++++++++++------------------
 1 file changed, 15 insertions(+), 18 deletions(-)

diff --git a/tests/unit/test-logging.c b/tests/unit/test-logging.c
index 54d7e8e33b..dcb8ac70df 100644
--- a/tests/unit/test-logging.c
+++ b/tests/unit/test-logging.c
@@ -110,12 +110,10 @@ static void test_parse_path(gconstpointer data)
 
 static void test_logfile_write(gconstpointer data)
 {
-    QemuLogFile *logfile;
-    QemuLogFile *logfile2;
+    FILE *logfile0, *logfile1;
     gchar const *dir = data;
-    g_autofree gchar *file_path = NULL;
+    g_autofree gchar *file_path0 = NULL;
     g_autofree gchar *file_path1 = NULL;
-    FILE *orig_fd;
 
     /*
      * Before starting test, set log flags, to ensure the file gets
@@ -124,29 +122,28 @@ static void test_logfile_write(gconstpointer data)
      * this is needed.
      */
     qemu_set_log(CPU_LOG_TB_OUT_ASM, &error_abort);
-    file_path = g_build_filename(dir, "qemu_test_log_write0.log", NULL);
+    file_path0 = 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, &error_abort);
-    rcu_read_lock();
-    logfile = qatomic_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);
+    qemu_set_log_filename(file_path0, &error_abort);
+    logfile0 = qemu_log_trylock();
+    g_assert(logfile0);
+    fprintf(logfile0, "%s 1st write to file\n", __func__);
+    fflush(logfile0);
 
     /* Change the logfile and ensure that the handle is still valid. */
     qemu_set_log_filename(file_path1, &error_abort);
-    logfile2 = qatomic_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();
+    logfile1 = qemu_log_trylock();
+    g_assert(logfile1);
+    g_assert(logfile0 != logfile1);
+    fprintf(logfile0, "%s 2nd write to file\n", __func__);
+    fflush(logfile0);
+    qemu_log_unlock(logfile0);
+    qemu_log_unlock(logfile1);
 }
 
 static void test_logfile_lock(gconstpointer data)
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 24/39] include/exec/log: Do not reference QemuLogFile directly
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (22 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 23/39] tests/unit: Do not reference QemuLogFile directly Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-19 10:14   ` Alex Bennée
  2022-04-17 18:30 ` [PATCH v3 25/39] include/qemu/log: Move entire implementation out-of-line Richard Henderson
                   ` (14 subsequent siblings)
  38 siblings, 1 reply; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Use qemu_log_trylock/unlock instead of the raw rcu_read.

Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/exec/log.h | 13 ++++---------
 1 file changed, 4 insertions(+), 9 deletions(-)

diff --git a/include/exec/log.h b/include/exec/log.h
index ad0a40cfeb..4a7375a45f 100644
--- a/include/exec/log.h
+++ b/include/exec/log.h
@@ -15,15 +15,10 @@
  */
 static inline void log_cpu_state(CPUState *cpu, int flags)
 {
-    QemuLogFile *logfile;
-
-    if (qemu_log_enabled()) {
-        rcu_read_lock();
-        logfile = qatomic_rcu_read(&qemu_logfile);
-        if (logfile) {
-            cpu_dump_state(cpu, logfile->fd, flags);
-        }
-        rcu_read_unlock();
+    FILE *f = qemu_log_trylock();
+    if (f) {
+        cpu_dump_state(cpu, f, flags);
+        qemu_log_unlock(f);
     }
 }
 
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 25/39] include/qemu/log: Move entire implementation out-of-line
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (23 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 24/39] include/exec/log: " Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 26/39] sysemu/os-win32: Test for and use _lock_file/_unlock_file Richard Henderson
                   ` (13 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Move QemuLogFile, qemu_logfile, and all inline functions into qemu/log.c.
No need to expose these implementation details in the api.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/qemu/log.h        | 38 ++++----------------------------------
 tests/unit/test-logging.c |  1 +
 util/log.c                | 30 +++++++++++++++++++++++++++++-
 3 files changed, 34 insertions(+), 35 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index 75973111bb..42d545f77a 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -3,46 +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 QemuLogFile *qemu_logfile;
-
 
 /* 
  * The new API:
- *
  */
 
-/* Log settings checking macros: */
+/* Returns true if qemu_log() will really write somewhere. */
+bool qemu_log_enabled(void);
 
-/* Returns true if qemu_log() will really write somewhere
- */
-static inline bool qemu_log_enabled(void)
-{
-    return qemu_logfile != NULL;
-}
-
-/* Returns true if qemu_log() will write somewhere else than stderr
- */
-static inline bool qemu_log_separate(void)
-{
-    QemuLogFile *logfile;
-    bool res = false;
-
-    rcu_read_lock();
-    logfile = qatomic_rcu_read(&qemu_logfile);
-    if (logfile && logfile->fd != stderr) {
-        res = true;
-    }
-    rcu_read_unlock();
-    return res;
-}
+/* Returns true if qemu_log() will write somewhere other than stderr. */
+bool qemu_log_separate(void);
 
 #define CPU_LOG_TB_OUT_ASM (1 << 0)
 #define CPU_LOG_TB_IN_ASM  (1 << 1)
diff --git a/tests/unit/test-logging.c b/tests/unit/test-logging.c
index dcb8ac70df..9b87af75af 100644
--- a/tests/unit/test-logging.c
+++ b/tests/unit/test-logging.c
@@ -30,6 +30,7 @@
 #include "qemu-common.h"
 #include "qapi/error.h"
 #include "qemu/log.h"
+#include "qemu/rcu.h"
 
 static void test_parse_range(void)
 {
diff --git a/util/log.c b/util/log.c
index caa38e707b..8b8b6a5d83 100644
--- a/util/log.c
+++ b/util/log.c
@@ -26,14 +26,42 @@
 #include "trace/control.h"
 #include "qemu/thread.h"
 #include "qemu/lockable.h"
+#include "qemu/rcu.h"
+
+
+typedef struct QemuLogFile {
+    struct rcu_head rcu;
+    FILE *fd;
+} QemuLogFile;
 
 static char *logfilename;
 static QemuMutex qemu_logfile_mutex;
-QemuLogFile *qemu_logfile;
+static QemuLogFile *qemu_logfile;
 int qemu_loglevel;
 static int log_append = 0;
 static GArray *debug_regions;
 
+/* Returns true if qemu_log() will really write somewhere. */
+bool qemu_log_enabled(void)
+{
+    return qemu_logfile != NULL;
+}
+
+/* Returns true if qemu_log() will write somewhere other than stderr. */
+bool qemu_log_separate(void)
+{
+    QemuLogFile *logfile;
+    bool res = false;
+
+    rcu_read_lock();
+    logfile = qatomic_rcu_read(&qemu_logfile);
+    if (logfile && logfile->fd != stderr) {
+        res = true;
+    }
+    rcu_read_unlock();
+    return res;
+}
+
 /* Lock/unlock output. */
 
 FILE *qemu_log_trylock(void)
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 26/39] sysemu/os-win32: Test for and use _lock_file/_unlock_file
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (24 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 25/39] include/qemu/log: Move entire implementation out-of-line Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 27/39] util/log: Introduce qemu_set_log_filename_flags Richard Henderson
                   ` (12 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

The bug referenced in os-win32.h was fixed in mingw-w64 v6.

According to repology, version 5 used by ubuntu 18, which is
not yet out of support, so provide a meson link test for it.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 meson.build               | 12 ++++++++++++
 include/sysemu/os-win32.h | 16 +++++++++-------
 2 files changed, 21 insertions(+), 7 deletions(-)

diff --git a/meson.build b/meson.build
index 861de93c4f..1b8b65f171 100644
--- a/meson.build
+++ b/meson.build
@@ -2054,6 +2054,18 @@ foreach k, v: config_host
   endif
 endforeach
 
+# Older versions of MinGW do not import _lock_file and _unlock_file properly.
+# This was fixed for v6.0.0 with commit b48e3ac8969d.
+if targetos == 'windows'
+  config_host_data.set('HAVE__LOCK_FILE', cc.links('''
+    #include <stdio.h>
+    int main(void) {
+      _lock_file(NULL);
+      _unlock_file(NULL);
+      return 0;
+    }''', name: '_lock_file and _unlock_file'))
+endif
+
 ########################
 # Target configuration #
 ########################
diff --git a/include/sysemu/os-win32.h b/include/sysemu/os-win32.h
index 770752222a..649f417d39 100644
--- a/include/sysemu/os-win32.h
+++ b/include/sysemu/os-win32.h
@@ -113,20 +113,22 @@ static inline char *realpath(const char *path, char *resolved_path)
     return resolved_path;
 }
 
-/* ??? Mingw appears to export _lock_file and _unlock_file as the functions
- * with which to lock a stdio handle.  But something is wrong in the markup,
- * either in the header or the library, such that we get undefined references
- * to "_imp___lock_file" etc when linking.  Since we seem to have no other
- * alternative, and the usage within the logging functions isn't critical,
- * ignore FILE locking.
+/*
+ * Older versions of MinGW do not import _lock_file and _unlock_file properly.
+ * This was fixed for v6.0.0 with commit b48e3ac8969d.
  */
-
 static inline void qemu_flockfile(FILE *f)
 {
+#ifdef HAVE__LOCK_FILE
+    _lock_file(f);
+#endif
 }
 
 static inline void qemu_funlockfile(FILE *f)
 {
+#ifdef HAVE__LOCK_FILE
+    _unlock_file(f);
+#endif
 }
 
 /* We wrap all the sockets functions so that we can
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 27/39] util/log: Introduce qemu_set_log_filename_flags
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (25 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 26/39] sysemu/os-win32: Test for and use _lock_file/_unlock_file Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 28/39] bsd-user: Use qemu_set_log_filename_flags Richard Henderson
                   ` (11 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Provide a function to set both filename and flags at
the same time.  This is the common case at startup.

Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
v2: Return bool, per recommendations in qapi/error.h (phil).
---
 include/qemu/log.h |   1 +
 util/log.c         | 122 ++++++++++++++++++++++++++++-----------------
 2 files changed, 77 insertions(+), 46 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index 42d545f77a..b6c73376b5 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -82,6 +82,7 @@ extern const QEMULogItem qemu_log_items[];
 
 bool qemu_set_log(int log_flags, Error **errp);
 bool qemu_set_log_filename(const char *filename, Error **errp);
+bool qemu_set_log_filename_flags(const char *name, int flags, Error **errp);
 void qemu_set_dfilter_ranges(const char *ranges, Error **errp);
 bool qemu_log_in_addr_range(uint64_t addr);
 int qemu_str_to_log_mask(const char *str);
diff --git a/util/log.c b/util/log.c
index 8b8b6a5d83..2152d5591e 100644
--- a/util/log.c
+++ b/util/log.c
@@ -117,15 +117,58 @@ static void qemu_logfile_free(QemuLogFile *logfile)
 }
 
 /* enable or disable low levels log */
-bool qemu_set_log(int log_flags, Error **errp)
+static bool qemu_set_log_internal(const char *filename, bool changed_name,
+                                  int log_flags, Error **errp)
 {
-    bool need_to_open_file = false;
+    bool need_to_open_file;
     QemuLogFile *logfile;
 
-    qemu_loglevel = log_flags;
+    QEMU_LOCK_GUARD(&qemu_logfile_mutex);
+    logfile = qemu_logfile;
+
+    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
+         */
+        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 format: %s", filename);
+                    return false;
+                }
+                newname = g_strdup_printf(filename, getpid());
+            } else {
+                newname = g_strdup(filename);
+            }
+        }
+
+        g_free(logfilename);
+        logfilename = newname;
+        filename = newname;
+
+        if (logfile) {
+            qatomic_rcu_set(&qemu_logfile, NULL);
+            call_rcu(logfile, qemu_logfile_free, rcu);
+            logfile = NULL;
+        }
+    } else {
+        filename = logfilename;
+    }
+
 #ifdef CONFIG_TRACE_LOG
-    qemu_loglevel |= LOG_TRACE;
+    log_flags |= LOG_TRACE;
 #endif
+    qemu_loglevel = log_flags;
+
     /*
      * In all cases we only log if qemu_loglevel is set.
      * Also:
@@ -134,71 +177,58 @@ bool qemu_set_log(int log_flags, Error **errp)
      *   If we are daemonized,
      *     we will only log if there is a logfilename.
      */
-    if (qemu_loglevel && (!is_daemonized() || logfilename)) {
-        need_to_open_file = true;
-    }
-    QEMU_LOCK_GUARD(&qemu_logfile_mutex);
-    if (qemu_logfile && !need_to_open_file) {
-        logfile = qemu_logfile;
+    need_to_open_file = log_flags && (!is_daemonized() || filename);
+
+    if (logfile && !need_to_open_file) {
         qatomic_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) {
-            logfile->fd = fopen(logfilename, log_append ? "a" : "w");
-            if (!logfile->fd) {
+        return true;
+    }
+    if (!logfile && need_to_open_file) {
+        FILE *fd;
+
+        if (filename) {
+            fd = fopen(filename, log_append ? "a" : "w");
+            if (!fd) {
                 error_setg_errno(errp, errno, "Error opening logfile %s",
-                                 logfilename);
+                                 filename);
                 return false;
             }
             /* In case we are a daemon redirect stderr to logfile */
             if (is_daemonized()) {
-                dup2(fileno(logfile->fd), STDERR_FILENO);
-                fclose(logfile->fd);
+                dup2(fileno(fd), STDERR_FILENO);
+                fclose(fd);
                 /* This will skip closing logfile in qemu_log_close() */
-                logfile->fd = stderr;
+                fd = stderr;
             }
         } else {
             /* Default to stderr if no log file specified */
             assert(!is_daemonized());
-            logfile->fd = stderr;
+            fd = stderr;
         }
 
         log_append = 1;
+
+        logfile = g_new0(QemuLogFile, 1);
+        logfile->fd = fd;
         qatomic_rcu_set(&qemu_logfile, logfile);
     }
     return true;
 }
 
-/*
- * 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
- */
+bool qemu_set_log(int log_flags, Error **errp)
+{
+    return qemu_set_log_internal(NULL, false, log_flags, errp);
+}
+
 bool qemu_set_log_filename(const char *filename, Error **errp)
 {
-    g_free(logfilename);
-    logfilename = NULL;
+    return qemu_set_log_internal(filename, true, qemu_loglevel, 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 format: %s", filename);
-                    return false;
-                } else {
-                    logfilename = g_strdup_printf(filename, getpid());
-                }
-            } else {
-                logfilename = g_strdup(filename);
-            }
-    }
-
-    qemu_log_close();
-    return qemu_set_log(qemu_loglevel, errp);
+bool qemu_set_log_filename_flags(const char *name, int flags, Error **errp)
+{
+    return qemu_set_log_internal(name, true, flags, errp);
 }
 
 /* Returns true if addr is in our debug filter or no filter defined
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 28/39] bsd-user: Use qemu_set_log_filename_flags
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (26 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 27/39] util/log: Introduce qemu_set_log_filename_flags Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 29/39] linux-user: " Richard Henderson
                   ` (10 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Perform all logfile setup in one step.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 bsd-user/main.c | 18 +++++++++---------
 1 file changed, 9 insertions(+), 9 deletions(-)

diff --git a/bsd-user/main.c b/bsd-user/main.c
index ed26fc5acb..aa13eae7f3 100644
--- a/bsd-user/main.c
+++ b/bsd-user/main.c
@@ -405,16 +405,16 @@ int main(int argc, char **argv)
     }
 
     /* init debug */
-    qemu_set_log_filename(log_file, &error_fatal);
-    if (log_mask) {
-        int mask;
-
-        mask = qemu_str_to_log_mask(log_mask);
-        if (!mask) {
-            qemu_print_log_usage(stdout);
-            exit(1);
+    {
+        int mask = 0;
+        if (log_mask) {
+            mask = qemu_str_to_log_mask(log_mask);
+            if (!mask) {
+                qemu_print_log_usage(stdout);
+                exit(1);
+            }
         }
-        qemu_set_log(mask, &error_fatal);
+        qemu_set_log_filename_flags(log_file, mask, &error_fatal);
     }
 
     if (optind >= argc) {
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 29/39] linux-user: Use qemu_set_log_filename_flags
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (27 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 28/39] bsd-user: Use qemu_set_log_filename_flags Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 30/39] softmmu: " Richard Henderson
                   ` (9 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Perform all logfile setup in one step.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 linux-user/main.c | 11 +++++------
 1 file changed, 5 insertions(+), 6 deletions(-)

diff --git a/linux-user/main.c b/linux-user/main.c
index d263b2a669..0297ae8321 100644
--- a/linux-user/main.c
+++ b/linux-user/main.c
@@ -85,6 +85,7 @@ static bool enable_strace;
  * Used to support command line arguments overriding environment variables.
  */
 static int last_log_mask;
+static const char *last_log_filename;
 
 /*
  * When running 32-on-64 we should make sure we can fit all of the possible
@@ -257,7 +258,7 @@ static void handle_arg_dfilter(const char *arg)
 
 static void handle_arg_log_filename(const char *arg)
 {
-    qemu_set_log_filename(arg, &error_fatal);
+    last_log_filename = arg;
 }
 
 static void handle_arg_set_env(const char *arg)
@@ -643,7 +644,6 @@ int main(int argc, char **argv, char **envp)
     int i;
     int ret;
     int execfd;
-    int log_mask;
     unsigned long max_reserved_va;
     bool preserve_argv0;
 
@@ -677,10 +677,9 @@ int main(int argc, char **argv, char **envp)
 
     optind = parse_args(argc, argv);
 
-    log_mask = last_log_mask | (enable_strace ? LOG_STRACE : 0);
-    if (log_mask) {
-        qemu_set_log(log_mask, &error_fatal);
-    }
+    qemu_set_log_filename_flags(last_log_filename,
+                                last_log_mask | (enable_strace * LOG_STRACE),
+                                &error_fatal);
 
     if (!trace_init_backends()) {
         exit(1);
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 30/39] softmmu: Use qemu_set_log_filename_flags
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (28 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 29/39] linux-user: " Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 31/39] util/log: Remove qemu_log_close Richard Henderson
                   ` (8 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Perform all logfile setup at startup in one step.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 softmmu/vl.c | 21 +++++++++------------
 1 file changed, 9 insertions(+), 12 deletions(-)

diff --git a/softmmu/vl.c b/softmmu/vl.c
index a74d0a44a2..65c02963b6 100644
--- a/softmmu/vl.c
+++ b/softmmu/vl.c
@@ -2559,19 +2559,16 @@ static void qemu_process_early_options(void)
 #endif
 
     /* Open the logfile at this point and set the log mask if necessary.  */
-    if (log_file) {
-        qemu_set_log_filename(log_file, &error_fatal);
-    }
-    if (log_mask) {
-        int mask;
-        mask = qemu_str_to_log_mask(log_mask);
-        if (!mask) {
-            qemu_print_log_usage(stdout);
-            exit(1);
+    {
+        int mask = 0;
+        if (log_mask) {
+            mask = qemu_str_to_log_mask(log_mask);
+            if (!mask) {
+                qemu_print_log_usage(stdout);
+                exit(1);
+            }
         }
-        qemu_set_log(mask, &error_fatal);
-    } else {
-        qemu_set_log(0, &error_fatal);
+        qemu_set_log_filename_flags(log_file, mask, &error_fatal);
     }
 
     qemu_add_default_firmwarepath();
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 31/39] util/log: Remove qemu_log_close
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (29 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 30/39] softmmu: " Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 32/39] util/log: Rename logfilename to global_filename Richard Henderson
                   ` (7 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

The only real use is in cpu_abort, where we have just
flushed the file via qemu_log_unlock, and are just about
to force-crash the application via abort.  We do not
really need to close the FILE before the abort.

The two uses in test-logging.c can be handled with
qemu_set_log_filename_flags.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 include/qemu/log.h        |  3 ---
 cpu.c                     |  1 -
 tests/unit/test-logging.c |  4 ++--
 util/log.c                | 17 +----------------
 4 files changed, 3 insertions(+), 22 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index b6c73376b5..a325bca661 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -92,7 +92,4 @@ int qemu_str_to_log_mask(const char *str);
  */
 void qemu_print_log_usage(FILE *f);
 
-/* Close the log file */
-void qemu_log_close(void);
-
 #endif
diff --git a/cpu.c b/cpu.c
index bfa4db9cd8..7df12537d5 100644
--- a/cpu.c
+++ b/cpu.c
@@ -408,7 +408,6 @@ void cpu_abort(CPUState *cpu, const char *fmt, ...)
             cpu_dump_state(cpu, logfile, CPU_DUMP_FPU | CPU_DUMP_CCOP);
             qemu_log_unlock(logfile);
         }
-        qemu_log_close();
     }
     va_end(ap2);
     va_end(ap);
diff --git a/tests/unit/test-logging.c b/tests/unit/test-logging.c
index 9b87af75af..74ec89f1a8 100644
--- a/tests/unit/test-logging.c
+++ b/tests/unit/test-logging.c
@@ -170,7 +170,7 @@ static void test_logfile_lock(gconstpointer data)
      * Initiate a close file and make sure our handle remains
      * valid since we still have the logfile lock.
      */
-    qemu_log_close();
+    qemu_set_log_filename_flags(NULL, 0, &error_abort);
     fprintf(logfile, "%s 2nd write to file\n", __func__);
     fflush(logfile);
     qemu_log_unlock(logfile);
@@ -208,7 +208,7 @@ int main(int argc, char **argv)
                          tmp_path, test_logfile_lock);
 
     rc = g_test_run();
-    qemu_log_close();
+    qemu_set_log_filename_flags(NULL, 0, &error_abort);
     drain_call_rcu();
 
     rmdir_full(tmp_path);
diff --git a/util/log.c b/util/log.c
index 2152d5591e..491a8f97f9 100644
--- a/util/log.c
+++ b/util/log.c
@@ -198,7 +198,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
             if (is_daemonized()) {
                 dup2(fileno(fd), STDERR_FILENO);
                 fclose(fd);
-                /* This will skip closing logfile in qemu_log_close() */
+                /* This will skip closing logfile in qemu_logfile_free. */
                 fd = stderr;
             }
         } else {
@@ -322,21 +322,6 @@ out:
     g_strfreev(ranges);
 }
 
-/* Close the log file */
-void qemu_log_close(void)
-{
-    QemuLogFile *logfile;
-
-    qemu_mutex_lock(&qemu_logfile_mutex);
-    logfile = qemu_logfile;
-
-    if (logfile) {
-        qatomic_rcu_set(&qemu_logfile, NULL);
-        call_rcu(logfile, qemu_logfile_free, rcu);
-    }
-    qemu_mutex_unlock(&qemu_logfile_mutex);
-}
-
 const QEMULogItem qemu_log_items[] = {
     { CPU_LOG_TB_OUT_ASM, "out_asm",
       "show generated host assembly code for each compiled TB" },
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 32/39] util/log: Rename logfilename to global_filename
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (30 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 31/39] util/log: Remove qemu_log_close Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 33/39] util/log: Rename qemu_logfile to global_file Richard Henderson
                   ` (6 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee, Philippe Mathieu-Daudé

Rename to emphasize this is the file-scope global variable.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 util/log.c | 13 ++++++-------
 1 file changed, 6 insertions(+), 7 deletions(-)

diff --git a/util/log.c b/util/log.c
index 491a8f97f9..b3f79deb6c 100644
--- a/util/log.c
+++ b/util/log.c
@@ -34,7 +34,7 @@ typedef struct QemuLogFile {
     FILE *fd;
 } QemuLogFile;
 
-static char *logfilename;
+static char *global_filename;
 static QemuMutex qemu_logfile_mutex;
 static QemuLogFile *qemu_logfile;
 int qemu_loglevel;
@@ -151,8 +151,8 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
             }
         }
 
-        g_free(logfilename);
-        logfilename = newname;
+        g_free(global_filename);
+        global_filename = newname;
         filename = newname;
 
         if (logfile) {
@@ -161,7 +161,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
             logfile = NULL;
         }
     } else {
-        filename = logfilename;
+        filename = global_filename;
     }
 
 #ifdef CONFIG_TRACE_LOG
@@ -173,9 +173,8 @@ 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 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.
+     *     or to a file (if there is a filename).
+     *   If we are daemonized, we will only log if there is a filename.
      */
     need_to_open_file = log_flags && (!is_daemonized() || filename);
 
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 33/39] util/log: Rename qemu_logfile to global_file
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (31 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 32/39] util/log: Rename logfilename to global_filename Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 34/39] util/log: Rename qemu_logfile_mutex to global_mutex Richard Henderson
                   ` (5 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee, Philippe Mathieu-Daudé

Rename to emphasize this is the file-scope global variable.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 util/log.c | 16 ++++++++--------
 1 file changed, 8 insertions(+), 8 deletions(-)

diff --git a/util/log.c b/util/log.c
index b3f79deb6c..425f0064b0 100644
--- a/util/log.c
+++ b/util/log.c
@@ -36,7 +36,7 @@ typedef struct QemuLogFile {
 
 static char *global_filename;
 static QemuMutex qemu_logfile_mutex;
-static QemuLogFile *qemu_logfile;
+static QemuLogFile *global_file;
 int qemu_loglevel;
 static int log_append = 0;
 static GArray *debug_regions;
@@ -44,7 +44,7 @@ static GArray *debug_regions;
 /* Returns true if qemu_log() will really write somewhere. */
 bool qemu_log_enabled(void)
 {
-    return qemu_logfile != NULL;
+    return global_file != NULL;
 }
 
 /* Returns true if qemu_log() will write somewhere other than stderr. */
@@ -54,7 +54,7 @@ bool qemu_log_separate(void)
     bool res = false;
 
     rcu_read_lock();
-    logfile = qatomic_rcu_read(&qemu_logfile);
+    logfile = qatomic_rcu_read(&global_file);
     if (logfile && logfile->fd != stderr) {
         res = true;
     }
@@ -69,7 +69,7 @@ FILE *qemu_log_trylock(void)
     QemuLogFile *logfile;
 
     rcu_read_lock();
-    logfile = qatomic_rcu_read(&qemu_logfile);
+    logfile = qatomic_rcu_read(&global_file);
     if (logfile) {
         qemu_flockfile(logfile->fd);
         return logfile->fd;
@@ -124,7 +124,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
     QemuLogFile *logfile;
 
     QEMU_LOCK_GUARD(&qemu_logfile_mutex);
-    logfile = qemu_logfile;
+    logfile = global_file;
 
     if (changed_name) {
         char *newname = NULL;
@@ -156,7 +156,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
         filename = newname;
 
         if (logfile) {
-            qatomic_rcu_set(&qemu_logfile, NULL);
+            qatomic_rcu_set(&global_file, NULL);
             call_rcu(logfile, qemu_logfile_free, rcu);
             logfile = NULL;
         }
@@ -179,7 +179,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
     need_to_open_file = log_flags && (!is_daemonized() || filename);
 
     if (logfile && !need_to_open_file) {
-        qatomic_rcu_set(&qemu_logfile, NULL);
+        qatomic_rcu_set(&global_file, NULL);
         call_rcu(logfile, qemu_logfile_free, rcu);
         return true;
     }
@@ -210,7 +210,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
 
         logfile = g_new0(QemuLogFile, 1);
         logfile->fd = fd;
-        qatomic_rcu_set(&qemu_logfile, logfile);
+        qatomic_rcu_set(&global_file, logfile);
     }
     return true;
 }
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 34/39] util/log: Rename qemu_logfile_mutex to global_mutex
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (32 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 33/39] util/log: Rename qemu_logfile to global_file Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 35/39] util/log: Hoist the eval of is_daemonized in qemu_set_log_internal Richard Henderson
                   ` (4 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Rename to emphasize this covers the file-scope global variables.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 util/log.c | 10 ++++++----
 1 file changed, 6 insertions(+), 4 deletions(-)

diff --git a/util/log.c b/util/log.c
index 425f0064b0..bb201664ac 100644
--- a/util/log.c
+++ b/util/log.c
@@ -34,9 +34,11 @@ typedef struct QemuLogFile {
     FILE *fd;
 } QemuLogFile;
 
+/* Mutex covering the other global_* variables. */
+static QemuMutex global_mutex;
 static char *global_filename;
-static QemuMutex qemu_logfile_mutex;
 static QemuLogFile *global_file;
+
 int qemu_loglevel;
 static int log_append = 0;
 static GArray *debug_regions;
@@ -101,9 +103,9 @@ void qemu_log(const char *fmt, ...)
     }
 }
 
-static void __attribute__((__constructor__)) qemu_logfile_init(void)
+static void __attribute__((__constructor__)) startup(void)
 {
-    qemu_mutex_init(&qemu_logfile_mutex);
+    qemu_mutex_init(&global_mutex);
 }
 
 static void qemu_logfile_free(QemuLogFile *logfile)
@@ -123,7 +125,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
     bool need_to_open_file;
     QemuLogFile *logfile;
 
-    QEMU_LOCK_GUARD(&qemu_logfile_mutex);
+    QEMU_LOCK_GUARD(&global_mutex);
     logfile = global_file;
 
     if (changed_name) {
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 35/39] util/log: Hoist the eval of is_daemonized in qemu_set_log_internal
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (33 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 34/39] util/log: Rename qemu_logfile_mutex to global_mutex Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 36/39] util/log: Combine two logfile closes Richard Henderson
                   ` (3 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee, Philippe Mathieu-Daudé

Only call is_daemonized once.
We require the result on all paths after this point.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 util/log.c | 8 +++++---
 1 file changed, 5 insertions(+), 3 deletions(-)

diff --git a/util/log.c b/util/log.c
index bb201664ac..631856e231 100644
--- a/util/log.c
+++ b/util/log.c
@@ -123,6 +123,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
                                   int log_flags, Error **errp)
 {
     bool need_to_open_file;
+    bool daemonized;
     QemuLogFile *logfile;
 
     QEMU_LOCK_GUARD(&global_mutex);
@@ -178,7 +179,8 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
      *     or to a file (if there is a filename).
      *   If we are daemonized, we will only log if there is a filename.
      */
-    need_to_open_file = log_flags && (!is_daemonized() || filename);
+    daemonized = is_daemonized();
+    need_to_open_file = log_flags && (!daemonized || filename);
 
     if (logfile && !need_to_open_file) {
         qatomic_rcu_set(&global_file, NULL);
@@ -196,7 +198,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
                 return false;
             }
             /* In case we are a daemon redirect stderr to logfile */
-            if (is_daemonized()) {
+            if (daemonized) {
                 dup2(fileno(fd), STDERR_FILENO);
                 fclose(fd);
                 /* This will skip closing logfile in qemu_logfile_free. */
@@ -204,7 +206,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
             }
         } else {
             /* Default to stderr if no log file specified */
-            assert(!is_daemonized());
+            assert(!daemonized);
             fd = stderr;
         }
 
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 36/39] util/log: Combine two logfile closes
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (34 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 35/39] util/log: Hoist the eval of is_daemonized in qemu_set_log_internal Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 37/39] util/log: Rename QemuLogFile to RCUCloseFILE Richard Henderson
                   ` (2 subsequent siblings)
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Merge the close from the changed_name block with the close
from the !need_to_open_file block.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 util/log.c | 11 +++--------
 1 file changed, 3 insertions(+), 8 deletions(-)

diff --git a/util/log.c b/util/log.c
index 631856e231..21da961d8d 100644
--- a/util/log.c
+++ b/util/log.c
@@ -157,12 +157,6 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
         g_free(global_filename);
         global_filename = newname;
         filename = newname;
-
-        if (logfile) {
-            qatomic_rcu_set(&global_file, NULL);
-            call_rcu(logfile, qemu_logfile_free, rcu);
-            logfile = NULL;
-        }
     } else {
         filename = global_filename;
     }
@@ -182,11 +176,12 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
     daemonized = is_daemonized();
     need_to_open_file = log_flags && (!daemonized || filename);
 
-    if (logfile && !need_to_open_file) {
+    if (logfile && (!need_to_open_file || changed_name)) {
         qatomic_rcu_set(&global_file, NULL);
         call_rcu(logfile, qemu_logfile_free, rcu);
-        return true;
+        logfile = NULL;
     }
+
     if (!logfile && need_to_open_file) {
         FILE *fd;
 
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 37/39] util/log: Rename QemuLogFile to RCUCloseFILE
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (35 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 36/39] util/log: Combine two logfile closes Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 38/39] util/log: Limit RCUCloseFILE to file closing Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 39/39] util/log: Support per-thread log files Richard Henderson
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee, Philippe Mathieu-Daudé

s/QemuLogFile/RCUCloseFILE/
s/qemu_logfile_free/rcu_close_file/

Emphasize that this is only a carrier for passing a pointer
to call_rcu for closing, and not the real logfile.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
 util/log.c | 28 +++++++++++++---------------
 1 file changed, 13 insertions(+), 15 deletions(-)

diff --git a/util/log.c b/util/log.c
index 21da961d8d..eb6e85b2f0 100644
--- a/util/log.c
+++ b/util/log.c
@@ -29,15 +29,15 @@
 #include "qemu/rcu.h"
 
 
-typedef struct QemuLogFile {
+typedef struct RCUCloseFILE {
     struct rcu_head rcu;
     FILE *fd;
-} QemuLogFile;
+} RCUCloseFILE;
 
 /* Mutex covering the other global_* variables. */
 static QemuMutex global_mutex;
 static char *global_filename;
-static QemuLogFile *global_file;
+static RCUCloseFILE *global_file;
 
 int qemu_loglevel;
 static int log_append = 0;
@@ -52,7 +52,7 @@ bool qemu_log_enabled(void)
 /* Returns true if qemu_log() will write somewhere other than stderr. */
 bool qemu_log_separate(void)
 {
-    QemuLogFile *logfile;
+    RCUCloseFILE *logfile;
     bool res = false;
 
     rcu_read_lock();
@@ -68,7 +68,7 @@ bool qemu_log_separate(void)
 
 FILE *qemu_log_trylock(void)
 {
-    QemuLogFile *logfile;
+    RCUCloseFILE *logfile;
 
     rcu_read_lock();
     logfile = qatomic_rcu_read(&global_file);
@@ -108,14 +108,12 @@ static void __attribute__((__constructor__)) startup(void)
     qemu_mutex_init(&global_mutex);
 }
 
-static void qemu_logfile_free(QemuLogFile *logfile)
+static void rcu_close_file(RCUCloseFILE *r)
 {
-    g_assert(logfile);
-
-    if (logfile->fd != stderr) {
-        fclose(logfile->fd);
+    if (r->fd != stderr) {
+        fclose(r->fd);
     }
-    g_free(logfile);
+    g_free(r);
 }
 
 /* enable or disable low levels log */
@@ -124,7 +122,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
 {
     bool need_to_open_file;
     bool daemonized;
-    QemuLogFile *logfile;
+    RCUCloseFILE *logfile;
 
     QEMU_LOCK_GUARD(&global_mutex);
     logfile = global_file;
@@ -178,7 +176,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
 
     if (logfile && (!need_to_open_file || changed_name)) {
         qatomic_rcu_set(&global_file, NULL);
-        call_rcu(logfile, qemu_logfile_free, rcu);
+        call_rcu(logfile, rcu_close_file, rcu);
         logfile = NULL;
     }
 
@@ -196,7 +194,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
             if (daemonized) {
                 dup2(fileno(fd), STDERR_FILENO);
                 fclose(fd);
-                /* This will skip closing logfile in qemu_logfile_free. */
+                /* This will skip closing logfile in rcu_close_file. */
                 fd = stderr;
             }
         } else {
@@ -207,7 +205,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
 
         log_append = 1;
 
-        logfile = g_new0(QemuLogFile, 1);
+        logfile = g_new0(RCUCloseFILE, 1);
         logfile->fd = fd;
         qatomic_rcu_set(&global_file, logfile);
     }
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 38/39] util/log: Limit RCUCloseFILE to file closing
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (36 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 37/39] util/log: Rename QemuLogFile to RCUCloseFILE Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  2022-04-17 18:30 ` [PATCH v3 39/39] util/log: Support per-thread log files Richard Henderson
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

Use FILE* for global_file.  We can perform an rcu_read on that
just as easily as RCUCloseFILE*.  This simplifies a couple of
places, where previously we required taking the rcu_read_lock
simply to avoid racing to dereference RCUCloseFile->fd.

Only allocate the RCUCloseFile prior to call_rcu.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
v2: Work around problem with qatomic_rcu_read vs struct _IO_FILE on musl.
---
 util/log.c | 68 +++++++++++++++++++++++++-----------------------------
 1 file changed, 32 insertions(+), 36 deletions(-)

diff --git a/util/log.c b/util/log.c
index eb6e85b2f0..df0710720f 100644
--- a/util/log.c
+++ b/util/log.c
@@ -37,7 +37,7 @@ typedef struct RCUCloseFILE {
 /* Mutex covering the other global_* variables. */
 static QemuMutex global_mutex;
 static char *global_filename;
-static RCUCloseFILE *global_file;
+static FILE *global_file;
 
 int qemu_loglevel;
 static int log_append = 0;
@@ -46,46 +46,44 @@ static GArray *debug_regions;
 /* Returns true if qemu_log() will really write somewhere. */
 bool qemu_log_enabled(void)
 {
-    return global_file != NULL;
+    return qatomic_read(&global_file) != NULL;
 }
 
 /* Returns true if qemu_log() will write somewhere other than stderr. */
 bool qemu_log_separate(void)
 {
-    RCUCloseFILE *logfile;
-    bool res = false;
-
-    rcu_read_lock();
-    logfile = qatomic_rcu_read(&global_file);
-    if (logfile && logfile->fd != stderr) {
-        res = true;
-    }
-    rcu_read_unlock();
-    return res;
+    FILE *logfile = qatomic_read(&global_file);
+    return logfile && logfile != stderr;
 }
 
 /* Lock/unlock output. */
 
 FILE *qemu_log_trylock(void)
 {
-    RCUCloseFILE *logfile;
+    FILE *logfile;
 
     rcu_read_lock();
-    logfile = qatomic_rcu_read(&global_file);
+    /*
+     * 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->fd);
-        return logfile->fd;
+        qemu_flockfile(logfile);
     } else {
         rcu_read_unlock();
-        return NULL;
     }
+    return logfile;
 }
 
-void qemu_log_unlock(FILE *fd)
+void qemu_log_unlock(FILE *logfile)
 {
-    if (fd) {
-        fflush(fd);
-        qemu_funlockfile(fd);
+    if (logfile) {
+        fflush(logfile);
+        qemu_funlockfile(logfile);
         rcu_read_unlock();
     }
 }
@@ -110,9 +108,7 @@ static void __attribute__((__constructor__)) startup(void)
 
 static void rcu_close_file(RCUCloseFILE *r)
 {
-    if (r->fd != stderr) {
-        fclose(r->fd);
-    }
+    fclose(r->fd);
     g_free(r);
 }
 
@@ -122,7 +118,7 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
 {
     bool need_to_open_file;
     bool daemonized;
-    RCUCloseFILE *logfile;
+    FILE *logfile;
 
     QEMU_LOCK_GUARD(&global_mutex);
     logfile = global_file;
@@ -176,37 +172,37 @@ static bool qemu_set_log_internal(const char *filename, bool changed_name,
 
     if (logfile && (!need_to_open_file || changed_name)) {
         qatomic_rcu_set(&global_file, NULL);
-        call_rcu(logfile, rcu_close_file, rcu);
+        if (logfile != stderr) {
+            RCUCloseFILE *r = g_new0(RCUCloseFILE, 1);
+            r->fd = logfile;
+            call_rcu(r, rcu_close_file, rcu);
+        }
         logfile = NULL;
     }
 
     if (!logfile && need_to_open_file) {
-        FILE *fd;
-
         if (filename) {
-            fd = fopen(filename, log_append ? "a" : "w");
-            if (!fd) {
+            logfile = fopen(filename, log_append ? "a" : "w");
+            if (!logfile) {
                 error_setg_errno(errp, errno, "Error opening logfile %s",
                                  filename);
                 return false;
             }
             /* In case we are a daemon redirect stderr to logfile */
             if (daemonized) {
-                dup2(fileno(fd), STDERR_FILENO);
-                fclose(fd);
+                dup2(fileno(logfile), STDERR_FILENO);
+                fclose(logfile);
                 /* This will skip closing logfile in rcu_close_file. */
-                fd = stderr;
+                logfile = stderr;
             }
         } else {
             /* Default to stderr if no log file specified */
             assert(!daemonized);
-            fd = stderr;
+            logfile = stderr;
         }
 
         log_append = 1;
 
-        logfile = g_new0(RCUCloseFILE, 1);
-        logfile->fd = fd;
         qatomic_rcu_set(&global_file, logfile);
     }
     return true;
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* [PATCH v3 39/39] util/log: Support per-thread log files
  2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
                   ` (37 preceding siblings ...)
  2022-04-17 18:30 ` [PATCH v3 38/39] util/log: Limit RCUCloseFILE to file closing Richard Henderson
@ 2022-04-17 18:30 ` Richard Henderson
  38 siblings, 0 replies; 41+ messages in thread
From: Richard Henderson @ 2022-04-17 18:30 UTC (permalink / raw)
  To: qemu-devel; +Cc: alex.bennee

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.

Reviewed-by: Alex Bennée <alex.bennee@linaro.org>
Signed-off-by: Richard Henderson <richard.henderson@linaro.org>
---
v2: Make use of CONFIG_GETTID, and fallback to SYS_gettid.
v3: Use enum for valid_filename_template (ajb).
---
 include/qemu/log.h |   1 +
 util/log.c         | 163 +++++++++++++++++++++++++++++++++++----------
 2 files changed, 128 insertions(+), 36 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..d6eb0378c3 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,40 @@ 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;
+    if (log_per_thread) {
+        return true;
+    } else {
+        FILE *logfile = qatomic_read(&global_file);
+        return 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 +83,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 +119,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 +149,81 @@ 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.
+ */
+
+typedef enum {
+    vft_error,
+    vft_stderr,
+    vft_strdup,
+    vft_pid_printf,
+} ValidFilenameTemplateResult;
+
+static ValidFilenameTemplateResult
+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 ? vft_strdup : vft_pid_printf;
+        }
+    }
+    if (per_thread) {
+        error_setg(errp, "Filename template with '%%d' required for 'tid'");
+        return vft_error;
+    }
+    return filename ? vft_strdup : vft_stderr;
+}
+
 /* 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 vft_error:
+            return false;
+        case vft_stderr:
+            break;
+        case vft_strdup:
+            newname = g_strdup(filename);
+            break;
+        case vft_pid_printf:
+            newname = g_strdup_printf(filename, getpid());
+            break;
         }
 
         g_free(global_filename);
@@ -153,8 +231,18 @@ 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) == vft_error) {
+            return false;
+        }
     }
 
+    /* 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 +251,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 +443,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 },
 };
 
-- 
2.25.1



^ permalink raw reply related	[flat|nested] 41+ messages in thread

* Re: [PATCH v3 24/39] include/exec/log: Do not reference QemuLogFile directly
  2022-04-17 18:30 ` [PATCH v3 24/39] include/exec/log: " Richard Henderson
@ 2022-04-19 10:14   ` Alex Bennée
  0 siblings, 0 replies; 41+ messages in thread
From: Alex Bennée @ 2022-04-19 10:14 UTC (permalink / raw)
  To: Richard Henderson; +Cc: qemu-devel


Richard Henderson <richard.henderson@linaro.org> writes:

> Use qemu_log_trylock/unlock instead of the raw rcu_read.
>
> Signed-off-by: Richard Henderson <richard.henderson@linaro.org>

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

-- 
Alex Bennée


^ permalink raw reply	[flat|nested] 41+ messages in thread

end of thread, other threads:[~2022-04-19 10:20 UTC | newest]

Thread overview: 41+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-04-17 18:29 [PATCH v3 00/39] Logging cleanup and per-thread logfiles Richard Henderson
2022-04-17 18:29 ` [PATCH v3 01/39] util/log: Drop manual log buffering Richard Henderson
2022-04-17 18:29 ` [PATCH v3 02/39] target/hexagon: Remove qemu_set_log in hexagon_translate_init Richard Henderson
2022-04-17 18:29 ` [PATCH v3 03/39] util/log: Return bool from qemu_set_log_filename Richard Henderson
2022-04-17 18:29 ` [PATCH v3 04/39] util/log: Pass Error pointer to qemu_set_log Richard Henderson
2022-04-17 18:29 ` [PATCH v3 05/39] os-posix: Use qemu_log_enabled Richard Henderson
2022-04-17 18:29 ` [PATCH v3 06/39] util/log: Move qemu_log_lock, qemu_log_unlock out of line Richard Henderson
2022-04-17 18:29 ` [PATCH v3 07/39] util/log: Rename qemu_log_lock to qemu_log_trylock Richard Henderson
2022-04-17 18:29 ` [PATCH v3 08/39] hw/xen: Split out xen_pv_output_msg Richard Henderson
2022-04-17 18:29 ` [PATCH v3 09/39] *: Use fprintf between qemu_log_trylock/unlock Richard Henderson
2022-04-17 18:29 ` [PATCH v3 10/39] util/log: Remove qemu_log_vprintf Richard Henderson
2022-04-17 18:29 ` [PATCH v3 11/39] tcg: Pass the locked filepointer to tcg_dump_ops Richard Henderson
2022-04-17 18:29 ` [PATCH v3 12/39] exec/translator: Pass the locked filepointer to disas_log hook Richard Henderson
2022-04-17 18:29 ` [PATCH v3 13/39] exec/log: Remove log_disas and log_target_disas Richard Henderson
2022-04-17 18:29 ` [PATCH v3 14/39] accel/tcg: Use cpu_dump_state between qemu_log_trylock/unlock Richard Henderson
2022-04-17 18:29 ` [PATCH v3 15/39] target/nios2: Remove log_cpu_state from reset Richard Henderson
2022-04-17 18:29 ` [PATCH v3 16/39] util/log: Use qemu_log_trylock/unlock in qemu_log Richard Henderson
2022-04-17 18:29 ` [PATCH v3 17/39] util/log: Drop return value from qemu_log Richard Henderson
2022-04-17 18:29 ` [PATCH v3 18/39] util/log: Mark qemu_log_trylock as G_GNUC_WARN_UNUSED_RESULT Richard Henderson
2022-04-17 18:29 ` [PATCH v3 19/39] util/log: Remove qemu_log_flush Richard Henderson
2022-04-17 18:30 ` [PATCH v3 20/39] util/log: Drop call to setvbuf Richard Henderson
2022-04-17 18:30 ` [PATCH v3 21/39] bsd-user: Expand log_page_dump inline Richard Henderson
2022-04-17 18:30 ` [PATCH v3 22/39] linux-user: " Richard Henderson
2022-04-17 18:30 ` [PATCH v3 23/39] tests/unit: Do not reference QemuLogFile directly Richard Henderson
2022-04-17 18:30 ` [PATCH v3 24/39] include/exec/log: " Richard Henderson
2022-04-19 10:14   ` Alex Bennée
2022-04-17 18:30 ` [PATCH v3 25/39] include/qemu/log: Move entire implementation out-of-line Richard Henderson
2022-04-17 18:30 ` [PATCH v3 26/39] sysemu/os-win32: Test for and use _lock_file/_unlock_file Richard Henderson
2022-04-17 18:30 ` [PATCH v3 27/39] util/log: Introduce qemu_set_log_filename_flags Richard Henderson
2022-04-17 18:30 ` [PATCH v3 28/39] bsd-user: Use qemu_set_log_filename_flags Richard Henderson
2022-04-17 18:30 ` [PATCH v3 29/39] linux-user: " Richard Henderson
2022-04-17 18:30 ` [PATCH v3 30/39] softmmu: " Richard Henderson
2022-04-17 18:30 ` [PATCH v3 31/39] util/log: Remove qemu_log_close Richard Henderson
2022-04-17 18:30 ` [PATCH v3 32/39] util/log: Rename logfilename to global_filename Richard Henderson
2022-04-17 18:30 ` [PATCH v3 33/39] util/log: Rename qemu_logfile to global_file Richard Henderson
2022-04-17 18:30 ` [PATCH v3 34/39] util/log: Rename qemu_logfile_mutex to global_mutex Richard Henderson
2022-04-17 18:30 ` [PATCH v3 35/39] util/log: Hoist the eval of is_daemonized in qemu_set_log_internal Richard Henderson
2022-04-17 18:30 ` [PATCH v3 36/39] util/log: Combine two logfile closes Richard Henderson
2022-04-17 18:30 ` [PATCH v3 37/39] util/log: Rename QemuLogFile to RCUCloseFILE Richard Henderson
2022-04-17 18:30 ` [PATCH v3 38/39] util/log: Limit RCUCloseFILE to file closing Richard Henderson
2022-04-17 18:30 ` [PATCH v3 39/39] util/log: Support per-thread log files Richard Henderson

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.