qemu: Ignore libvirt debug messages in qemu log

qemu driver uses a 4K buffer for reading qemu log file. This is enough
when only qemu's output is present in the log file. However, when
debugging messages are turned on, intermediate libvirt process fills the
log with a bunch of debugging messages before it executes qemu binary.
In such a case the buffer may become too small. However, we are not
really interested in libvirt messages so they can be filtered out from
the buffer.

diff --git a/src/qemu/qemu_process.c b/src/qemu/qemu_process.c
index e31e1b4bece7e869bab739e59b54fb5238360967..2fc2b6c6a468ad7f38c1b59f3370fd119d26f83c 100644 (file)
--- a/src/qemu/qemu_process.c
+++ b/src/qemu/qemu_process.c
@@ -762,11 +762,23 @@ qemuProcessReadLogOutput(virDomainObjPtr vm,
 {
     int retries = (timeout*10);
     int got = 0;
+    char *debug = NULL;
+    int ret = -1;
+    char *filter_next = buf;
+
     buf[0] = '\0';
 
+    /* This relies on log message format generated by virLogFormatString() and
+     * might need to be modified when message format changes. */
+    if (virAsprintf(&debug, ": %d: debug : ", vm->pid) < 0) {
+        virReportOOMError();
+        return -1;
+    }
+
     while (retries) {
-        ssize_t func_ret, ret;
+        ssize_t func_ret, bytes;
         int isdead = 0;
+        char *eol;
 
         func_ret = func(vm, buf, fd);
 
@@ -775,32 +787,47 @@ qemuProcessReadLogOutput(virDomainObjPtr vm,
 
         /* Any failures should be detected before we read the log, so we
          * always have something useful to report on failure. */
-        ret = saferead(fd, buf+got, buflen-got-1);
-        if (ret < 0) {
+        bytes = saferead(fd, buf+got, buflen-got-1);
+        if (bytes < 0) {
             virReportSystemError(errno,
                                  _("Failure while reading %s log output"),
                                  what);
-            return -1;
+            goto cleanup;
         }
 
-        got += ret;
+        got += bytes;
         buf[got] = '\0';
+
+        /* Filter out debug messages from intermediate libvirt process */
+        while ((eol = strchr(filter_next, '\n'))) {
+            *eol = '\0';
+            if (strstr(filter_next, debug)) {
+                memmove(filter_next, eol + 1, got - (eol - buf));
+                got -= eol + 1 - filter_next;
+            } else {
+                filter_next = eol + 1;
+                *eol = '\n';
+            }
+        }
+
         if (got == buflen-1) {
             qemuReportError(VIR_ERR_INTERNAL_ERROR,
                             _("Out of space while reading %s log output: %s"),
                             what, buf);
-            return -1;
+            goto cleanup;
         }
 
         if (isdead) {
             qemuReportError(VIR_ERR_INTERNAL_ERROR,
                             _("Process exited while reading %s log output: %s"),
                             what, buf);
-            return -1;
+            goto cleanup;
         }
 
-        if (func_ret <= 0)
-            return func_ret;
+        if (func_ret <= 0) {
+            ret = func_ret;
+            goto cleanup;
+        }
 
         usleep(100*1000);
         retries--;
@@ -809,7 +836,10 @@ qemuProcessReadLogOutput(virDomainObjPtr vm,
     qemuReportError(VIR_ERR_INTERNAL_ERROR,
                     _("Timed out while reading %s log output: %s"),
                     what, buf);
-    return -1;
+
+cleanup:
+    VIR_FREE(debug);
+    return ret;
 }
 
 

diff --git a/src/util/logging.c b/src/util/logging.c
index 48c0cfd4b4d010ea1cd669a3223ee64871b3434b..9d187523ce703552eca5e53b790bda8f1df4c44b 100644 (file)
--- a/src/util/logging.c
+++ b/src/util/logging.c
@@ -660,6 +660,14 @@ virLogFormatString(char **msg,
                    const char *str)
 {
     int ret;
+
+    /*
+     * Be careful when changing the following log message formatting, we rely
+     * on it when stripping libvirt debug messages from qemu log files. So when
+     * changing this, you might also need to change the code there.
+     * virLogFormatString() function name is mentioned there so it's sufficient
+     * to just grep for it to find the right place.
+     */
     if ((funcname != NULL)) {
         ret = virAsprintf(msg, "%02d:%02d:%02d.%03d: %d: %s : %s:%lld : %s\n",
                           time_info->tm_hour, time_info->tm_min,