qemu-devel.nongnu.org archive mirror
 help / color / mirror / Atom feed
* [Qemu-devel] [PATCH v5] log: Make glib logging go through QEMU
@ 2019-01-21 17:04 Christophe Fergeau
  2019-01-22 14:13 ` Stefan Hajnoczi
                   ` (2 more replies)
  0 siblings, 3 replies; 9+ messages in thread
From: Christophe Fergeau @ 2019-01-21 17:04 UTC (permalink / raw)
  To: qemu-devel; +Cc: Daniel P . Berrangé, Stefan Hajnoczi

This commit adds a qemu_init_logging() 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
monitor if one is configured.
This commit also adds a call to qemu_init_logging() to the binaries
installed by QEMU.
glib debug messages are enabled through G_MESSAGES_DEBUG similarly to
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: Daniel P. Berrangé <berrange@redhat.com>
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
---
One more iteration of the patch as it hit CI failures
(https://patchew.org/QEMU/20181214105642.673-1-cfergeau@redhat.com/ )
Only difference from v4 is the addition of #include "qemu/error-report.h"
in bsd-user and linux-user.


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

diff --git a/bsd-user/main.c b/bsd-user/main.c
index 0d3156974c..0df5c853d3 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();
 
+    qemu_init_logging();
     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..2852e9df2a 100644
--- a/include/qemu/error-report.h
+++ b/include/qemu/error-report.h
@@ -49,6 +49,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 qemu_init_logging(void);
+
 /*
  * 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..d9b3ffd1f4 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;
 
+    qemu_init_logging();
     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..9214392565 100644
--- a/qemu-img.c
+++ b/qemu-img.c
@@ -4912,6 +4912,7 @@ int main(int argc, char **argv)
     signal(SIGPIPE, SIG_IGN);
 #endif
 
+    qemu_init_logging();
     module_call_init(MODULE_INIT_TRACE);
     error_set_progname(argv[0]);
     qemu_init_exec_dir(argv[0]);
diff --git a/qemu-io.c b/qemu-io.c
index 6df7731af4..ad38d12e68 100644
--- a/qemu-io.c
+++ b/qemu-io.c
@@ -524,6 +524,7 @@ int main(int argc, char **argv)
     signal(SIGPIPE, SIG_IGN);
 #endif
 
+    qemu_init_logging();
     module_call_init(MODULE_INIT_TRACE);
     progname = g_path_get_basename(argv[0]);
     qemu_init_exec_dir(argv[0]);
diff --git a/qemu-nbd.c b/qemu-nbd.c
index 51b55f2e06..274b22d445 100644
--- a/qemu-nbd.c
+++ b/qemu-nbd.c
@@ -581,6 +581,7 @@ int main(int argc, char **argv)
     signal(SIGPIPE, SIG_IGN);
 #endif
 
+    qemu_init_logging();
     module_call_init(MODULE_INIT_TRACE);
     error_set_progname(argv[0]);
     qcrypto_init(&error_fatal);
diff --git a/scsi/qemu-pr-helper.c b/scsi/qemu-pr-helper.c
index e7af637232..523f8b237c 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);
 
+    qemu_init_logging();
     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..1118ed4695 100644
--- a/util/qemu-error.c
+++ b/util/qemu-error.c
@@ -345,3 +345,50 @@ 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:
+        /* 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_INFO:
+        /* Fall through */
+    case G_LOG_LEVEL_MESSAGE:
+        info_report("%s: %s", log_domain, message);
+        break;
+    case G_LOG_LEVEL_WARNING:
+        warn_report("%s: %s", log_domain, message);
+        break;
+    case G_LOG_LEVEL_CRITICAL:
+        /* Fall through */
+    case G_LOG_LEVEL_ERROR:
+        error_report("%s: %s", log_domain, message);
+        break;
+    }
+}
+
+/*
+ * Init QEMU logging subsystem. This sets up glib logging so libraries using it
+ * also print their logs through {info,warn,error}_report.
+ */
+void qemu_init_logging(void)
+{
+    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 bc9fbec654..f03f20e060 100644
--- a/vl.c
+++ b/vl.c
@@ -3039,6 +3039,7 @@ int main(int argc, char **argv, char **envp)
     QSIMPLEQ_HEAD(, BlockdevOptions_queue) bdo_queue
         = QSIMPLEQ_HEAD_INITIALIZER(bdo_queue);
 
+    qemu_init_logging();
     module_call_init(MODULE_INIT_TRACE);
 
     qemu_init_cpu_list();
-- 
2.20.1

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

* Re: [Qemu-devel] [PATCH v5] log: Make glib logging go through QEMU
  2019-01-21 17:04 [Qemu-devel] [PATCH v5] log: Make glib logging go through QEMU Christophe Fergeau
@ 2019-01-22 14:13 ` Stefan Hajnoczi
  2019-01-24  9:38 ` Markus Armbruster
  2019-01-24 16:10 ` Markus Armbruster
  2 siblings, 0 replies; 9+ messages in thread
From: Stefan Hajnoczi @ 2019-01-22 14:13 UTC (permalink / raw)
  To: Christophe Fergeau; +Cc: qemu-devel, Daniel P . Berrangé

[-- Attachment #1: Type: text/plain, Size: 1747 bytes --]

On Mon, Jan 21, 2019 at 06:04:35PM +0100, Christophe Fergeau wrote:
> This commit adds a qemu_init_logging() 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
> monitor if one is configured.
> This commit also adds a call to qemu_init_logging() to the binaries
> installed by QEMU.
> glib debug messages are enabled through G_MESSAGES_DEBUG similarly to
> 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: Daniel P. Berrangé <berrange@redhat.com>
> Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
> ---
> One more iteration of the patch as it hit CI failures
> (https://patchew.org/QEMU/20181214105642.673-1-cfergeau@redhat.com/ )
> Only difference from v4 is the addition of #include "qemu/error-report.h"
> in bsd-user and linux-user.
> 
> 
>  bsd-user/main.c             |  2 ++
>  include/qemu/error-report.h |  2 ++
>  linux-user/main.c           |  2 ++
>  qemu-img.c                  |  1 +
>  qemu-io.c                   |  1 +
>  qemu-nbd.c                  |  1 +
>  scsi/qemu-pr-helper.c       |  1 +
>  util/qemu-error.c           | 47 +++++++++++++++++++++++++++++++++++++
>  vl.c                        |  1 +
>  9 files changed, 58 insertions(+)

Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 455 bytes --]

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

* Re: [Qemu-devel] [PATCH v5] log: Make glib logging go through QEMU
  2019-01-21 17:04 [Qemu-devel] [PATCH v5] log: Make glib logging go through QEMU Christophe Fergeau
  2019-01-22 14:13 ` Stefan Hajnoczi
@ 2019-01-24  9:38 ` Markus Armbruster
  2019-01-24 12:44   ` Christophe Fergeau
  2019-01-24 16:10 ` Markus Armbruster
  2 siblings, 1 reply; 9+ messages in thread
From: Markus Armbruster @ 2019-01-24  9:38 UTC (permalink / raw)
  To: Christophe Fergeau; +Cc: qemu-devel, Stefan Hajnoczi

Christophe Fergeau <cfergeau@redhat.com> writes:

> This commit adds a qemu_init_logging() 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
> monitor if one is configured.
> This commit also adds a call to qemu_init_logging() to the binaries
> installed by QEMU.
> glib debug messages are enabled through G_MESSAGES_DEBUG similarly to
> 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: Daniel P. Berrangé <berrange@redhat.com>
> Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>

Do you expect this to go through my tree?

Hint: if you do, cc'ing me tends to help ;)

scripts/get_maintainer.pl can be your friend.

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

* Re: [Qemu-devel] [PATCH v5] log: Make glib logging go through QEMU
  2019-01-24  9:38 ` Markus Armbruster
@ 2019-01-24 12:44   ` Christophe Fergeau
  2019-01-24 15:23     ` Markus Armbruster
  0 siblings, 1 reply; 9+ messages in thread
From: Christophe Fergeau @ 2019-01-24 12:44 UTC (permalink / raw)
  To: Markus Armbruster; +Cc: qemu-devel, Stefan Hajnoczi

[-- Attachment #1: Type: text/plain, Size: 1619 bytes --]

Hey,

On Thu, Jan 24, 2019 at 10:38:37AM +0100, Markus Armbruster wrote:
> Christophe Fergeau <cfergeau@redhat.com> writes:
> 
> > This commit adds a qemu_init_logging() 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
> > monitor if one is configured.
> > This commit also adds a call to qemu_init_logging() to the binaries
> > installed by QEMU.
> > glib debug messages are enabled through G_MESSAGES_DEBUG similarly to
> > 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: Daniel P. Berrangé <berrange@redhat.com>
> > Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
> 
> Do you expect this to go through my tree?

To be honest, I don't know through whose tree this should go.

> Hint: if you do, cc'ing me tends to help ;)
> 
> scripts/get_maintainer.pl can be your friend.

I ran it, but it returned a few too many names given that it touches
files in various subsystems, I was not sure I should cc: everyone.
Now that I look again, at least "(supporter:Error reporting)" would have
made sense.

Thanks for noticing this patch without the cc: :)

Christophe

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

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

* Re: [Qemu-devel] [PATCH v5] log: Make glib logging go through QEMU
  2019-01-24 12:44   ` Christophe Fergeau
@ 2019-01-24 15:23     ` Markus Armbruster
  0 siblings, 0 replies; 9+ messages in thread
From: Markus Armbruster @ 2019-01-24 15:23 UTC (permalink / raw)
  To: Christophe Fergeau; +Cc: qemu-devel, Stefan Hajnoczi

Christophe Fergeau <cfergeau@redhat.com> writes:

> Hey,
>
> On Thu, Jan 24, 2019 at 10:38:37AM +0100, Markus Armbruster wrote:
>> Christophe Fergeau <cfergeau@redhat.com> writes:
>> 
>> > This commit adds a qemu_init_logging() 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
>> > monitor if one is configured.
>> > This commit also adds a call to qemu_init_logging() to the binaries
>> > installed by QEMU.
>> > glib debug messages are enabled through G_MESSAGES_DEBUG similarly to
>> > 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: Daniel P. Berrangé <berrange@redhat.com>
>> > Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
>> 
>> Do you expect this to go through my tree?
>
> To be honest, I don't know through whose tree this should go.

The bulk of the patch is in qemu-error.c, which suggests my tree.

>> Hint: if you do, cc'ing me tends to help ;)
>> 
>> scripts/get_maintainer.pl can be your friend.
>
> I ran it, but it returned a few too many names given that it touches
> files in various subsystems, I was not sure I should cc: everyone.

You were right to doubt.

> Now that I look again, at least "(supporter:Error reporting)" would have
> made sense.
>
> Thanks for noticing this patch without the cc: :)

