[PATCH v6 26/27] util: add support for formatting thread info in messages

["Daniel P. Berrangé" <berrange@redhat.com>]

The message context is now extended to be able to include the
thread ID and thread name, after the program name. On Linux
the thread ID will match the process TID visible in /proc,
while on other platforms it will merely be an integer repr
of the system thread object address/ID.

This changes the output for both error_report and qemu_log,
when running under the system emulators or the QEMU storage
daemon. Other programs omit the thread information since
they are largely single threaded, though potentially it
would be useful to enable in all of them, given that the RCU
thread will always get spawned by a constructor function.

Before:

  # qemu-system-x86_64 -object tls-creds-x509,id=t0,dir=fish -d 'trace:qcrypto*'
  qemu-system-x86_64: qcrypto_tls_creds_x509_load TLS creds x509 load creds=0x560db818e080 dir=fish
  qemu-system-x86_64: qcrypto_tls_creds_get_path TLS creds path creds=0x560db818e080 filename=ca-cert.pem path=<none>
  qemu-system-x86_64: Unable to access credentials fish/ca-cert.pem: No such file or directory

After:

  # qemu-system-x86_64 -object tls-creds-x509,id=t0,dir=fish -d 'trace:qcrypto*'
  qemu-system-x86_64: (772366:main): qcrypto_tls_creds_x509_load TLS creds x509 load creds=0x560db818e080 dir=fish
  qemu-system-x86_64: (772366:main): qcrypto_tls_creds_get_path TLS creds path creds=0x560db818e080 filename=ca-cert.pem path=<none>
  qemu-system-x86_64: (772366:main): Unable to access credentials fish/ca-cert.pem: No such file or directory

The '-msg thread-info=on|off' argument is introduced to allow this
new default output to be supressed if desired.

Reviewed-by: Richard Henderson <richard.henderson@linaro.org>
Signed-off-by: Daniel P. Berrangé <berrange@redhat.com>
---
 include/qemu/message.h               |  1 +
 qemu-options.hx                      | 10 +++++++---
 storage-daemon/qemu-storage-daemon.c |  6 ++++++
 system/vl.c                          | 17 +++++++++++++++--
 tests/qemu-iotests/041               |  2 +-
 tests/qemu-iotests/common.filter     |  2 +-
 util/message.c                       |  7 +++++++
 7 files changed, 38 insertions(+), 7 deletions(-)

diff --git a/include/qemu/message.h b/include/qemu/message.h
index b8518d06be..2cc092c993 100644
--- a/include/qemu/message.h
+++ b/include/qemu/message.h
@@ -7,6 +7,7 @@ enum QMessageFormatFlags {
     QMESSAGE_FORMAT_TIMESTAMP = (1 << 0),
     QMESSAGE_FORMAT_WORKLOAD_NAME = (1 << 1),
     QMESSAGE_FORMAT_PROGRAM_NAME = (1 << 2),
+    QMESSAGE_FORMAT_THREAD_INFO = (1 << 3),
 };
 
 /**
diff --git a/qemu-options.hx b/qemu-options.hx
index 84dcbb0983..50cbecc7d7 100644
--- a/qemu-options.hx
+++ b/qemu-options.hx
@@ -5515,15 +5515,16 @@ ERST
 
 DEF("msg", HAS_ARG, QEMU_OPTION_msg,
     "-msg [timestamp=on|off][,guest-name=on|off]\n"
-    "     [,program-name=on|off]\n"
+    "     [,program-name=on|off][,thread-info=on|off]\n"
     "                control error message format\n"
     "                timestamp=on enables timestamps (default: off)\n"
     "                guest-name=on enables guest name prefix but only if\n"
     "                              -name guest option is set (default: off)\n"
-    "                program-name=off disables program name prefix (default: on)\n",
+    "                program-name=off disables program name prefix (default: on)\n"
+    "                thread-info=off disables thread ID and name prefix (default: on)\n",
     QEMU_ARCH_ALL)
 SRST
-``-msg [timestamp=on|off][,guest-name=on|off][,program-name=on|off]``
+``-msg [timestamp=on|off][,guest-name=on|off][,program-name=on|off][,thread-info=on|off]``
     Control error message format.
 
     ``timestamp=on|off``
@@ -5535,6 +5536,9 @@ SRST
 
     ``program-name=on|off``
         Prefix messages with the program name. Default is on.
+
+    ``guest-info=on|off``
+        Prefix messages with the thread ID and name. Default is on.
 ERST
 
 DEF("dump-vmstate", HAS_ARG, QEMU_OPTION_dump_vmstate,
diff --git a/storage-daemon/qemu-storage-daemon.c b/storage-daemon/qemu-storage-daemon.c
index eb72561358..cc44ed7848 100644
--- a/storage-daemon/qemu-storage-daemon.c
+++ b/storage-daemon/qemu-storage-daemon.c
@@ -47,6 +47,7 @@
 #include "qemu/cutils.h"
 #include "qemu/config-file.h"
 #include "qemu/error-report.h"
+#include "qemu/message.h"
 #include "qemu/help_option.h"
 #include "qemu/job.h"
 #include "qemu/log.h"
@@ -65,6 +66,10 @@ static const char *pid_file;
 static char *pid_file_realpath;
 static volatile bool exit_requested = false;
 
+#define QMESSAGE_FORMAT_DEFAULT \
+    (QMESSAGE_FORMAT_PROGRAM_NAME | \
+     QMESSAGE_FORMAT_THREAD_INFO)
+
 void qemu_system_killed(int signal, pid_t pid)
 {
     exit_requested = true;
@@ -399,6 +404,7 @@ int main(int argc, char *argv[])
 #endif
 
     error_init(argv[0]);
+    qmessage_set_format(QMESSAGE_FORMAT_DEFAULT);
     qemu_init_exec_dir(argv[0]);
     os_setup_signal_handling();
 
diff --git a/system/vl.c b/system/vl.c
index 3e79bf47e0..bedda94103 100644
--- a/system/vl.c
+++ b/system/vl.c
@@ -145,6 +145,10 @@
 
 #define MAX_VIRTIO_CONSOLES 1
 
+#define QMESSAGE_FORMAT_DEFAULT \
+    (QMESSAGE_FORMAT_PROGRAM_NAME | \
+     QMESSAGE_FORMAT_THREAD_INFO)
+
 typedef struct BlockdevOptionsQueueEntry {
     BlockdevOptions *bdo;
     Location loc;
@@ -387,6 +391,12 @@ static QemuOptsList qemu_msg_opts = {
             .help = "Prepends program name for error messages (enabled "
                     "by default)\n",
         },
+        {
+            .name = "program-name",
+            .type = QEMU_OPT_BOOL,
+            .help = "Prepends current thread ID and name for error messages "
+                    "(enabled by default)\n",
+        },
         { /* end of list */ }
     },
 };
