[PATCH 3/3] chardev: add logtimestamp option

Vladimir Sementsov-Ogievskiy posted 3 patches 14 hours ago
Maintainers: "Marc-André Lureau" <marcandre.lureau@redhat.com>, Paolo Bonzini <pbonzini@redhat.com>, Markus Armbruster <armbru@redhat.com>, Eric Blake <eblake@redhat.com>
[PATCH 3/3] chardev: add logtimestamp option
Posted by Vladimir Sementsov-Ogievskiy 14 hours ago
Add an option to inject timestamps into serial log file.
That simplifies debugging a lot, when you can simply compare
QEMU logs with guest console logs.

Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@yandex-team.ru>
---
 chardev/char.c         | 63 ++++++++++++++++++++++++++++++++++++++----
 include/chardev/char.h |  2 ++
 qapi/char.json         |  6 +++-
 3 files changed, 65 insertions(+), 6 deletions(-)

diff --git a/chardev/char.c b/chardev/char.c
index 64006a3119..57c65544d0 100644
--- a/chardev/char.c
+++ b/chardev/char.c
@@ -82,12 +82,8 @@ void qemu_chr_be_event(Chardev *s, QEMUChrEvent event)
     CHARDEV_GET_CLASS(s)->chr_be_event(s, event);
 }
 
-static void qemu_chr_write_log(Chardev *s, const uint8_t *buf, size_t len)
+static void do_write_log(Chardev *s, const uint8_t *buf, size_t len)
 {
-    if (s->logfd < 0) {
-        return;
-    }
-
     if (qemu_write_full(s->logfd, buf, len) < len) {
         /*
          * qemu_write_full() is defined with G_GNUC_WARN_UNUSED_RESULT,
@@ -96,6 +92,55 @@ static void qemu_chr_write_log(Chardev *s, const uint8_t *buf, size_t len)
     }
 }
 
+static void do_write_log_timestamps(Chardev *s, const uint8_t *buf, size_t len)
+{
+    g_autofree char *timestr = NULL;
+
+    while (len) {
+        size_t i;
+
+        if (s->log_line_start) {
+            if (!timestr) {
+                timestr = real_time_iso8601();
+            }
+            do_write_log(s, (const uint8_t *)timestr, strlen(timestr));
+            do_write_log(s, (const uint8_t *)" ", 1);
+            s->log_line_start = false;
+        }
+
+        for (i = 0; i < len; i++) {
+            if (buf[i] == '\n') {
+                break;
+            }
+        }
+
+        if (i == len) {
+            /* not found \n */
+            do_write_log(s, buf, len);
+            return;
+        }
+
+        i += 1;
+        do_write_log(s, buf, i);
+        buf += i;
+        len -= i;
+        s->log_line_start = true;
+    }
+}
+
+static void qemu_chr_write_log(Chardev *s, const uint8_t *buf, size_t len)
+{
+    if (s->logfd < 0) {
+        return;
+    }
+
+    if (s->logtimestamp) {
+        do_write_log_timestamps(s, buf, len);
+    } else {
+        do_write_log(s, buf, len);
+    }
+}
+
 static int qemu_chr_write_buffer(Chardev *s,
                                  const uint8_t *buf, int len,
                                  int *offset, bool write_all)
@@ -249,6 +294,7 @@ static void qemu_char_open(Chardev *chr, ChardevBackend *backend,
         } else {
             flags |= O_TRUNC;
         }
+        chr->logtimestamp = common->has_logtimestamp && common->logtimestamp;
         chr->logfd = qemu_create(common->logfile, flags, 0666, errp);
         if (chr->logfd < 0) {
             return;
@@ -266,6 +312,7 @@ static void char_init(Object *obj)
 
     chr->handover_yank_instance = false;
     chr->logfd = -1;
+    chr->log_line_start = true;
     qemu_mutex_init(&chr->chr_write_lock);
 
     /*
@@ -505,6 +552,9 @@ void qemu_chr_parse_common(QemuOpts *opts, ChardevCommon *backend)
     backend->logfile = g_strdup(logfile);
     backend->has_logappend = true;
     backend->logappend = qemu_opt_get_bool(opts, "logappend", false);
+
+    backend->has_logtimestamp = true;
+    backend->logtimestamp = qemu_opt_get_bool(opts, "logtimestamp", false);
 }
 
 static const ChardevClass *char_get_class(const char *driver, Error **errp)
@@ -956,6 +1006,9 @@ QemuOptsList qemu_chardev_opts = {
         },{
             .name = "logappend",
             .type = QEMU_OPT_BOOL,
+        },{
+            .name = "logtimestamp",
+            .type = QEMU_OPT_BOOL,
         },{
             .name = "mouse",
             .type = QEMU_OPT_BOOL,
diff --git a/include/chardev/char.h b/include/chardev/char.h
index b65e9981c1..6a5318c918 100644
--- a/include/chardev/char.h
+++ b/include/chardev/char.h
@@ -64,6 +64,8 @@ struct Chardev {
     char *label;
     char *filename;
     int logfd;
+    bool logtimestamp;
+    bool log_line_start;
     int be_open;
     /* used to coordinate the chardev-change special-case: */
     bool handover_yank_instance;
diff --git a/qapi/char.json b/qapi/char.json
index 140614f82c..a4abafa680 100644
--- a/qapi/char.json
+++ b/qapi/char.json
@@ -197,11 +197,15 @@
 # @logappend: true to append instead of truncate (default to false to
 #     truncate)
 #
+# @logtimestamp: true to insert timestamps into logfile
+#     (default false) (since 11.0)
+#
 # Since: 2.6
 ##
 { 'struct': 'ChardevCommon',
   'data': { '*logfile': 'str',
-            '*logappend': 'bool' } }
+            '*logappend': 'bool',
+            '*logtimestamp': 'bool' } }
 
 ##
 # @ChardevFile:
-- 
2.48.1