No problem :)

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

* Re: [Qemu-devel] [PATCH v5] log: Make glib logging go through QEMU
  2019-01-21 17:04 [Qemu-devel] [PATCH v5] log: Make glib logging go through QEMU Christophe Fergeau
  2019-01-22 14:13 ` Stefan Hajnoczi
  2019-01-24  9:38 ` Markus Armbruster
@ 2019-01-24 16:10 ` Markus Armbruster
  2019-01-24 18:32   ` Dr. David Alan Gilbert
  2019-01-25 17:19   ` Christophe Fergeau
  2 siblings, 2 replies; 9+ messages in thread
From: Markus Armbruster @ 2019-01-24 16:10 UTC (permalink / raw)
  To: Christophe Fergeau; +Cc: qemu-devel, Stefan Hajnoczi, David Alan Gilbert

Christophe Fergeau <cfergeau@redhat.com> writes:

> This commit adds a qemu_init_logging() 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
> monitor if one is configured.

s/monitor/HMP monitor/

I see why one would like to extend the timestamp feature to GLib log
messages.  Routing them through the HMP monitor is perhaps debatable.
Cc: Dave in case he has an opinion.

> This commit also adds a call to qemu_init_logging() to the binaries
> installed by QEMU.
> glib debug messages are enabled through G_MESSAGES_DEBUG similarly to
> 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: Daniel P. Berrangé <berrange@redhat.com>
> Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
> ---
> One more iteration of the patch as it hit CI failures
> (https://patchew.org/QEMU/20181214105642.673-1-cfergeau@redhat.com/ )
> Only difference from v4 is the addition of #include "qemu/error-report.h"
> in bsd-user and linux-user.
>
>
>  bsd-user/main.c             |  2 ++
>  include/qemu/error-report.h |  2 ++
>  linux-user/main.c           |  2 ++
>  qemu-img.c                  |  1 +
>  qemu-io.c                   |  1 +
>  qemu-nbd.c                  |  1 +
>  scsi/qemu-pr-helper.c       |  1 +
>  util/qemu-error.c           | 47 +++++++++++++++++++++++++++++++++++++
>  vl.c                        |  1 +
>  9 files changed, 58 insertions(+)
>
> diff --git a/bsd-user/main.c b/bsd-user/main.c
> index 0d3156974c..0df5c853d3 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();
>  
> +    qemu_init_logging();
>      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..2852e9df2a 100644
> --- a/include/qemu/error-report.h
> +++ b/include/qemu/error-report.h
> @@ -49,6 +49,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 qemu_init_logging(void);
> +
>  /*
>   * 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..d9b3ffd1f4 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;
>  
> +    qemu_init_logging();
>      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..9214392565 100644
> --- a/qemu-img.c
> +++ b/qemu-img.c
> @@ -4912,6 +4912,7 @@ int main(int argc, char **argv)
>      signal(SIGPIPE, SIG_IGN);
>  #endif
>  
> +    qemu_init_logging();
>      module_call_init(MODULE_INIT_TRACE);
>      error_set_progname(argv[0]);
>      qemu_init_exec_dir(argv[0]);
> diff --git a/qemu-io.c b/qemu-io.c
> index 6df7731af4..ad38d12e68 100644
> --- a/qemu-io.c
> +++ b/qemu-io.c
> @@ -524,6 +524,7 @@ int main(int argc, char **argv)
>      signal(SIGPIPE, SIG_IGN);
>  #endif
>  
> +    qemu_init_logging();
>      module_call_init(MODULE_INIT_TRACE);
>      progname = g_path_get_basename(argv[0]);
>      qemu_init_exec_dir(argv[0]);
> diff --git a/qemu-nbd.c b/qemu-nbd.c
> index 51b55f2e06..274b22d445 100644
> --- a/qemu-nbd.c
> +++ b/qemu-nbd.c
> @@ -581,6 +581,7 @@ int main(int argc, char **argv)
>      signal(SIGPIPE, SIG_IGN);
>  #endif
>  
> +    qemu_init_logging();
>      module_call_init(MODULE_INIT_TRACE);
>      error_set_progname(argv[0]);
>      qcrypto_init(&error_fatal);
> diff --git a/scsi/qemu-pr-helper.c b/scsi/qemu-pr-helper.c
> index e7af637232..523f8b237c 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);
>  
> +    qemu_init_logging();
>      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..1118ed4695 100644
> --- a/util/qemu-error.c
> +++ b/util/qemu-error.c
> @@ -345,3 +345,50 @@ 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:
> +        /* Use same G_MESSAGES_DEBUG logic as glib to enable/disable debug
> +         * messages
> +         */

Wing both ends of the comment, please.

> +        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_INFO:
> +        /* Fall through */

g_log_default_handler() applies G_MESSAGES_DEBUG suppression logic to
G_LOG_LEVEL_INFO messages, too.  Do you deviate intentionally?

> +    case G_LOG_LEVEL_MESSAGE:
> +        info_report("%s: %s", log_domain, message);

@log_domain can be null.  You even check for that above.

> +        break;
> +    case G_LOG_LEVEL_WARNING:
> +        warn_report("%s: %s", log_domain, message);
> +        break;
> +    case G_LOG_LEVEL_CRITICAL:
> +        /* Fall through */
> +    case G_LOG_LEVEL_ERROR:
> +        error_report("%s: %s", log_domain, message);
> +        break;

Sure we don't need to check for G_LOG_FLAG_RECURSION?
g_log_default_handler() has a conditional for that...

Not sure it has anything for G_LOG_FLAG_FATAL; it's code is surprisingly
complex.

> +    }
> +}
> +
> +/*
> + * Init QEMU logging subsystem. This sets up glib logging so libraries using it
> + * also print their logs through {info,warn,error}_report.
> + */

Format like the other function comments:

   /*
    * Init QEMU logging subsystem.
    * This sets up glib logging so libraries using it also print their logs
    * through error_report(), warn_report(), info_report().
    */

Braces expanded for better grepability.

> +void qemu_init_logging(void)

Naming is hard...  Yes, this "initializes logging" in a sense: it
installs a GLib default log handler that routes GLib log messages
through this module.  But that's detail; the callers don't care what
this function does, all they care for is "must call early".  If this
module ever grows a need to initialize something else before it gets
used, we'll regret naming its initialization function
qemu_init_logging().

Hmm, it has already grown such a need: initializing @progname.
error_set_progname() does it.  Asking a module's users to call *two*
initializtion functions is not nice.

Fuse the two into error_init(const char *argv0)?

> +{
> +    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 bc9fbec654..f03f20e060 100644
> --- a/vl.c
> +++ b/vl.c
> @@ -3039,6 +3039,7 @@ int main(int argc, char **argv, char **envp)
>      QSIMPLEQ_HEAD(, BlockdevOptions_queue) bdo_queue
>          = QSIMPLEQ_HEAD_INITIALIZER(bdo_queue);
>  
> +    qemu_init_logging();
>      module_call_init(MODULE_INIT_TRACE);
>  
>      qemu_init_cpu_list();

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

* Re: [Qemu-devel] [PATCH v5] log: Make glib logging go through QEMU
  2019-01-24 16:10 ` Markus Armbruster