@@ -822,10 +832,9 @@ static void realtime_init(void)
     }
 }
 
-
 static void configure_msg(QemuOpts *opts)
 {
-    int flags = QMESSAGE_FORMAT_PROGRAM_NAME;
+    int flags = QMESSAGE_FORMAT_DEFAULT;
     if (qemu_opt_get_bool(opts, "timestamp", false)) {
         flags |= QMESSAGE_FORMAT_TIMESTAMP;
     }
@@ -835,6 +844,9 @@ static void configure_msg(QemuOpts *opts)
     if (!qemu_opt_get_bool(opts, "program-name", true)) {
         flags &= ~QMESSAGE_FORMAT_PROGRAM_NAME;
     }
+    if (!qemu_opt_get_bool(opts, "thread-info", true)) {
+        flags &= ~QMESSAGE_FORMAT_THREAD_INFO;
+    }
     qmessage_set_format(flags);
 }
 
@@ -2903,6 +2915,7 @@ void qemu_init(int argc, char **argv)
     module_call_init(MODULE_INIT_OPTS);
 
     error_init(argv[0]);
+    qmessage_set_format(QMESSAGE_FORMAT_DEFAULT);
     qemu_init_exec_dir(argv[0]);
 
     os_setup_limits();
diff --git a/tests/qemu-iotests/041 b/tests/qemu-iotests/041
index 8452845f44..dc2666afe7 100755
--- a/tests/qemu-iotests/041
+++ b/tests/qemu-iotests/041
@@ -1102,7 +1102,7 @@ class TestRepairQuorum(iotests.QMPTestCase):
         self.vm.shutdown()
         log = iotests.filter_qtest(self.vm.get_log())
         log = re.sub(r'^Formatting.*\n', '', log)
-        log = re.sub(r'^%s: ' % os.path.basename(iotests.qemu_prog), '', log)
+        log = re.sub(r'^%s: \(\d+:\w+\): ' % os.path.basename(iotests.qemu_prog), '', log)
 
         self.assertEqual(log,
                          "Can no longer replace 'img1' by 'repair0', because " +
diff --git a/tests/qemu-iotests/common.filter b/tests/qemu-iotests/common.filter
index 26e6b45b04..c8cb2e860c 100644
--- a/tests/qemu-iotests/common.filter
+++ b/tests/qemu-iotests/common.filter
@@ -81,7 +81,7 @@ _filter_qemu_io()
 # replace occurrences of QEMU_PROG with "qemu"
 _filter_qemu()
 {
-    gsed -e "s#\\(^\\|(qemu) \\)$(basename $QEMU_PROG):#\1QEMU_PROG:#" \
+    gsed -e "s#\\(^\\|(qemu) \\)$(basename $QEMU_PROG): ([0-9]\+:[-_a-zA-Z]\+):#\1QEMU_PROG:#" \
         -e 's#^QEMU [0-9]\+\.[0-9]\+\.[0-9]\+ monitor#QEMU X.Y.Z monitor#' \
         -e $'s#\r##' # QEMU monitor uses \r\n line endings
 }
diff --git a/util/message.c b/util/message.c
index dd01bf7462..9bf640c8c4 100644
--- a/util/message.c
+++ b/util/message.c
@@ -40,4 +40,11 @@ void qmessage_context_print(FILE *fp)
             fputs(": ", fp);
         }
     }
+
+    if (message_format & QMESSAGE_FORMAT_THREAD_INFO) {
+        int thid = qemu_get_thread_id();
+        const char *thname = qemu_thread_get_name();
+
+        fprintf(fp, "(%d:%s): ", thid, thname);
+    }
 }
-- 
2.53.0