Patchwork [PULL,6/6] add timestamp to error_report()

login
register
mail settings
Submitter Luiz Capitulino
Date July 10, 2013, 5:52 p.m.
Message ID <1373478767-20965-7-git-send-email-lcapitulino@redhat.com>
Download mbox | patch
Permalink /patch/258185/
State New
Headers show

Comments

Luiz Capitulino - July 10, 2013, 5:52 p.m.
From: Seiji Aguchi <seiji.aguchi@hds.com>

[Issue]
When we offer a customer support service and a problem happens
in a customer's system, we try to understand the problem by
comparing what the customer reports with message logs of the
customer's system.

In this case, we often need to know when the problem happens.

But, currently, there is no timestamp in qemu's error messages.
Therefore, we may not be able to understand the problem based on
error messages.

[Solution]
Add a timestamp to qemu's error message logged by
error_report() with g_time_val_to_iso8601().

Signed-off-by: Seiji Aguchi <seiji.aguchi@hds.com>
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
Signed-off-by: Luiz Capitulino <lcapitulino@redhat.com>
---
 include/qemu/error-report.h |  2 ++
 qemu-options.hx             | 11 +++++++++++
 util/qemu-error.c           | 10 ++++++++++
 vl.c                        | 26 ++++++++++++++++++++++++++
 4 files changed, 49 insertions(+)
Paolo Bonzini - July 12, 2013, 6:58 a.m.
Il 10/07/2013 19:52, Luiz Capitulino ha scritto:
> From: Seiji Aguchi <seiji.aguchi@hds.com>
> 
> [Issue]
> When we offer a customer support service and a problem happens
> in a customer's system, we try to understand the problem by
> comparing what the customer reports with message logs of the
> customer's system.
> 
> In this case, we often need to know when the problem happens.
> 
> But, currently, there is no timestamp in qemu's error messages.
> Therefore, we may not be able to understand the problem based on
> error messages.
> 
> [Solution]
> Add a timestamp to qemu's error message logged by
> error_report() with g_time_val_to_iso8601().
> 
> Signed-off-by: Seiji Aguchi <seiji.aguchi@hds.com>
> Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
> Signed-off-by: Luiz Capitulino <lcapitulino@redhat.com>

What about removing the option, and instead:

- logging no timestamp until the virtual machine has started

- always logging timestamps after the virtual machine has started

?

Paolo
Luiz Capitulino - July 12, 2013, 12:46 p.m.
On Fri, 12 Jul 2013 08:58:03 +0200
Paolo Bonzini <pbonzini@redhat.com> wrote:

> Il 10/07/2013 19:52, Luiz Capitulino ha scritto:
> > From: Seiji Aguchi <seiji.aguchi@hds.com>
> > 
> > [Issue]
> > When we offer a customer support service and a problem happens
> > in a customer's system, we try to understand the problem by
> > comparing what the customer reports with message logs of the
> > customer's system.
> > 
> > In this case, we often need to know when the problem happens.
> > 
> > But, currently, there is no timestamp in qemu's error messages.
> > Therefore, we may not be able to understand the problem based on
> > error messages.
> > 
> > [Solution]
> > Add a timestamp to qemu's error message logged by
> > error_report() with g_time_val_to_iso8601().
> > 
> > Signed-off-by: Seiji Aguchi <seiji.aguchi@hds.com>
> > Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
> > Signed-off-by: Luiz Capitulino <lcapitulino@redhat.com>
> 
> What about removing the option, and instead:
> 
> - logging no timestamp until the virtual machine has started

You mean, the guest has started? Why? What about if an error
happens before the guest has started?

> - always logging timestamps after the virtual machine has started

I don't like having this enabled by default, because it makes
error messages pretty verbose and also because it's not human
readable at a first glance. So, IMO, only people who really
want this should enable it.
Seiji Aguchi - July 12, 2013, 2:23 p.m.
> -----Original Message-----
> From: qemu-devel-bounces+seiji.aguchi=hds.com@nongnu.org [mailto:qemu-devel-bounces+seiji.aguchi=hds.com@nongnu.org]
> On Behalf Of Luiz Capitulino
> Sent: Friday, July 12, 2013 8:47 AM
> To: Paolo Bonzini
> Cc: aliguori@us.ibm.com; qemu-devel@nongnu.org
> Subject: Re: [Qemu-devel] [PULL 6/6] add timestamp to error_report()
> 
> On Fri, 12 Jul 2013 08:58:03 +0200
> Paolo Bonzini <pbonzini@redhat.com> wrote:
> 
> > Il 10/07/2013 19:52, Luiz Capitulino ha scritto:
> > > From: Seiji Aguchi <seiji.aguchi@hds.com>
> > >
> > > [Issue]
> > > When we offer a customer support service and a problem happens
> > > in a customer's system, we try to understand the problem by
> > > comparing what the customer reports with message logs of the
> > > customer's system.
> > >
> > > In this case, we often need to know when the problem happens.
> > >
> > > But, currently, there is no timestamp in qemu's error messages.
> > > Therefore, we may not be able to understand the problem based on
> > > error messages.
> > >
> > > [Solution]
> > > Add a timestamp to qemu's error message logged by
> > > error_report() with g_time_val_to_iso8601().
> > >
> > > Signed-off-by: Seiji Aguchi <seiji.aguchi@hds.com>
> > > Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
> > > Signed-off-by: Luiz Capitulino <lcapitulino@redhat.com>
> >
> > What about removing the option, and instead:
> >
> > - logging no timestamp until the virtual machine has started
> 
> You mean, the guest has started? Why? What about if an error
> happens before the guest has started?