@ 2019-01-24 18:32   ` Dr. David Alan Gilbert
  2019-01-25  6:57     ` Markus Armbruster
  2019-01-25 17:19   ` Christophe Fergeau
  1 sibling, 1 reply; 9+ messages in thread
From: Dr. David Alan Gilbert @ 2019-01-24 18:32 UTC (permalink / raw)
  To: Markus Armbruster; +Cc: Christophe Fergeau, qemu-devel, Stefan Hajnoczi

* Markus Armbruster (armbru@redhat.com) wrote:
> Christophe Fergeau <cfergeau@redhat.com> writes:
> 
> > This commit adds a qemu_init_logging() 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
> > monitor if one is configured.
> 
> s/monitor/HMP monitor/
> 
> I see why one would like to extend the timestamp feature to GLib log
> messages.  Routing them through the HMP monitor is perhaps debatable.
> Cc: Dave in case he has an opinion.

Yes, it's a little odd; what's wrong with stderr for this type of thing?
My experience has been that things like spice errors are fairly
asynchronous rather than directly triggered by commands, so maybe less
suitable for interleaving in the monitor.

While stderr and hmp output are normally the same, if someone has
HMP wired to a script, I'd assume this is more likely to break it.

Dave

> > This commit also adds a call to qemu_init_logging() to the binaries
> > installed by QEMU.
> > glib debug messages are enabled through G_MESSAGES_DEBUG similarly to
> > 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: Daniel P. Berrangé <berrange@redhat.com>
> > Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
> > ---
> > One more iteration of the patch as it hit CI failures
> > (https://patchew.org/QEMU/20181214105642.673-1-cfergeau@redhat.com/ )
> > Only difference from v4 is the addition of #include "qemu/error-report.h"
> > in bsd-user and linux-user.
> >
> >
> >  bsd-user/main.c             |  2 ++
> >  include/qemu/error-report.h |  2 ++
> >  linux-user/main.c           |  2 ++
> >  qemu-img.c                  |  1 +
> >  qemu-io.c                   |  1 +
> >  qemu-nbd.c                  |  1 +
> >  scsi/qemu-pr-helper.c       |  1 +
> >  util/qemu-error.c           | 47 +++++++++++++++++++++++++++++++++++++
> >  vl.c                        |  1 +
> >  9 files changed, 58 insertions(+)
> >
> > diff --git a/bsd-user/main.c b/bsd-user/main.c
> > index 0d3156974c..0df5c853d3 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();
> >  
> > +    qemu_init_logging();
> >      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..2852e9df2a 100644
> > --- a/include/qemu/error-report.h
> > +++ b/include/qemu/error-report.h
> > @@ -49,6 +49,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 qemu_init_logging(void);
> > +
> >  /*
> >   * 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..d9b3ffd1f4 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;
> >  
> > +    qemu_init_logging();
> >      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..9214392565 100644
> > --- a/qemu-img.c
> > +++ b/qemu-img.c
> > @@ -4912,6 +4912,7 @@ int main(int argc, char **argv)
> >      signal(SIGPIPE, SIG_IGN);
> >  #endif
> >  
> > +    qemu_init_logging();
> >      module_call_init(MODULE_INIT_TRACE);
> >      error_set_progname(argv[0]);
> >      qemu_init_exec_dir(argv[0]);
> > diff --git a/qemu-io.c b/qemu-io.c
> > index 6df7731af4..ad38d12e68 100644
> > --- a/qemu-io.c
> > +++ b/qemu-io.c
> > @@ -524,6 +524,7 @@ int main(int argc, char **argv)
> >      signal(SIGPIPE, SIG_IGN);
> >  #endif
> >  
> > +    qemu_init_logging();
> >      module_call_init(MODULE_INIT_TRACE);
> >      progname = g_path_get_basename(argv[0]);
> >      qemu_init_exec_dir(argv[0]);
> > diff --git a/qemu-nbd.c b/qemu-nbd.c
> > index 51b55f2e06..274b22d445 100644
> > --- a/qemu-nbd.c
> > +++ b/qemu-nbd.c
> > @@ -581,6 +581,7 @@ int main(int argc, char **argv)
> >      signal(SIGPIPE, SIG_IGN);
> >  #endif
> >  
> > +    qemu_init_logging();
> >      module_call_init(MODULE_INIT_TRACE);
> >      error_set_progname(argv[0]);
> >      qcrypto_init(&error_fatal);
> > diff --git a/scsi/qemu-pr-helper.c b/scsi/qemu-pr-helper.c
> > index e7af637232..523f8b237c 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);
> >  
> > +    qemu_init_logging();
> >      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..1118ed4695 100644
> > --- a/util/qemu-error.c
> > +++ b/util/qemu-error.c
> > @@ -345,3 +345,50 @@ 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:
> > +        /* Use same G_MESSAGES_DEBUG logic as glib to enable/disable debug
> > +         * messages
> > +         */
> 
> Wing both ends of the comment, please.
> 
> > +        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_INFO:
> > +        /* Fall through */
> 
> g_log_default_handler() applies G_MESSAGES_DEBUG suppression logic to
> G_LOG_LEVEL_INFO messages, too.  Do you deviate intentionally?
> 
> > +    case G_LOG_LEVEL_MESSAGE:
> > +        info_report("%s: %s", log_domain, message);
> 
> @log_domain can be null.  You even check for that above.
> 
> > +        break;
> > +    case G_LOG_LEVEL_WARNING:
> > +        warn_report("%s: %s", log_domain, message);
> > +        break;
> > +    case G_LOG_LEVEL_CRITICAL:
> > +        /* Fall through */
> > +    case G_LOG_LEVEL_ERROR:
> > +        error_report("%s: %s", log_domain, message);
> > +        break;
> 
> Sure we don't need to check for G_LOG_FLAG_RECURSION?
> g_log_default_handler() has a conditional for that...
> 
> Not sure it has anything for G_LOG_FLAG_FATAL; it's code is surprisingly
> complex.
> 
> > +    }
> > +}
> > +
> > +/*
> > + * Init QEMU logging subsystem. This sets up glib logging so libraries using it
> > + * also print their logs through {info,warn,error}_report.
> > + */
> 
> Format like the other function comments:
> 
>    /*
>     * Init QEMU logging subsystem.
>     * This sets up glib logging so libraries using it also print their logs
>     * through error_report(), warn_report(), info_report().
>     */
> 
> Braces expanded for better grepability.
> 
> > +void qemu_init_logging(void)
> 
> Naming is hard...  Yes, this "initializes logging" in a sense: it
> installs a GLib default log handler that routes GLib log messages
> through this module.  But that's detail; the callers don't care what
> this function does, all they care for is "must call early".  If this
> module ever grows a need to initialize something else before it gets
> used, we'll regret naming its initialization function
> qemu_init_logging().
> 
> Hmm, it has already grown such a need: initializing @progname.
> error_set_progname() does it.  Asking a module's users to call *two*
> initializtion functions is not nice.
> 
> Fuse the two into error_init(const char *argv0)?
> 
> > +{
> > +    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 bc9fbec654..f03f20e060 100644
> > --- a/vl.c
> > +++ b/vl.c
> > @@ -3039,6 +3039,7 @@ int main(int argc, char **argv, char **envp)
> >      QSIMPLEQ_HEAD(, BlockdevOptions_queue) bdo_queue
> >          = QSIMPLEQ_HEAD_INITIALIZER(bdo_queue);
> >  
> > +    qemu_init_logging();
> >      module_call_init(MODULE_INIT_TRACE);
> >  
> >      qemu_init_cpu_list();
--
Dr. David Alan Gilbert / dgilbert@redhat.com / Manchester, UK

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

* Re: [Qemu-devel] [PATCH v5] log: Make glib logging go through QEMU
  2019-01-24 18:32   ` Dr. David Alan Gilbert
