[Qemu-devel] [PATCH v7 0/2] log: Make glib logging go through QEMU

[Qemu-devel] [PATCH v7 0/2] log: Make glib logging go through QEMU

[Christophe Fergeau]

The main goal of this patch series is to make logs output by
libspice-server.so go through qemu logging infrastructure so that their
format is the same as the rest of QEMU messages (in particular,
timestamps). This is done in the second patch, the first one is a
preparation patch.

Christophe Fergeau (2):
  qemu-io: Use error_[gs]et_progname()
  log: Make glib logging go through QEMU

 bsd-user/main.c             |  2 ++
 include/qemu/error-report.h |  3 +-
 linux-user/main.c           |  2 ++
 qemu-img.c                  |  2 +-
 qemu-io.c                   | 14 ++++------
 qemu-nbd.c                  |  2 +-
 scsi/qemu-pr-helper.c       |  1 +
 util/qemu-error.c           | 55 ++++++++++++++++++++++++++++++++++++-
 vl.c                        |  2 +-
 9 files changed, 70 insertions(+), 13 deletions(-)

-- 
2.20.1

[Qemu-devel] [PATCH v7 1/2] qemu-io: Use error_[gs]et_progname()

[Christophe Fergeau]

qemu-io reimplements itself what
error_get_progname()/error_set_progname() already does.
This commit switches it to use this API from qemu-error.h

Signed-off-by: Christophe Fergeau <cfergeau@redhat.com>
Reviewed-by: Eric Blake <eblake@redhat.com>
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
---
No changes since v6

 qemu-io.c | 14 ++++++--------
 1 file changed, 6 insertions(+), 8 deletions(-)

diff --git a/qemu-io.c b/qemu-io.c
index 6df7731af4..2c52ac0ade 100644
--- a/qemu-io.c
+++ b/qemu-io.c
@@ -34,8 +34,6 @@
 
 #define CMD_NOFILE_OK   0x01
 
-static char *progname;
-
 static BlockBackend *qemuio_blk;
 static bool quit_qemu_io;
 
@@ -312,7 +310,7 @@ static char *get_prompt(void)
     static char prompt[FILENAME_MAX + 2 /*"> "*/ + 1 /*"\0"*/ ];
 
     if (!prompt[0]) {
-        snprintf(prompt, sizeof(prompt), "%s> ", progname);
+        snprintf(prompt, sizeof(prompt), "%s> ", error_get_progname());
     }
 
     return prompt;
@@ -525,7 +523,7 @@ int main(int argc, char **argv)
 #endif
 
     module_call_init(MODULE_INIT_TRACE);
-    progname = g_path_get_basename(argv[0]);
+    error_set_progname(argv[0]);
     qemu_init_exec_dir(argv[0]);
 
     qcrypto_init(&error_fatal);
@@ -580,10 +578,10 @@ int main(int argc, char **argv)
             break;
         case 'V':
             printf("%s version " QEMU_FULL_VERSION "\n"
-                   QEMU_COPYRIGHT "\n", progname);
+                   QEMU_COPYRIGHT "\n", error_get_progname());
             exit(0);
         case 'h':
-            usage(progname);
+            usage(error_get_progname());
             exit(0);
         case 'U':
             force_share = true;
@@ -600,13 +598,13 @@ int main(int argc, char **argv)
             imageOpts = true;
             break;
         default:
-            usage(progname);
+            usage(error_get_progname());
             exit(1);
         }
     }
 
     if ((argc - optind) > 1) {
-        usage(progname);
+        usage(error_get_progname());
         exit(1);
     }
 
-- 
2.20.1

[Qemu-devel] [PATCH v7 2/2] log: Make glib logging go through QEMU

[Christophe Fergeau]

This commit adds a error_init() helper which calls
g_log_set_default_handler() so that glib logs (g_log, g_warning, ...)
are handled similarly to other QEMU logs. This means they will get a
timestamp if timestamps are enabled, and they will go through the
HMP monitor if one is configured.

This commit also adds a call to error_init() to the binaries
installed by QEMU. Since error_init() also calls error_set_progname(),
this means that *-linux-user, *-bsd-user and qemu-pr-helper messages
output with error_report, info_report, ... will slightly change: they
will be prefixed by the binary name.

