For logging one-shot entries to the VM log file it's quite a waste to hold open the file descriptor for logging that is provided by the current API. This new API will be ideal for logging one-shot entries to the file e.g. at the point when we shut the VM down rather than having to add the whole file-descriptor infrastructure. Additionally this will allow to add the messages even after restart of libvirtd since virtlogd doesn't allow to obtain a regular context with filedescriptors while the VM is still active. --- src/logging/log_handler.c | 50 +++++++++++++++++++++++++++++++++++++++++++++++ src/logging/log_handler.h | 8 ++++++++ 2 files changed, 58 insertions(+) diff --git a/src/logging/log_handler.c b/src/logging/log_handler.c index 4c08223..a8cb6cf 100644 --- a/src/logging/log_handler.c +++ b/src/logging/log_handler.c @@ -513,6 +513,56 @@ virLogHandlerDomainReadLogFile(virLogHandlerPtr handler, } +int +virLogHandlerDomainAppendLogFile(virLogHandlerPtr handler, + const char *driver ATTRIBUTE_UNUSED, + const unsigned char *domuuid ATTRIBUTE_UNUSED, + const char *domname ATTRIBUTE_UNUSED, + const char *path, + const char *message, + unsigned int flags) +{ + size_t i; + virRotatingFileWriterPtr writer = NULL; + virRotatingFileWriterPtr newwriter = NULL; + int ret = -1; + + virCheckFlags(0, -1); + + VIR_DEBUG("Appending to log '%s' message: '%s'", path, message); + + virObjectLock(handler); + + for (i = 0; i < handler->nfiles; i++) { + if (STREQ(virRotatingFileWriterGetPath(handler->files[i]->file), path)) { + writer = handler->files[i]->file; + break; + } + } + + if (!writer) { + if (!(newwriter = virRotatingFileWriterNew(path, + DEFAULT_FILE_SIZE, + DEFAULT_MAX_BACKUP, + false, + DEFAULT_MODE))) + goto cleanup; + + writer = newwriter; + } + + if (virRotatingFileWriterAppend(writer, message, strlen(message)) < 0) + goto cleanup; + + ret = 0; + + cleanup: + virRotatingFileWriterFree(newwriter); + virObjectUnlock(handler); + return ret; +} + + virJSONValuePtr virLogHandlerPreExecRestart(virLogHandlerPtr handler) { diff --git a/src/logging/log_handler.h b/src/logging/log_handler.h index 54a9cd9..4607e45 100644 --- a/src/logging/log_handler.h +++ b/src/logging/log_handler.h @@ -65,6 +65,14 @@ char *virLogHandlerDomainReadLogFile(virLogHandlerPtr handler, size_t maxlen, unsigned int flags); +int virLogHandlerDomainAppendLogFile(virLogHandlerPtr handler, + const char *driver, + const unsigned char *domuuid, + const char *domname, + const char *path, + const char *message, + unsigned int flags); + virJSONValuePtr virLogHandlerPreExecRestart(virLogHandlerPtr handler); #endif /** __VIR_LOG_HANDLER_H__ */ -- 2.8.3

Implement the RPC dispatcher and caller for the new API. --- src/libvirt_private.syms | 1 + src/logging/log_daemon_dispatch.c | 26 ++++++++++++++++++++++++++ src/logging/log_manager.c | 34 ++++++++++++++++++++++++++++++++++ src/logging/log_manager.h | 8 ++++++++ src/logging/log_protocol.x | 20 +++++++++++++++++++- 5 files changed, 88 insertions(+), 1 deletion(-) diff --git a/src/libvirt_private.syms b/src/libvirt_private.syms index 3fd042b..f197f55 100644 --- a/src/libvirt_private.syms +++ b/src/libvirt_private.syms @@ -1048,6 +1048,7 @@ virLockManagerRelease; # logging/log_manager.h +virLogManagerDomainAppendMessage; virLogManagerDomainGetLogFilePosition; virLogManagerDomainOpenLogFile; virLogManagerDomainReadLogFile; diff --git a/src/logging/log_daemon_dispatch.c b/src/logging/log_daemon_dispatch.c index b00cee2..ec69112 100644 --- a/src/logging/log_daemon_dispatch.c +++ b/src/logging/log_daemon_dispatch.c @@ -143,3 +143,29 @@ virLogManagerProtocolDispatchDomainReadLogFile(virNetServerPtr server ATTRIBUTE_ virNetMessageSaveError(rerr); return rv; } + + +static int +virLogManagerProtocolDispatchDomainAppendLogFile(virNetServerPtr server ATTRIBUTE_UNUSED, + virNetServerClientPtr client ATTRIBUTE_UNUSED, + virNetMessagePtr msg ATTRIBUTE_UNUSED, + virNetMessageErrorPtr rerr, + virLogManagerProtocolDomainAppendLogFileArgs *args, + virLogManagerProtocolDomainAppendLogFileRet *ret) +{ + int rv; + + if ((rv = virLogHandlerDomainAppendLogFile(virLogDaemonGetHandler(logDaemon), + args->driver, + (unsigned char *)args->dom.uuid, + args->dom.name, + args->path, + args->message, + args->flags)) < 0) { + virNetMessageSaveError(rerr); + return -1; + } + + ret->ret = rv; + return 0; +} diff --git a/src/logging/log_manager.c b/src/logging/log_manager.c index 7c37ba1..e84abdb 100644 --- a/src/logging/log_manager.c +++ b/src/logging/log_manager.c @@ -282,3 +282,37 @@ virLogManagerDomainReadLogFile(virLogManagerPtr mgr, cleanup: return rv; } + + +int +virLogManagerDomainAppendMessage(virLogManagerPtr mgr, + const char *driver, + const unsigned char *domuuid, + const char *domname, + const char *path, + const char *message, + unsigned int flags) +{ + struct virLogManagerProtocolDomainAppendLogFileArgs args; + struct virLogManagerProtocolDomainAppendLogFileRet ret; + + memset(&args, 0, sizeof(args)); + + args.driver = (char *)driver; + memcpy(args.dom.uuid, domuuid, VIR_UUID_BUFLEN); + args.dom.name = (char *)domname; + args.path = (char *)path; + args.message = (char *)message; + args.flags = flags; + + if (virNetClientProgramCall(mgr->program, + mgr->client, + mgr->serial++, + VIR_LOG_MANAGER_PROTOCOL_PROC_DOMAIN_APPEND_LOG_FILE, + 0, NULL, NULL, NULL, + (xdrproc_t)xdr_virLogManagerProtocolDomainAppendLogFileArgs, &args, + (xdrproc_t)xdr_virLogManagerProtocolDomainAppendLogFileRet, &ret) < 0) + return -1; + + return ret.ret; +} diff --git a/src/logging/log_manager.h b/src/logging/log_manager.h index 7deaba7..7f8e518 100644 --- a/src/logging/log_manager.h +++ b/src/logging/log_manager.h @@ -57,4 +57,12 @@ char *virLogManagerDomainReadLogFile(virLogManagerPtr mgr, size_t maxlen, unsigned int flags); +int virLogManagerDomainAppendMessage(virLogManagerPtr mgr, + const char *driver, + const unsigned char *domuuid, + const char *domname, + const char *path, + const char *message, + unsigned int flags); + #endif /* __VIR_LOG_MANAGER_H__ */ diff --git a/src/logging/log_protocol.x b/src/logging/log_protocol.x index 0363c75..2434043 100644 --- a/src/logging/log_protocol.x +++ b/src/logging/log_protocol.x @@ -68,6 +68,18 @@ struct virLogManagerProtocolDomainReadLogFileRet { virLogManagerProtocolNonNullString data; }; +struct virLogManagerProtocolDomainAppendLogFileArgs { + virLogManagerProtocolNonNullString driver; + virLogManagerProtocolDomain dom; + virLogManagerProtocolNonNullString path; + virLogManagerProtocolNonNullString message; + unsigned int flags; +}; + +struct virLogManagerProtocolDomainAppendLogFileRet { + int ret; +}; + /* Define the program number, protocol version and procedure numbers here. */ const VIR_LOG_MANAGER_PROTOCOL_PROGRAM = 0x87539319; const VIR_LOG_MANAGER_PROTOCOL_PROGRAM_VERSION = 1; @@ -115,5 +127,11 @@ enum virLogManagerProtocolProcedure { * @generate: none * @acl: none */ - VIR_LOG_MANAGER_PROTOCOL_PROC_DOMAIN_READ_LOG_FILE = 3 + VIR_LOG_MANAGER_PROTOCOL_PROC_DOMAIN_READ_LOG_FILE = 3, + + /** + * @generate: none + * @acl: none + */ + VIR_LOG_MANAGER_PROTOCOL_PROC_DOMAIN_APPEND_LOG_FILE = 4 }; -- 2.8.3

Along with the virtlogd addition of the log file appending API implement a helper for logging one-shot entries to the log file including the fallback approach of using direct file access. This will be used for noting the shutdown of the qemu proces and possibly other actions such as VM migration and other critical VM lifecycle events. --- src/qemu/qemu_domain.c | 62 ++++++++++++++++++++++++++++++++++++++++++++++++++ src/qemu/qemu_domain.h | 5 ++++ 2 files changed, 67 insertions(+) diff --git a/src/qemu/qemu_domain.c b/src/qemu/qemu_domain.c index 7e64545..b14afe0 100644 --- a/src/qemu/qemu_domain.c +++ b/src/qemu/qemu_domain.c @@ -3506,6 +3506,68 @@ ssize_t qemuDomainLogContextRead(qemuDomainLogContextPtr ctxt, } +/** + * qemuDomainLogAppendMessage: + * + * This is a best-effort attempt to add a log message to the qemu log file + * either by using virtlogd or the legacy approach */ +int +qemuDomainLogAppendMessage(virQEMUDriverPtr driver, + virDomainObjPtr vm, + const char *fmt, + ...) +{ + virQEMUDriverConfigPtr cfg = virQEMUDriverGetConfig(driver); + virLogManagerPtr manager = NULL; + va_list ap; + char *path = NULL; + int writefd = -1; + char *message = NULL; + int ret = -1; + + va_start(ap, fmt); + + if (virVasprintf(&message, fmt, ap) < 0) + goto cleanup; + + VIR_DEBUG("Append log message (vm='%s' message='%s) stdioLogD=%d", + vm->def->name, message, cfg->stdioLogD); + + if (virAsprintf(&path, "%s/%s.log", cfg->logDir, vm->def->name) < 0) + goto cleanup; + + if (cfg->stdioLogD) { + if (!(manager = virLogManagerNew(virQEMUDriverIsPrivileged(driver)))) + goto cleanup; + + if (virLogManagerDomainAppendMessage(manager, "qemu", vm->def->uuid, + vm->def->name, path, message, 0) < 0) + goto cleanup; + } else { + if ((writefd = open(path, O_WRONLY | O_CREAT | O_APPEND, S_IRUSR | S_IWUSR)) < 0) { + virReportSystemError(errno, _("failed to create logfile %s"), + path); + goto cleanup; + } + + if (safewrite(writefd, message, strlen(message)) < 0) + goto cleanup; + } + + ret = 0; + + cleanup: + va_end(ap); + VIR_FREE(message); + VIR_FORCE_CLOSE(writefd); + virLogManagerFree(manager); + virObjectUnref(cfg); + VIR_FREE(path); + + return ret; +} + + int qemuDomainLogContextGetWriteFD(qemuDomainLogContextPtr ctxt) { return ctxt->writefd; diff --git a/src/qemu/qemu_domain.h b/src/qemu/qemu_domain.h index a9a7295..25381b1 100644 --- a/src/qemu/qemu_domain.h +++ b/src/qemu/qemu_domain.h @@ -480,6 +480,11 @@ void qemuDomainLogContextFree(qemuDomainLogContextPtr ctxt); virLogManagerPtr qemuDomainLogContextGetManager(qemuDomainLogContextPtr ctxt); +int qemuDomainLogAppendMessage(virQEMUDriverPtr driver, + virDomainObjPtr vm, + const char *fmt, + ...) ATTRIBUTE_FMT_PRINTF(3, 4); + const char *qemuFindQemuImgBinary(virQEMUDriverPtr driver); int qemuDomainSnapshotWriteMetadata(virDomainObjPtr vm, -- 2.8.3

Use qemuDomainLogAppendMessage rather than attempting to open a new logging context with file descriptors. The new approach allows to log the message even if qemu is still running at that point which appens during migration finish phase where qemuProcessStop is killing qemu. Resolves: https://bugzilla.redhat.com/show_bug.cgi?id=1312188 --- src/qemu/qemu_process.c | 11 +++-------- 1 file changed, 3 insertions(+), 8 deletions(-) diff --git a/src/qemu/qemu_process.c b/src/qemu/qemu_process.c index 66bc4b1..84454ab 100644 --- a/src/qemu/qemu_process.c +++ b/src/qemu/qemu_process.c @@ -5605,7 +5605,6 @@ void qemuProcessStop(virQEMUDriverPtr driver, size_t i; char *timestamp; virQEMUDriverConfigPtr cfg = virQEMUDriverGetConfig(driver); - qemuDomainLogContextPtr logCtxt = NULL; VIR_DEBUG("Shutting down vm=%p name=%s id=%d pid=%llu, " "reason=%s, asyncJob=%s, flags=%x", @@ -5642,13 +5641,9 @@ void qemuProcessStop(virQEMUDriverPtr driver, /* Wake up anything waiting on domain condition */ virDomainObjBroadcast(vm); - if ((logCtxt = qemuDomainLogContextNew(driver, vm, - QEMU_DOMAIN_LOG_CONTEXT_MODE_STOP))) { - if ((timestamp = virTimeStringNow()) != NULL) { - qemuDomainLogContextWrite(logCtxt, "%s: shutting down\n", timestamp); - VIR_FREE(timestamp); - } - qemuDomainLogContextFree(logCtxt); + if ((timestamp = virTimeStringNow()) != NULL) { + qemuDomainLogAppendMessage(driver, vm, "%s: shutting down\n", timestamp); + VIR_FREE(timestamp); } /* Clear network bandwidth */ -- 2.8.3

Note the start of migration of a qemu process to the VM log file for possible debug purposes. --- src/qemu/qemu_migration.c | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/src/qemu/qemu_migration.c b/src/qemu/qemu_migration.c index 82d044f..38c07a8 100644 --- a/src/qemu/qemu_migration.c +++ b/src/qemu/qemu_migration.c @@ -4519,6 +4519,7 @@ qemuMigrationRun(virQEMUDriverPtr driver, bool inPostCopy = false; unsigned int waitFlags; virDomainDefPtr persistDef = NULL; + char *timestamp; int rc; VIR_DEBUG("driver=%p, vm=%p, cookiein=%s, cookieinlen=%d, " @@ -4645,6 +4646,12 @@ qemuMigrationRun(virQEMUDriverPtr driver, goto exit_monitor; } + /* log start of migration */ + if ((timestamp = virTimeStringNow()) != NULL) { + qemuDomainLogAppendMessage(driver, vm, "%s: initiating migration\n", timestamp); + VIR_FREE(timestamp); + } + switch (spec->destType) { case MIGRATION_DEST_HOST: if (STREQ(spec->dest.host.protocol, "rdma") && -- 2.8.3