[libvirt] [PATCH v2 06/13] qemu: unify code for reporting errors from QEMU log files

There are two pretty similar functions qemuProcessReadLog and qemuProcessReadChildErrors. Both read from the QEMU log file and try to strip out libvirt messages. The latter than reports an error, while the former lets the callers report an error. Re-write qemuProcessReadLog so that it uses a single read into a dynamically allocated buffer. Then introduce a new qemuProcessReportLogError that calls qemuProcessReadLog and reports an error. Convert all callers to use qemuProcessReportLogError. Signed-off-by: Daniel P. Berrange <berrange(a)redhat.com&gt; --- src/qemu/qemu_domain.c | 24 +----- src/qemu/qemu_domain.h | 2 +- src/qemu/qemu_migration.c | 2 +- src/qemu/qemu_monitor.c | 58 +++----------- src/qemu/qemu_monitor.h | 2 +- src/qemu/qemu_process.c | 200 ++++++++++++++++++---------------------------- src/qemu/qemu_process.h | 4 +- 7 files changed, 95 insertions(+), 197 deletions(-) diff --git a/src/qemu/qemu_domain.c b/src/qemu/qemu_domain.c index 416ab5b..1dd3cee 100644 --- a/src/qemu/qemu_domain.c +++ b/src/qemu/qemu_domain.c @@ -2297,38 +2297,16 @@ qemuDomainCreateLog(virQEMUDriverPtr driver, virDomainObjPtr vm, int -qemuDomainOpenLog(virQEMUDriverPtr driver, virDomainObjPtr vm, off_t pos) +qemuDomainOpenLog(virQEMUDriverPtr driver, virDomainObjPtr vm) { virQEMUDriverConfigPtr cfg = virQEMUDriverGetConfig(driver); int fd; - off_t off; - int whence; fd = qemuDomainOpenLogHelper(cfg, vm, O_RDONLY, 0); virObjectUnref(cfg); if (fd < 0) return -1; - if (pos < 0) { - off = 0; - whence = SEEK_END; - } else { - off = pos; - whence = SEEK_SET; - } - - if (lseek(fd, off, whence) < 0) { - if (whence == SEEK_END) - virReportSystemError(errno, - _("unable to seek to end of log for %s"), - vm->def->name); - else - virReportSystemError(errno, - _("unable to seek to %lld from start for %s"), - (long long)off, vm->def->name); - VIR_FORCE_CLOSE(fd); - } - return fd; } diff --git a/src/qemu/qemu_domain.h b/src/qemu/qemu_domain.h index 4be998c..16dc93c 100644 --- a/src/qemu/qemu_domain.h +++ b/src/qemu/qemu_domain.h @@ -350,7 +350,7 @@ void qemuDomainObjCheckNetTaint(virQEMUDriverPtr driver, int qemuDomainCreateLog(virQEMUDriverPtr driver, virDomainObjPtr vm, bool append); -int qemuDomainOpenLog(virQEMUDriverPtr driver, virDomainObjPtr vm, off_t pos); +int qemuDomainOpenLog(virQEMUDriverPtr driver, virDomainObjPtr vm); int qemuDomainAppendLog(virQEMUDriverPtr driver, virDomainObjPtr vm, int logFD, diff --git a/src/qemu/qemu_migration.c b/src/qemu/qemu_migration.c index 3eee3a5..475f97d 100644 --- a/src/qemu/qemu_migration.c +++ b/src/qemu/qemu_migration.c @@ -5849,7 +5849,7 @@ qemuMigrationFinish(virQEMUDriverPtr driver, cleanup: virPortAllocatorRelease(driver->migrationPorts, port); if (priv->mon) - qemuMonitorSetDomainLog(priv->mon, -1); + qemuMonitorSetDomainLog(priv->mon, -1, -1); VIR_FREE(priv->origname); virDomainObjEndAPI(&vm); if (mig) { diff --git a/src/qemu/qemu_monitor.c b/src/qemu/qemu_monitor.c index 49d4aa2..d3f0c09 100644 --- a/src/qemu/qemu_monitor.c +++ b/src/qemu/qemu_monitor.c @@ -96,6 +96,7 @@ struct _qemuMonitor { /* Log file fd of the qemu process to dig for usable info */ int logfd; + off_t logpos; }; /** @@ -389,38 +390,6 @@ qemuMonitorOpenPty(const char *monitor) } -/* Get a possible error from qemu's log. This function closes the - * corresponding log fd */ -static char * -qemuMonitorGetErrorFromLog(qemuMonitorPtr mon) -{ - int len; - char *logbuf = NULL; - int orig_errno = errno; - - if (mon->logfd < 0) - return NULL; - - if (VIR_ALLOC_N_QUIET(logbuf, 4096) < 0) - goto error; - - if ((len = qemuProcessReadLog(mon->logfd, logbuf, 4096 - 1, 0, true)) <= 0) - goto error; - - while (len > 0 && logbuf[len - 1] == '\n') - logbuf[--len] = '\0'; - - cleanup: - errno = orig_errno; - VIR_FORCE_CLOSE(mon->logfd); - return logbuf; - - error: - VIR_FREE(logbuf); - goto cleanup; -} - - /* This method processes data that has been received * from the monitor. Looking for async events and * replies/errors. @@ -737,25 +706,20 @@ qemuMonitorIO(int watch, int fd, int events, void *opaque) } if (error || eof) { - if (hangup) { + if (hangup && mon->logfd != -1) { /* Check if an error message from qemu is available and if so, use * it to overwrite the actual message. It's done only in early * startup phases or during incoming migration when the message * from qemu is certainly more interesting than a * "connection reset by peer" message. */ - char *qemuMessage; - - if ((qemuMessage = qemuMonitorGetErrorFromLog(mon))) { - virReportError(VIR_ERR_INTERNAL_ERROR, - _("early end of file from monitor: " - "possible problem:\n%s"), - qemuMessage); - virCopyLastError(&mon->lastError); - virResetLastError(); - } - - VIR_FREE(qemuMessage); + qemuProcessReportLogError(mon->logfd, + mon->logpos, + _("early end of file from monitor, " + "possible problem")); + VIR_FORCE_CLOSE(mon->logfd); + virCopyLastError(&mon->lastError); + virResetLastError(); } if (mon->lastError.code != VIR_ERR_OK) { @@ -3683,9 +3647,10 @@ qemuMonitorGetDeviceAliases(qemuMonitorPtr mon, * * @mon: Monitor object to set the log file reading on * @logfd: File descriptor of the already open log file + * @pos: position to read errors from */ int -qemuMonitorSetDomainLog(qemuMonitorPtr mon, int logfd) +qemuMonitorSetDomainLog(qemuMonitorPtr mon, int logfd, off_t pos) { VIR_FORCE_CLOSE(mon->logfd); if (logfd >= 0 && @@ -3693,6 +3658,7 @@ qemuMonitorSetDomainLog(qemuMonitorPtr mon, int logfd) virReportSystemError(errno, "%s", _("failed to duplicate log fd")); return -1; } + mon->logpos = pos; return 0; } diff --git a/src/qemu/qemu_monitor.h b/src/qemu/qemu_monitor.h index 2ce3958..a2a9a77 100644 --- a/src/qemu/qemu_monitor.h +++ b/src/qemu/qemu_monitor.h @@ -892,7 +892,7 @@ int qemuMonitorDetachCharDev(qemuMonitorPtr mon, int qemuMonitorGetDeviceAliases(qemuMonitorPtr mon, char ***aliases); -int qemuMonitorSetDomainLog(qemuMonitorPtr mon, int logfd); +int qemuMonitorSetDomainLog(qemuMonitorPtr mon, int logfd, off_t pos); int qemuMonitorGetGuestCPU(qemuMonitorPtr mon, virArch arch, diff --git a/src/qemu/qemu_process.c b/src/qemu/qemu_process.c index 69a0f97..c09e9dc 100644 --- a/src/qemu/qemu_process.c +++ b/src/qemu/qemu_process.c @@ -1549,7 +1549,7 @@ static qemuMonitorCallbacks monitorCallbacks = { static int qemuConnectMonitor(virQEMUDriverPtr driver, virDomainObjPtr vm, int asyncJob, - int logfd) + int logfd, off_t pos) { qemuDomainObjPrivatePtr priv = vm->privateData; int ret = -1; @@ -1575,8 +1575,8 @@ qemuConnectMonitor(virQEMUDriverPtr driver, virDomainObjPtr vm, int asyncJob, &monitorCallbacks, driver); - if (mon) - ignore_value(qemuMonitorSetDomainLog(mon, logfd)); + if (mon && logfd != -1 && pos != -1) + ignore_value(qemuMonitorSetDomainLog(mon, logfd, pos)); virObjectLock(vm); virObjectUnref(vm); @@ -1630,111 +1630,76 @@ qemuConnectMonitor(virQEMUDriverPtr driver, virDomainObjPtr vm, int asyncJob, /** * qemuProcessReadLog: Read log file of a qemu VM * @fd: File descriptor of the log file - * @buf: buffer to store the read messages - * @buflen: allocated space available in @buf + * @msg: pointer to buffer to store the read messages in * @off: Offset to start reading from - * @skipchar: Skip messages about created character devices * * Reads log of a qemu VM. Skips messages not produced by qemu or irrelevant - * messages. Returns length of the message stored in @buf, or -1 on error. + * messages. Returns returns 0 on success or -1 on error */ -int -qemuProcessReadLog(int fd, char *buf, int buflen, int off, bool skipchar) +static int +qemuProcessReadLog(int fd, off_t offset, char **msg) { - char *filter_next = buf; - ssize_t bytes; + char *buf; + size_t buflen = 1024 * 128; + ssize_t got; char *eol; + char *filter_next; - while (off < buflen - 1) { - bytes = saferead(fd, buf + off, buflen - off - 1); - if (bytes < 0) - return -1; - - off += bytes; - buf[off] = '\0'; + /* Best effort jump to start of messages */ + ignore_value(lseek(fd, offset, SEEK_SET)); - if (bytes == 0) - break; + if (VIR_ALLOC_N(buf, buflen) < 0) + return -1; - /* Filter out debug messages from intermediate libvirt process */ - while ((eol = strchr(filter_next, '\n'))) { - *eol = '\0'; - if (virLogProbablyLogMessage(filter_next) || - (skipchar && - STRPREFIX(filter_next, "char device redirected to"))) { - memmove(filter_next, eol + 1, off - (eol - buf)); - off -= eol + 1 - filter_next; - } else { - filter_next = eol + 1; - *eol = '\n'; - } - } + got = saferead(fd, buf, buflen - 1); + if (got < 0) { + virReportSystemError(errno, "%s", + _("Unable to read from log file")); + return -1; } - return off; -} - -/* - * Read domain log and probably overwrite error if there's one in - * the domain log file. This function exists to cover the small - * window between fork() and exec() during which child may fail - * by libvirt's hand, e.g. placing onto a NUMA node failed. - */ -static int -qemuProcessReadChildErrors(virQEMUDriverPtr driver, - virDomainObjPtr vm, - off_t originalOff) -{ - int ret = -1; - int logfd; - off_t off = 0; - ssize_t bytes; - char buf[1024] = {0}; - char *eol, *filter_next = buf; - - if ((logfd = qemuDomainOpenLog(driver, vm, originalOff)) < 0) - goto cleanup; - - while (off < sizeof(buf) - 1) { - bytes = saferead(logfd, buf + off, sizeof(buf) - off - 1); - if (bytes < 0) { - VIR_WARN("unable to read from log file: %s", - virStrerror(errno, buf, sizeof(buf))); - goto cleanup; - } + buf[got] = '\0'; - off += bytes; - buf[off] = '\0'; - - if (bytes == 0) - break; - - while ((eol = strchr(filter_next, '\n'))) { - *eol = '\0'; - if (STRPREFIX(filter_next, "libvirt: ")) { - filter_next = eol + 1; - *eol = '\n'; - break; - } else { - memmove(filter_next, eol + 1, off - (eol - buf)); - off -= eol + 1 - filter_next; - } + /* Filter out debug messages from intermediate libvirt process */ + filter_next = buf; + while ((eol = strchr(filter_next, '\n'))) { + *eol = '\0'; + if (virLogProbablyLogMessage(filter_next) || + STRPREFIX(filter_next, "char device redirected to")) { + size_t skip = (eol + 1) - filter_next; + memmove(filter_next, eol + 1, (got - skip) + 1); + got -= skip; + } else { + filter_next = eol + 1; + *eol = '\n'; } } - if (off > 0) { - /* Found an error in the log. Report it */ - virResetLastError(); - virReportError(VIR_ERR_INTERNAL_ERROR, - _("Process exited prior to exec: %s"), - buf); + if (buf[got - 1] == '\n') { + buf[got - 1] = '\0'; + got--; } + VIR_SHRINK_N(buf, buflen, buflen - got - 1); + *msg = buf; + return 0; +} - ret = 0; - cleanup: - VIR_FORCE_CLOSE(logfd); - return ret; +int +qemuProcessReportLogError(int logfd, + off_t offset, + const char *msgprefix) +{ + char *logmsg = NULL; + + if (qemuProcessReadLog(logfd, offset, &logmsg) < 0) + return -1; + + virResetLastError(); + virReportError(VIR_ERR_INTERNAL_ERROR, + _("%s: %s"), msgprefix, logmsg); + VIR_FREE(logmsg); + return 0; } @@ -1944,20 +1909,17 @@ qemuProcessWaitForMonitor(virQEMUDriverPtr driver, virQEMUCapsPtr qemuCaps, off_t pos) { - char *buf = NULL; - size_t buf_size = 4096; /* Plenty of space to get startup greeting */ - int logfd = -1; int ret = -1; virHashTablePtr info = NULL; qemuDomainObjPrivatePtr priv; + int logfd = -1; - if (pos != -1 && - (logfd = qemuDomainOpenLog(driver, vm, pos)) < 0) - return -1; - + if (pos != (off_t)-1 && + (logfd = qemuDomainOpenLog(driver, vm)) < 0) + goto cleanup; VIR_DEBUG("Connect monitor to %p '%s'", vm, vm->def->name); - if (qemuConnectMonitor(driver, vm, asyncJob, logfd) < 0) + if (qemuConnectMonitor(driver, vm, asyncJob, logfd, pos) < 0) goto cleanup; /* Try to get the pty path mappings again via the monitor. This is much more @@ -1985,31 +1947,14 @@ qemuProcessWaitForMonitor(virQEMUDriverPtr driver, cleanup: virHashFree(info); - if (pos != -1 && kill(vm->pid, 0) == -1 && errno == ESRCH) { - /* VM is dead, any other error raised in the interim is probably - * not as important as the qemu cmdline output */ - if (VIR_ALLOC_N(buf, buf_size) < 0) - goto closelog; - - /* best effort seek - we need to reset to the original position, so that - * a possible read of the fd in the monitor code doesn't influence this - * error delivery option */ - ignore_value(lseek(logfd, pos, SEEK_SET)); - qemuProcessReadLog(logfd, buf, buf_size - 1, 0, true); - virReportError(VIR_ERR_INTERNAL_ERROR, - _("process exited while connecting to monitor: %s"), - buf); + if (pos != (off_t)-1 && kill(vm->pid, 0) == -1 && errno == ESRCH) { + qemuProcessReportLogError(logfd, pos, + _("process exited while connecting to monitor")); ret = -1; } - closelog: - if (VIR_CLOSE(logfd) < 0) { - char ebuf[1024]; - VIR_WARN("Unable to close logfile: %s", - virStrerror(errno, ebuf, sizeof(ebuf))); - } - VIR_FREE(buf); + VIR_FORCE_CLOSE(logfd); return ret; } @@ -3557,7 +3502,7 @@ qemuProcessReconnect(void *opaque) VIR_DEBUG("Reconnect monitor to %p '%s'", obj, obj->def->name); /* XXX check PID liveliness & EXE path */ - if (qemuConnectMonitor(driver, obj, QEMU_ASYNC_JOB_NONE, -1) < 0) + if (qemuConnectMonitor(driver, obj, QEMU_ASYNC_JOB_NONE, -1, -1) < 0) goto error; /* Failure to connect to agent shouldn't be fatal */ @@ -4577,9 +4522,11 @@ int qemuProcessStart(virConnectPtr conn, qemuDomainObjCheckTaint(driver, vm, logfile); - if ((pos = lseek(logfile, 0, SEEK_END)) < 0) + if ((pos = lseek(logfile, 0, SEEK_END)) < 0) { VIR_WARN("Unable to seek to end of logfile: %s", virStrerror(errno, ebuf, sizeof(ebuf))); + pos = 0; + } VIR_DEBUG("Clear emulator capabilities: %d", cfg->clearEmulatorCapabilities); @@ -4673,7 +4620,12 @@ int qemuProcessStart(virConnectPtr conn, VIR_DEBUG("Waiting for handshake from child"); if (virCommandHandshakeWait(cmd) < 0) { /* Read errors from child that occurred between fork and exec. */ - qemuProcessReadChildErrors(driver, vm, pos); + int logfd = qemuDomainOpenLog(driver, vm); + if (logfd >= 0) { + qemuProcessReportLogError(logfd, pos, + _("Process exited prior to exec")); + VIR_FORCE_CLOSE(logfd); + } goto error; } @@ -4896,7 +4848,7 @@ int qemuProcessStart(virConnectPtr conn, /* Keep watching qemu log for errors during incoming migration, otherwise * unset reporting errors from qemu log. */ if (!migrateFrom) - qemuMonitorSetDomainLog(priv->mon, -1); + qemuMonitorSetDomainLog(priv->mon, -1, -1); ret = 0; @@ -4915,7 +4867,7 @@ int qemuProcessStart(virConnectPtr conn, * if we failed to initialize the now running VM. kill it off and * pretend we never started it */ if (priv->mon) - qemuMonitorSetDomainLog(priv->mon, -1); + qemuMonitorSetDomainLog(priv->mon, -1, -1); qemuProcessStop(driver, vm, VIR_DOMAIN_SHUTOFF_FAILED, stop_flags); goto cleanup; diff --git a/src/qemu/qemu_process.h b/src/qemu/qemu_process.h index d40f68d..2df5c4d 100644 --- a/src/qemu/qemu_process.h +++ b/src/qemu/qemu_process.h @@ -100,7 +100,9 @@ int qemuProcessAutoDestroyRemove(virQEMUDriverPtr driver, bool qemuProcessAutoDestroyActive(virQEMUDriverPtr driver, virDomainObjPtr vm); -int qemuProcessReadLog(int fd, char *buf, int buflen, int off, bool skipchar); +int qemuProcessReportLogError(int fd, + off_t offset, + const char *msgprefix); int qemuProcessSetSchedParams(int id, pid_t pid, size_t nsp, virDomainThreadSchedParamPtr sp); -- 2.5.0