I agree with Luiz.
We need the timestamp to investigate an error before the guest has started.

> 
> > - always logging timestamps after the virtual machine has started
> 
> I don't like having this enabled by default, because it makes
> error messages pretty verbose and also because it's not human
> readable at a first glance. So, IMO, only people who really
> want this should enable it.

We have already discussed this.
There is an use case that timestamp is not needed.

http://marc.info/?l=qemu-devel&m=135997005926563&w=2

Seiji

Patch

diff --git a/include/qemu/error-report.h b/include/qemu/error-report.h
index 14c1719..3b098a9 100644
--- a/include/qemu/error-report.h
+++ b/include/qemu/error-report.h
@@ -14,6 +14,7 @@ 
 #define QEMU_ERROR_H
 
 #include <stdarg.h>
+#include <stdbool.h>
 #include "qemu/compiler.h"
 
 typedef struct Location {
@@ -40,5 +41,6 @@  void error_print_loc(void);
 void error_set_progname(const char *argv0);
 void error_report(const char *fmt, ...) GCC_FMT_ATTR(1, 2);
 const char *error_get_progname(void);
+extern bool enable_timestamp_msg;
 
 #endif
diff --git a/qemu-options.hx b/qemu-options.hx
index 7cc4d8e..4e98b4f 100644
--- a/qemu-options.hx
+++ b/qemu-options.hx
@@ -3100,6 +3100,17 @@  property must be set.  These objects are placed in the
 '/objects' path.
 ETEXI
 
+DEF("msg", HAS_ARG, QEMU_OPTION_msg,
+    "-msg timestamp[=on|off]\n"
+    "                change the format of messages\n"
+    "                on|off controls leading timestamps (default:on)\n",
+    QEMU_ARCH_ALL)
+STEXI
+@item -msg timestamp[=on|off]
+@findex -msg
+prepend a timestamp to each log message.(default:on)
+ETEXI
+
 HXCOMM This is the last statement. Insert new options before this line!
 STEXI
 @end table
diff --git a/util/qemu-error.c b/util/qemu-error.c
index 08a36f4..fec02c6 100644
--- a/util/qemu-error.c
+++ b/util/qemu-error.c
@@ -196,6 +196,7 @@  void error_print_loc(void)
     }
 }
 
+bool enable_timestamp_msg;
 /*
  * Print an error message to current monitor if we have one, else to stderr.
  * Format arguments like sprintf().  The result should not contain
@@ -206,6 +207,15 @@  void error_print_loc(void)
 void error_report(const char *fmt, ...)
 {
     va_list ap;
+    GTimeVal tv;
+    gchar *timestr;
+
+    if (enable_timestamp_msg) {
+        g_get_current_time(&tv);
+        timestr = g_time_val_to_iso8601(&tv);
+        error_printf("%s ", timestr);
+        g_free(timestr);
+    }
 
     error_print_loc();
     va_start(ap, fmt);
diff --git a/vl.c b/vl.c
index bea1a10..25b8f2f 100644
--- a/vl.c
+++ b/vl.c
@@ -516,6 +516,18 @@  static QemuOptsList qemu_realtime_opts = {
     },
 };
 
+static QemuOptsList qemu_msg_opts = {
+    .name = "msg",
+    .head = QTAILQ_HEAD_INITIALIZER(qemu_msg_opts.head),
+    .desc = {
+        {
+            .name = "timestamp",
+            .type = QEMU_OPT_BOOL,
+        },
+        { /* end of list */ }
+    },
+};
+
 /**
  * Get machine options
  *
@@ -1503,6 +1515,12 @@  static void configure_realtime(QemuOpts *opts)
     }
 }
 
+
+static void configure_msg(QemuOpts *opts)
+{
+    enable_timestamp_msg = qemu_opt_get_bool(opts, "timestamp", true);
+}
+
 /***********************************************************/
 /* USB devices */
 
@@ -2942,6 +2960,7 @@  int main(int argc, char **argv, char **envp)
     qemu_add_opts(&qemu_object_opts);
     qemu_add_opts(&qemu_tpmdev_opts);
     qemu_add_opts(&qemu_realtime_opts);
+    qemu_add_opts(&qemu_msg_opts);
 
     runstate_init();
 
@@ -3838,6 +3857,13 @@  int main(int argc, char **argv, char **envp)
                 }
                 configure_realtime(opts);
                 break;
+            case QEMU_OPTION_msg:
+                opts = qemu_opts_parse(qemu_find_opts("msg"), optarg, 0);
+                if (!opts) {
+                    exit(1);
+                }
+                configure_msg(opts);
+                break;
             default:
                 os_parse_cmd_args(popt->index, optarg);
             }