glib debug messages are enabled through G_MESSAGES_DEBUG similarly to
the glib default log handler.

At the moment, this change will mostly impact SPICE logging if your
spice version is >= 0.14.1. With older spice versions, this is not going
to work as expected, but will not have any ill effect, so this call is
not conditional on the SPICE version.

Signed-off-by: Christophe Fergeau <cfergeau@redhat.com>
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
---
Changes since v6:
- expanded on the bsd-user/linux-user/qemu-pr-helper changes in the
  commit log
- fix obsolete mention of qemu_init_logging() in commit log
- improved output when 'log_domain' is NULL
- removed unneeded "fall through" comment in switch/case
- fixed multi-line comments

 bsd-user/main.c             |  2 ++
 include/qemu/error-report.h |  3 +-
 linux-user/main.c           |  2 ++
 qemu-img.c                  |  2 +-
 qemu-io.c                   |  2 +-
 qemu-nbd.c                  |  2 +-
 scsi/qemu-pr-helper.c       |  1 +
 util/qemu-error.c           | 55 ++++++++++++++++++++++++++++++++++++-
 vl.c                        |  2 +-
 9 files changed, 65 insertions(+), 6 deletions(-)

diff --git a/bsd-user/main.c b/bsd-user/main.c
index 0d3156974c..8fd8ae4127 100644
--- a/bsd-user/main.c
+++ b/bsd-user/main.c
@@ -24,6 +24,7 @@
 #include "qapi/error.h"
 #include "qemu.h"
 #include "qemu/config-file.h"
+#include "qemu/error-report.h"
 #include "qemu/path.h"
 #include "qemu/help_option.h"
 #include "cpu.h"
@@ -743,6 +744,7 @@ int main(int argc, char **argv)
     if (argc <= 1)
         usage();
 
+    error_init(argv[0]);
     module_call_init(MODULE_INIT_TRACE);
     qemu_init_cpu_list();
     module_call_init(MODULE_INIT_QOM);
diff --git a/include/qemu/error-report.h b/include/qemu/error-report.h
index 0a8d9cc9ea..ce43c02314 100644
--- a/include/qemu/error-report.h
+++ b/include/qemu/error-report.h
@@ -34,7 +34,6 @@ void error_vprintf(const char *fmt, va_list ap) GCC_FMT_ATTR(1, 0);
 void error_printf(const char *fmt, ...) GCC_FMT_ATTR(1, 2);
 void error_vprintf_unless_qmp(const char *fmt, va_list ap) GCC_FMT_ATTR(1, 0);
 void error_printf_unless_qmp(const char *fmt, ...) GCC_FMT_ATTR(1, 2);
-void error_set_progname(const char *argv0);
 
 void error_vreport(const char *fmt, va_list ap) GCC_FMT_ATTR(1, 0);
 void warn_vreport(const char *fmt, va_list ap) GCC_FMT_ATTR(1, 0);
@@ -49,6 +48,8 @@ bool error_report_once_cond(bool *printed, const char *fmt, ...)
 bool warn_report_once_cond(bool *printed, const char *fmt, ...)
     GCC_FMT_ATTR(2, 3);
 