@ 2019-01-25  6:57     ` Markus Armbruster
  0 siblings, 0 replies; 9+ messages in thread
From: Markus Armbruster @ 2019-01-25  6:57 UTC (permalink / raw)
  To: Dr. David Alan Gilbert; +Cc: Stefan Hajnoczi, qemu-devel, Christophe Fergeau

"Dr. David Alan Gilbert" <dgilbert@redhat.com> writes:

> * Markus Armbruster (armbru@redhat.com) wrote:
>> Christophe Fergeau <cfergeau@redhat.com> writes:
>> 
>> > This commit adds a qemu_init_logging() 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
>> > monitor if one is configured.
>> 
>> s/monitor/HMP monitor/
>> 
>> I see why one would like to extend the timestamp feature to GLib log
>> messages.  Routing them through the HMP monitor is perhaps debatable.
>> Cc: Dave in case he has an opinion.
>
> Yes, it's a little odd; what's wrong with stderr for this type of thing?
> My experience has been that things like spice errors are fairly
> asynchronous rather than directly triggered by commands, so maybe less
> suitable for interleaving in the monitor.

Fortunately, error_printf() & friends print to an HMP monitor only when
the current thread is running in HMP monitor context.

> While stderr and hmp output are normally the same, if someone has
> HMP wired to a script, I'd assume this is more likely to break it.

Programs consuming HMP output are brittle.  While we don't break them
just because we can, we do change HMP output without worrying about them
whenever we feel the change is an improvement for *human* readers.

Another possible concern is messages vanishing from stderr.

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

* Re: [Qemu-devel] [PATCH v5] log: Make glib logging go through QEMU
  2019-01-24 16:10 ` Markus Armbruster
  2019-01-24 18:32   ` Dr. David Alan Gilbert
@ 2019-01-25 17:19   ` Christophe Fergeau
  1 sibling, 0 replies; 9+ messages in thread
