From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([2001:4830:134:3::10]:48818) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1UwG0n-0004ji-MP for qemu-devel@nongnu.org; Mon, 08 Jul 2013 14:18:11 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1UwG0l-0004Tj-RR for qemu-devel@nongnu.org; Mon, 08 Jul 2013 14:18:09 -0400 Received: from mx1.redhat.com ([209.132.183.28]:39330) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1UwG0l-0004Td-J2 for qemu-devel@nongnu.org; Mon, 08 Jul 2013 14:18:07 -0400 Date: Mon, 8 Jul 2013 14:17:49 -0400 From: Luiz Capitulino Message-ID: <20130708141749.1cc166ac@redhat.com> In-Reply-To: <51D4E5D6.6050404@hds.com> References: <51D4E5D6.6050404@hds.com> Mime-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit Subject: Re: [Qemu-devel] [PATCH v6] add timestamp to error_report() List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Seiji Aguchi Cc: kwolf@redhat.com, aliguori@us.ibm.com, stefanha@gmail.com, mtosatti@redhat.com, qemu-devel@nongnu.org, armbru@redhat.com, dle-develop@lists.sourceforge.net, tomoki.sekiyama@hds.com, pbonzini@redhat.com, lersek@redhat.com On Wed, 03 Jul 2013 23:02:46 -0400 Seiji Aguchi 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 > --- > 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 > +#include > #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); > }