+void error_init(const char *argv0);
+
 /*
  * Similar to error_report(), except it prints the message just once.
  * Return true when it prints, false otherwise.
diff --git a/linux-user/main.c b/linux-user/main.c
index a0aba9cb1e..f9efe9ff6e 100644
--- a/linux-user/main.c
+++ b/linux-user/main.c
@@ -27,6 +27,7 @@
 #include "qemu/path.h"
 #include "qemu/config-file.h"
 #include "qemu/cutils.h"
+#include "qemu/error-report.h"
 #include "qemu/help_option.h"
 #include "cpu.h"
 #include "exec/exec-all.h"
@@ -600,6 +601,7 @@ int main(int argc, char **argv, char **envp)
     int ret;
     int execfd;
 
+    error_init(argv[0]);
     module_call_init(MODULE_INIT_TRACE);
     qemu_init_cpu_list();
     module_call_init(MODULE_INIT_QOM);
diff --git a/qemu-img.c b/qemu-img.c
index ad04f59565..0af9cac244 100644
--- a/qemu-img.c
+++ b/qemu-img.c
@@ -4912,8 +4912,8 @@ int main(int argc, char **argv)
     signal(SIGPIPE, SIG_IGN);
 #endif
 
+    error_init(argv[0]);
     module_call_init(MODULE_INIT_TRACE);
-    error_set_progname(argv[0]);
     qemu_init_exec_dir(argv[0]);
 
     if (qemu_init_main_loop(&local_error)) {
diff --git a/qemu-io.c b/qemu-io.c
index 2c52ac0ade..8d5d5911cb 100644
--- a/qemu-io.c
+++ b/qemu-io.c
@@ -522,8 +522,8 @@ int main(int argc, char **argv)
     signal(SIGPIPE, SIG_IGN);
 #endif
 
+    error_init(argv[0]);
     module_call_init(MODULE_INIT_TRACE);
-    error_set_progname(argv[0]);
     qemu_init_exec_dir(argv[0]);
 
     qcrypto_init(&error_fatal);
diff --git a/qemu-nbd.c b/qemu-nbd.c
index 1f7b2a03f5..39849f1692 100644
--- a/qemu-nbd.c
+++ b/qemu-nbd.c
@@ -685,8 +685,8 @@ int main(int argc, char **argv)
     signal(SIGPIPE, SIG_IGN);
 #endif
 
+    error_init(argv[0]);
     module_call_init(MODULE_INIT_TRACE);
-    error_set_progname(argv[0]);
     qcrypto_init(&error_fatal);
 
     module_call_init(MODULE_INIT_QOM);
diff --git a/scsi/qemu-pr-helper.c b/scsi/qemu-pr-helper.c
index e7af637232..2541fbbd1b 100644
--- a/scsi/qemu-pr-helper.c
+++ b/scsi/qemu-pr-helper.c
@@ -895,6 +895,7 @@ int main(int argc, char **argv)
 
     signal(SIGPIPE, SIG_IGN);
 
+    error_init(argv[0]);
     module_call_init(MODULE_INIT_TRACE);
     module_call_init(MODULE_INIT_QOM);
     qemu_add_opts(&qemu_trace_opts);
diff --git a/util/qemu-error.c b/util/qemu-error.c
index fcbe8a1f74..d08139d9ac 100644
--- a/util/qemu-error.c
+++ b/util/qemu-error.c
@@ -142,7 +142,7 @@ static const char *progname;
 /*
  * Set the program name for error_print_loc().
  */
-void error_set_progname(const char *argv0)
+static void error_set_progname(const char *argv0)
 {
     const char *p = strrchr(argv0, '/');
     progname = p ? p + 1 : argv0;
@@ -345,3 +345,56 @@ bool warn_report_once_cond(bool *printed, const char *fmt, ...)
     va_end(ap);
     return true;
 }
+
+static char *qemu_glog_domains;
+
+static void qemu_log_func(const gchar *log_domain,
+                          GLogLevelFlags log_level,
+                          const gchar *message,
+                          gpointer user_data)
+{
+    switch (log_level & G_LOG_LEVEL_MASK) {
+    case G_LOG_LEVEL_DEBUG:
+    case G_LOG_LEVEL_INFO:
+        /*
+         * Use same G_MESSAGES_DEBUG logic as glib to enable/disable debug
+         * messages
+         */
+        if (qemu_glog_domains == NULL) {
+            break;
+        }
+        if (strcmp(qemu_glog_domains, "all") != 0 &&
+          (log_domain == NULL || !strstr(qemu_glog_domains, log_domain))) {
+            break;
+        }
+        /* Fall through */
+    case G_LOG_LEVEL_MESSAGE:
+        info_report("%s%s%s",
+                    log_domain ?: "", log_domain ? ": " : "", message);
+
+        break;
+    case G_LOG_LEVEL_WARNING:
+        warn_report("%s%s%s",
+                    log_domain ?: "", log_domain ? ": " : "", message);
+        break;
+    case G_LOG_LEVEL_CRITICAL:
+    case G_LOG_LEVEL_ERROR:
+        error_report("%s%s%s",
+                     log_domain ?: "", log_domain ? ": " : "", message);
+        break;
+    }
+}
+
+void error_init(const char *argv0)
+{
+    /* Set the program name for error_print_loc(). */
+    error_set_progname(argv0);
+
+    /*
+     * This sets up glib logging so libraries using it also print their logs
+     * through error_report(), warn_report(), info_report().
+     */
+    g_log_set_default_handler(qemu_log_func, NULL);
+    g_warn_if_fail(qemu_glog_domains == NULL);
+    qemu_glog_domains = g_strdup(g_getenv("G_MESSAGES_DEBUG"));
+}
diff --git a/vl.c b/vl.c
index 9cf0fbe0b8..3d447b84d1 100644
--- a/vl.c
+++ b/vl.c
@@ -3042,6 +3042,7 @@ int main(int argc, char **argv, char **envp)
     QSIMPLEQ_HEAD(, BlockdevOptions_queue) bdo_queue
         = QSIMPLEQ_HEAD_INITIALIZER(bdo_queue);
 