From: Christophe Fergeau @ 2019-01-25 17:19 UTC (permalink / raw)
  To: Markus Armbruster; +Cc: qemu-devel, Stefan Hajnoczi, David Alan Gilbert

[-- Attachment #1: Type: text/plain, Size: 5135 bytes --]

On Thu, Jan 24, 2019 at 05:10:28PM +0100, Markus Armbruster wrote:
> Christophe Fergeau <cfergeau@redhat.com> writes:
> 
> > This commit adds a qemu_init_logging() 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
> > monitor if one is configured.
> 
> s/monitor/HMP monitor/
> 
> I see why one would like to extend the timestamp feature to GLib log
> messages.  Routing them through the HMP monitor is perhaps debatable.
> Cc: Dave in case he has an opinion.

Yep, I don't mind whether this goes through HMP or not, this definitely
was not one of my goals when writing this patch. I mention it in the
commit log because this is what the current code is going to do.

> > [snip]
> > diff --git a/util/qemu-error.c b/util/qemu-error.c
> > index fcbe8a1f74..1118ed4695 100644
> > --- a/util/qemu-error.c
> > +++ b/util/qemu-error.c
> > @@ -345,3 +345,50 @@ 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:
> > +        /* Use same G_MESSAGES_DEBUG logic as glib to enable/disable debug
> > +         * messages
> > +         */
> 
> Wing both ends of the comment, please.

Fixed.

> 
> > +        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_INFO:
> > +        /* Fall through */
> 
> g_log_default_handler() applies G_MESSAGES_DEBUG suppression logic to
> G_LOG_LEVEL_INFO messages, too.  Do you deviate intentionally?

Nope, I thought INFO and MESSAGE were equivalent. Fixed now.

> 
> > +    case G_LOG_LEVEL_MESSAGE:
> > +        info_report("%s: %s", log_domain, message);
> 
> @log_domain can be null.  You even check for that above.

Fixed.

> 
> > +        break;
> > +    case G_LOG_LEVEL_WARNING:
> > +        warn_report("%s: %s", log_domain, message);
> > +        break;
> > +    case G_LOG_LEVEL_CRITICAL:
> > +        /* Fall through */
> > +    case G_LOG_LEVEL_ERROR:
> > +        error_report("%s: %s", log_domain, message);
> > +        break;
> 
> Sure we don't need to check for G_LOG_FLAG_RECURSION?
> g_log_default_handler() has a conditional for that...
> 
> Not sure it has anything for G_LOG_FLAG_FATAL; it's code is surprisingly
> complex.

Both are filtered out from the switch() through G_LOG_LEVEL_MASK:
   switch (log_level & G_LOG_LEVEL_MASK) {
and
https://developer.gnome.org/glib/2.58/glib-Message-Logging.html#G-LOG-FLAG-RECURSION:CAPS
documents G_LOG_FLAG_FATAL and G_LOG_FLAG_RECURSION as fatal.

However, g_log_set_handler() then mentions handling them anyways:
https://developer.gnome.org/glib/2.58/glib-Message-Logging.html#g-log-set-handler
"Sets the log handler for a domain and a set of log levels. To handle
fatal and recursive messages the log_levels parameter must be combined
with the G_LOG_FLAG_FATAL and G_LOG_FLAG_RECURSION bit flags."

My understanding of glib's code is if any of these 2 flags is set, glib
is going to abort anyways, so handling or not handling these flags is
not going to make a big difference.

> 
> > +    }
> > +}
> > +
> > +/*
> > + * Init QEMU logging subsystem. This sets up glib logging so libraries using it
> > + * also print their logs through {info,warn,error}_report.
> > + */
> 
> Format like the other function comments:
> 
>    /*
>     * Init QEMU logging subsystem.
>     * This sets up glib logging so libraries using it also print their logs
>     * through error_report(), warn_report(), info_report().
>     */
> 
> Braces expanded for better grepability.
> 
> > +void qemu_init_logging(void)
> 
> Naming is hard...  Yes, this "initializes logging" in a sense: it
> installs a GLib default log handler that routes GLib log messages
> through this module.  But that's detail; the callers don't care what
> this function does, all they care for is "must call early".  If this
> module ever grows a need to initialize something else before it gets
> used, we'll regret naming its initialization function
> qemu_init_logging().
> 
> Hmm, it has already grown such a need: initializing @progname.
> error_set_progname() does it.  Asking a module's users to call *two*
> initializtion functions is not nice.
> 
> Fuse the two into error_init(const char *argv0)?

Ok, I've done that now, I'll send a v6.

Thanks for the review,

Christophe

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

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

end of thread, other threads:[~2019-01-25 17:19 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-01-21 17:04 [Qemu-devel] [PATCH v5] log: Make glib logging go through QEMU Christophe Fergeau
2019-01-22 14:13 ` Stefan Hajnoczi
2019-01-24  9:38 ` Markus Armbruster
2019-01-24 12:44   ` Christophe Fergeau
2019-01-24 15:23     ` Markus Armbruster
2019-01-24 16:10 ` Markus Armbruster
2019-01-24 18:32   ` Dr. David Alan Gilbert
2019-01-25  6:57     ` Markus Armbruster
2019-01-25 17:19   ` Christophe Fergeau

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).