"Denis V. Lunev" <d...@openvz.org> writes:
> From: Pavel Butsykin <pbutsy...@virtuozzo.com>
>
> This patch is written as an addition to the previous one with logging of
> QPM commands. This information (the moment of the event) is very useful
> to match guest problems with actions performing by management software.
>
> example:
> 2015-10-14 17:15:25.644 qmp event:
> {
> "timestamp": {
> "seconds": 1444832125,
> "microseconds": 644854
> },
> "event": "RESUME"
> }
> 2015-10-14 17:15:35.823 hmp request:
> info registers
> 2015-10-14 17:15:46.936 hmp request:
> q
> 2015-10-14 17:15:46.936 qmp event:
> {
> "timestamp": {
> "seconds": 1444832146,
> "microseconds": 936214
> },
> "event": "SHUTDOWN"
> }
>
> This patch is not perfect as messages from different threads could
> interleave but this is not a big deal, timestamps are nearly the
> same.
>
> Signed-off-by: Pavel Butsykin <pbutsy...@virtuozzo.com>
> Signed-off-by: Denis V. Lunev <d...@openvz.org>
> CC: Markus Armbruster <arm...@redhat.com>
> CC: Luiz Capitulino <lcapitul...@redhat.com>
> CC: Eric Blake <ebl...@redhat.com>
> CC: Peter Maydell <peter.mayd...@linaro.org>
> ---
> include/qemu/log.h | 9 +++++++++
> qemu-log.c | 17 ++++++++++++++++-
> 2 files changed, 25 insertions(+), 1 deletion(-)
>
> diff --git a/include/qemu/log.h b/include/qemu/log.h
> index ba86606..285636a 100644
> --- a/include/qemu/log.h
> +++ b/include/qemu/log.h
> @@ -42,6 +42,7 @@ static inline bool qemu_log_enabled(void)
> #define LOG_GUEST_ERROR (1 << 11)
> #define CPU_LOG_MMU (1 << 12)
> #define LOG_CMD (1 << 13)
> +#define LOG_TIME (1 << 14)
>
> /* Returns true if a bit is set in the current loglevel mask
> */
> @@ -52,6 +53,11 @@ static inline bool qemu_loglevel_mask(int mask)
>
> /* Logging functions: */
>
> +
> +/* timestamp logging function
> +*/
> +void qemu_log_time(void);
> +
> /* main logging function
> */
> #define qemu_log(args...) \
> @@ -59,6 +65,9 @@ static inline bool qemu_loglevel_mask(int mask)
> if (!qemu_log_enabled()) { \
> break; \
> } \
> + if (qemu_loglevel & LOG_TIME) { \
> + qemu_log_time(); \
> + } \
> fprintf(qemu_logfile, args); \
> } while (0)
Since this is no longer just a simple fprintf(), you should keep the
actual logging out of line, like this:
static inline void qemu_log(const char *fmt, ...)
{
va_list ap;
if (qemu_log_enabled()) {
va_start(ap, fmt);
qemu_do_log(fmt, ap);
va_end(ap);
}
}
You don't add a timestamp to qemu_log_vprintf(), log_cpu_state(), ...
Intentional?
>
> diff --git a/qemu-log.c b/qemu-log.c
> index ba7b34c..6a8ca71 100644
> --- a/qemu-log.c
> +++ b/qemu-log.c
> @@ -25,6 +25,18 @@ FILE *qemu_logfile;
> int qemu_loglevel;
> static int log_append = 0;
>
> +void qemu_log_time(void)
> +{
> + qemu_timeval tv;
> + char timestr[32];
> +
> + qemu_gettimeofday(&tv);
> +
> + /* cast below needed for OpenBSD where tv_sec is still 'long' */
> + strftime(timestr, sizeof(timestr), "%F %T",
> + localtime((const time_t *)&tv.tv_sec));
The pointer cast is unnecessarily unclean. The clean version is
time_t now = tv.tv_sec;
strftime(timestr, sizeof(timestr), "%F %T", localtime(&now));
Why not simply ctime(&now)?
> + fprintf(qemu_logfile, "%s.%03lu ", timestr, tv.tv_usec / 1000);
> +}
>
> /* enable or disable low levels log */
> void do_qemu_set_log(int log_flags, bool use_own_buffers)
> @@ -98,7 +110,10 @@ const QEMULogItem qemu_log_items[] = {
> { LOG_GUEST_ERROR, "guest_errors",
> "log when the guest OS does something invalid (eg accessing a\n"
> "non-existent register)" },
> - { LOG_CMD, "cmd", "log the hmp/qmp commands execution" },
> + { LOG_CMD, "cmd",
> + "log the hmp/qmp commands execution" },
> + { LOG_TIME, "time",
> + "adds a timestamp to each log entry" },
Make that "add a timestamp", for consistency with the other help texts.
> { 0, NULL, NULL },
> };