+    error_init(argv[0]);
     module_call_init(MODULE_INIT_TRACE);
 
     qemu_init_cpu_list();
@@ -3050,7 +3051,6 @@ int main(int argc, char **argv, char **envp)
     qemu_mutex_lock_iothread();
 
     atexit(qemu_run_exit_notifiers);
-    error_set_progname(argv[0]);
     qemu_init_exec_dir(argv[0]);
 
     module_call_init(MODULE_INIT_QOM);
-- 
2.20.1

Re: [Qemu-devel] [PATCH v7 1/2] qemu-io: Use error_[gs]et_progname()

[Thomas Huth]

On 31/01/2019 17.46, Christophe Fergeau wrote:
> qemu-io reimplements itself what
> error_get_progname()/error_set_progname() already does.
> This commit switches it to use this API from qemu-error.h
> 
> Signed-off-by: Christophe Fergeau <cfergeau@redhat.com>
> Reviewed-by: Eric Blake <eblake@redhat.com>
> Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>

This patch causes some qemu-iotests to fail now, e.g.:

cd tests/qemu-iotests
./check -qcow2 114
[...]
114 0s ... - output mismatch (see 114.out.bad)
--- /home/thuth/devel/qemu/tests/qemu-iotests/114.out	2019-04-23
16:43:12.000000000 +0200
+++ /home/thuth/tmp/qemu-build/tests/qemu-iotests/114.out.bad	2019-04-25
12:27:47.000000000 +0200
@@ -7,7 +7,7 @@
 cluster_size: 65536
 backing file: TEST_DIR/t.IMGFMT.base
 backing file format: foo
-can't open device TEST_DIR/t.qcow2: Could not open backing file:
Unknown driver 'foo'
+qemu-io: can't open device TEST_DIR/t.qcow2: Could not open backing
file: Unknown driver 'foo'
 no file open, try 'help open'
 read 4096/4096 bytes at offset 0
 4 KiB, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)

Could you please have a look?

 Thomas

Re: [Qemu-devel] [PATCH v7 1/2] qemu-io: Use error_[gs]et_progname()

[Thomas Huth]

On 31/01/2019 17.46, Christophe Fergeau wrote:
> qemu-io reimplements itself what
> error_get_progname()/error_set_progname() already does.
> This commit switches it to use this API from qemu-error.h
> 
> Signed-off-by: Christophe Fergeau <cfergeau@redhat.com>
> Reviewed-by: Eric Blake <eblake@redhat.com>
> Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>

This patch causes some qemu-iotests to fail now, e.g.:

cd tests/qemu-iotests
./check -qcow2 114
[...]
114 0s ... - output mismatch (see 114.out.bad)
--- /home/thuth/devel/qemu/tests/qemu-iotests/114.out	2019-04-23
16:43:12.000000000 +0200
+++ /home/thuth/tmp/qemu-build/tests/qemu-iotests/114.out.bad	2019-04-25
12:27:47.000000000 +0200
@@ -7,7 +7,7 @@
 cluster_size: 65536
 backing file: TEST_DIR/t.IMGFMT.base
 backing file format: foo
-can't open device TEST_DIR/t.qcow2: Could not open backing file:
Unknown driver 'foo'
+qemu-io: can't open device TEST_DIR/t.qcow2: Could not open backing
file: Unknown driver 'foo'
 no file open, try 'help open'
 read 4096/4096 bytes at offset 0
 4 KiB, X ops; XX:XX:XX.X (XXX YYY/sec and XXX ops/sec)

Could you please have a look?

 Thomas