From patchwork Thu Jul 4 03:02:46 2013 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Seiji Aguchi X-Patchwork-Id: 256775 Return-Path: X-Original-To: incoming@patchwork.ozlabs.org Delivered-To: patchwork-incoming@bilbo.ozlabs.org Received: from lists.gnu.org (lists.gnu.org [IPv6:2001:4830:134:3::11]) (using TLSv1 with cipher AES256-SHA (256/256 bits)) (Client did not present a certificate) by ozlabs.org (Postfix) with ESMTPS id A994D2C00AD for ; Thu, 4 Jul 2013 13:03:24 +1000 (EST) Received: from localhost ([::1]:41727 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1UuZpK-0007ib-62 for incoming@patchwork.ozlabs.org; Wed, 03 Jul 2013 23:03:22 -0400 Received: from eggs.gnu.org ([2001:4830:134:3::10]:45732) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1UuZp0-0007iT-2M for qemu-devel@nongnu.org; Wed, 03 Jul 2013 23:03:04 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1UuZow-0000zp-Ng for qemu-devel@nongnu.org; Wed, 03 Jul 2013 23:03:01 -0400 Received: from usindpps03.hds.com ([207.126.252.16]:46227) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1UuZow-0000zl-Hl for qemu-devel@nongnu.org; Wed, 03 Jul 2013 23:02:58 -0400 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=hds.com; h=message-id : date : from : mime-version : to : cc : subject : content-type : content-transfer-encoding; s=mail1; bh=GkuO9B7+ZDzvj9FUIYrSkpzx/ZlheKQZfeVyDp7N0sw=; b=IYwpTXp47sk12D0lZrXtJXBqu2lpJduGWyc7deE0L2YRZTXUMkcoI1rx3gQDGgfsbDoA i8lKFgWUfNWArCxUG+NQlp7Hjoa1PFMAN1yGi4goaN9NhEAT9HmGuHT3hdtoA5kouE7W mlZIqS5A0bnky/l4xqszT2vqiNjuhzO6sfgF/bpDSED9qnaQeY3M4V63gGNTFWF4dnS6 PLw5clAZU4EJPL5gOpUMbGZdnF8F7Gogtnvr3to0HVqgKfpTnPtRh7ya2RFBw1WfBlSf IDlexis27qw+S5xlZH1axr1vhE/gPyxz3ypljb+VZJwGO9lw54DA91Ph17aS1xh5hasa bQ== Received: from usindmail02.hds.com (usindmail02 [207.126.252.21]) by usindpps03.hds.com (8.14.5/8.14.5) with ESMTP id r6432n5D024856; Wed, 3 Jul 2013 23:02:49 -0400 Received: from [10.74.98.50] (usindnetf5d-vlan47float.corp.hds.com [10.74.73.11]) by usindmail02.hds.com (8.14.1/8.14.1) with ESMTP id r6432k8f010692; Wed, 3 Jul 2013 23:02:47 -0400 (EDT) Message-ID: <51D4E5D6.6050404@hds.com> Date: Wed, 03 Jul 2013 23:02:46 -0400 From: Seiji Aguchi User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:17.0) Gecko/20130620 Thunderbird/17.0.7 MIME-Version: 1.0 To: qemu-devel@nongnu.org X-Proofpoint-SPF-Result: pass X-Proofpoint-SPF-Record: v=spf1 mx ip4:207.126.244.0/26 ip4:207.126.252.0/25 include:mktomail.com include:cloud.hds.com ~all X-Proofpoint-Virus-Version: vendor=fsecure engine=2.50.10432:5.10.8794, 1.0.431, 0.0.0000 definitions=2013-07-03_12:2013-07-03, 2013-07-03, 1970-01-01 signatures=0 X-Proofpoint-Spam-Details: rule=notspam policy=outbound_policy score=0 kscore.is_bulkscore=1.71679337412911e-12 kscore.compositescore=0 circleOfTrustscore=0 compositescore=0.207753582200735 urlsuspect_oldscore=0.997706424038378 suspectscore=21 recipient_domain_to_sender_totalscore=0 phishscore=0 bulkscore=0 kscore.is_spamscore=0 recipient_to_sender_totalscore=0 recipient_domain_to_sender_domain_totalscore=349 rbsscore=0.207753582200735 spamscore=0 recipient_to_sender_domain_totalscore=0 urlsuspectscore=0.9 adultscore=0 classifier=spam adjust=0 reason=mlx scancount=1 engine=7.0.1-1305240000 definitions=main-1307030287 X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.4.x X-Received-From: 207.126.252.16 Cc: kwolf@redhat.com, aliguori@us.ibm.com, stefanha@gmail.com, mtosatti@redhat.com, armbru@redhat.com, lcapitulino@redhat.com, dle-develop@lists.sourceforge.net, tomoki.sekiyama@hds.com, pbonzini@redhat.com, lersek@redhat.com Subject: [Qemu-devel] [PATCH v6] add timestamp to error_report() X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: qemu-devel-bounces+incoming=patchwork.ozlabs.org@nongnu.org Sender: qemu-devel-bounces+incoming=patchwork.ozlabs.org@nongnu.org [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 Reviewed-by: Stefan Hajnoczi Reviewed-by: Laszlo Ersek --- 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", + 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 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); }