On Wed, 03 Jul 2013 23:02:46 -0400 Seiji Aguchi <seiji.agu...@hds.com> wrote:
> [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(). I can take this through the QMP tree, but I have two review comments below. > Signed-off-by: Seiji Aguchi <seiji.agu...@hds.com> > --- > Changelog > v5 -> v6 > - Remove include/qemu/time.h and utils/qemu-time.c. > - Fix a syntax and indent of messages in msg option's DEF(). > - Change explanation of the msg option. > > v4 -> v5 > - Fix descriptions of msg option. > - Rename TIME_H to QEMU_TIME_H. (avoiding double inclusion of qemu/time.h) > - Change argument of qemu_get_timestamp_str to "char *" and "size_t". > - Confirmed msg option is displayed by query-command-line-options. > > v3 -> v4 > - Correct email address of Signed-off-by. > > v2 -> v3 > - Use g_time_val_to_iso8601() to get timestamp instead of > copying libvirt's time-handling functions. > > According to discussion below, qemu doesn't need to take care > if timestamp functions are async-signal safe or not. > > http://marc.info/?l=qemu-devel&m=136741841921265&w=2 > > Also, In the review of v2 patch, strftime() are recommended to > format string. But it is not a suitable function to handle msec. > > Then, simply call g_time_val_to_iso8601(). > > - Intoroduce a common time-handling function to util/qemu-time.c. > (Suggested by Daniel P. Berrange) > > - Add testing for g_time_val_to_iso8601() to tests/test-time.c. > The test cases are copied from libvirt's virtimetest. > (Suggested by Daniel P. Berrange) > > v1 -> v2 > > - add an option, -msg timestamp={on|off}, to enable output message with > timestamp > --- > include/qemu/error-report.h | 2 ++ > qemu-options.hx | 11 +++++++++++ > util/qemu-error.c | 10 ++++++++++ > vl.c | 26 ++++++++++++++++++++++++++ > 4 files changed, 49 insertions(+), 0 deletions(-) > > 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 ca6fdf6..f241379 100644 > --- a/qemu-options.hx > +++ b/qemu-options.hx > @@ -3098,6 +3098,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", Did you really intend to say it's on by default? Because it's actually disabled by default. I prefer having this disabled btw, and I can fix it myself before applying if that's what you intended. > + 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, ...) > { There are some errors being printed to stderr that call error_get_pretty(), you might want to convert them to error_report() to increase coverage. But you can do this as a follow up patch. > 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 0a8f056..589d264 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 */ } > + }, > +}; > + > const char *qemu_get_vm_name(void) > { > return qemu_name; > @@ -1459,6 +1471,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 */ > > @@ -2901,6 +2919,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(); > > @@ -3808,6 +3827,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); > }