7:17 a.m.
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
2:46 p.m.
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(a)redhat.com +1-801-349-2682
Libvirt virtualization library http://libvirt.org
3:27 a.m.
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
4985
days inactive
4986
days old
2 comments
2 participants
participants (2)
-
Eric Blake -
Jiri Denemark