[libvirt] [PATCH] 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. --- src/qemu/qemu_process.c | 47 +++++++++++++++++++++++++++++++++++++---------- 1 files changed, 37 insertions(+), 10 deletions(-) diff --git a/src/qemu/qemu_process.c b/src/qemu/qemu_process.c index e31e1b4..bc117a4 100644 --- a/src/qemu/qemu_process.c +++ b/src/qemu/qemu_process.c @@ -762,11 +762,21 @@ qemuProcessReadLogOutput(virDomainObjPtr vm, { int retries = (timeout*10); int got = 0; + char *debug = NULL; + int ret = -1; + char *filter_next = buf; + buf[0] = '\0'; + 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 +785,46 @@ 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'))) { + char *p = strstr(filter_next, debug); + if (p && p < eol) { + memmove(filter_next, eol + 1, got - (eol - buf)); + got -= eol + 1 - filter_next; + } else { + filter_next = eol + 1; + } + } + 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 +833,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; } -- 1.7.4.1

On 03/30/2011 06:17 AM, Jiri Denemark wrote:
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. --- src/qemu/qemu_process.c | 47 +++++++++++++++++++++++++++++++++++++---------- 1 files changed, 37 insertions(+), 10 deletions(-)
+ if (virAsprintf(&debug, ": %d: debug : ", vm->pid) < 0) {
That's rather hard-coded to our current output style; should we add comments here and to the place that outputs those lines to be careful to keep the two places in sync?
- got += ret; + got += bytes; buf[got] = '\0'; + + /* Filter out debug messages from intermediate libvirt process */ + while ((eol = strchr(filter_next, '\n'))) { + char *p = strstr(filter_next, debug);
Suppose you have five normal lines before the first debug line. Is it any more efficient to use use getline() to read a line at a time, and just strstr() once per line, rather than reading the entire file and having strstr() repeatedly scan multiple lines on each iteration (15 lines scanned over 5 iterations)? Or even if you don't use getline(), can you temporarily set eol to NUL so that strstr() is bounded to a given line rather than searching into the rest of the file, since the filtering is line-based?
+ if (p && p < eol) { + memmove(filter_next, eol + 1, got - (eol - buf));
Conversely, supposed you have five debug lines followed by five normal lines. Doing the memmove() on every debug line encountered results in moving 25 lines around, whereas if you rewrite the loop to only copy one line at a time and only if it passed the filter, then you only have to move 5 lines around. I like the idea, but I think it can be made more efficient in v2. -- Eric Blake eblake@redhat.com +1-801-349-2682 Libvirt virtualization library http://libvirt.org

On Wed, Mar 30, 2011 at 13:46:12 -0600, Eric Blake wrote:
On 03/30/2011 06:17 AM, Jiri Denemark wrote:
+ if (virAsprintf(&debug, ": %d: debug : ", vm->pid) < 0) {
That's rather hard-coded to our current output style; should we add comments here and to the place that outputs those lines to be careful to keep the two places in sync?
Yeah, it makes sense to add these comments.
- got += ret; + got += bytes; buf[got] = '\0'; + + /* Filter out debug messages from intermediate libvirt process */ + while ((eol = strchr(filter_next, '\n'))) { + char *p = strstr(filter_next, debug);
Suppose you have five normal lines before the first debug line. Is it any more efficient to use use getline() to read a line at a time
Heh, the one which needs FILE *? No, thanks :-)
Or even if you don't use getline(), can you temporarily set eol to NUL
Sure, that actually even results in a bit nicer code.
+ if (p && p < eol) { + memmove(filter_next, eol + 1, got - (eol - buf));
Conversely, supposed you have five debug lines followed by five normal lines. Doing the memmove() on every debug line encountered results in moving 25 lines around, whereas if you rewrite the loop to only copy one line at a time and only if it passed the filter, then you only have to move 5 lines around.
And all this after we went through fork() and going to call exec() soon, I don't think such optimization would make any difference. If this code had been run on any libvirt API, it would have make sense to optimize the loop, but now I don't think it's worth it. It looks like a premature optimization to me :-) Jirka
participants (2)
-
Eric Blake
-
Jiri Denemark