The QEMU command line arguments are very long and currently all written on a single line to /var/log/libvirt/qemu/$GUEST.log. This introduces logic to add line breaks after every env variable and "-" optional argument, and every positional argument. This will create a clearer log file, which will in turn present better in bug reports when people cut + paste from the log into a bug comment. An example log file entry now looks like this: 2018-12-14 12:57:03.677+0000: starting up libvirt version: 5.0.0, qemu version: 3.0.0qemu-3.0.0-1.fc29, kernel: 4.19.5-300.fc29.x86_64, hostname: localhost.localdomain LC_ALL=C \ PATH=/usr/local/bin:/usr/local/sbin:/usr/bin:/usr/sbin \ HOME=/home/berrange \ USER=berrange \ LOGNAME=berrange \ QEMU_AUDIO_DRV=none \ /usr/bin/qemu-system-ppc64 \ -name guest=guest,debug-threads=on \ -S \ -object secret,id=masterKey0,format=raw,file=/home/berrange/.config/libvirt/qemu/lib/domain-33-guest/master-key.aes \ -machine pseries-2.10,accel=tcg,usb=off,dump-guest-core=off \ -m 1024 \ -realtime mlock=off \ -smp 1,sockets=1,cores=1,threads=1 \ -uuid c8a74977-ab18-41d0-ae3b-4041c7fffbcd \ -display none \ -no-user-config \ -nodefaults \ -chardev socket,id=charmonitor,fd=23,server,nowait \ -mon chardev=charmonitor,id=monitor,mode=control \ -rtc base=utc \ -no-shutdown \ -boot strict=on \ -device qemu-xhci,id=usb,bus=pci.0,addr=0x1 \ -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x2 \ -sandbox on,obsolete=deny,elevateprivileges=deny,spawn=deny,resourcecontrol=deny \ -msg timestamp=on 2018-12-14 12:57:03.730+0000: shutting down, reason=failed Signed-off-by: Daniel P. Berrangé <berrange@redhat.com> --- docs/internals/command.html.in | 2 +- src/bhyve/bhyve_driver.c | 4 +- src/qemu/qemu_driver.c | 2 +- src/qemu/qemu_interface.c | 2 +- src/qemu/qemu_process.c | 2 +- src/security/security_apparmor.c | 2 +- src/util/vircommand.c | 19 ++++++++-- src/util/vircommand.h | 2 +- src/util/virfirewall.c | 2 +- tests/bhyvexml2argvtest.c | 4 +- tests/commanddata/test26.log | 1 + tests/commandtest.c | 64 +++++++++++++++++++++++++++++++- tests/qemuxml2argvtest.c | 2 +- tests/storagepoolxml2argvtest.c | 2 +- tests/storagevolxml2argvtest.c | 4 +- 15 files changed, 95 insertions(+), 19 deletions(-) create mode 100644 tests/commanddata/test26.log diff --git a/docs/internals/command.html.in b/docs/internals/command.html.in index 43f51a49bb..8a9061e70f 100644 --- a/docs/internals/command.html.in +++ b/docs/internals/command.html.in @@ -426,7 +426,7 @@ dprintf(logfd, "%s: ", timestamp); VIR_FREE(timestamp); virCommandWriteArgLog(cmd, logfd); -string = virCommandToString(cmd); +string = virCommandToString(cmd, false); if (string) VIR_DEBUG("about to run %s", string); VIR_FREE(string); diff --git a/src/bhyve/bhyve_driver.c b/src/bhyve/bhyve_driver.c index 4998100bc2..912797cfcf 100644 --- a/src/bhyve/bhyve_driver.c +++ b/src/bhyve/bhyve_driver.c @@ -733,14 +733,14 @@ bhyveConnectDomainXMLToNative(virConnectPtr conn, NULL))) goto cleanup; - virBufferAdd(&buf, virCommandToString(loadcmd), -1); + virBufferAdd(&buf, virCommandToString(loadcmd, false), -1); virBufferAddChar(&buf, '\n'); } if (!(cmd = virBhyveProcessBuildBhyveCmd(conn, def, true))) goto cleanup; - virBufferAdd(&buf, virCommandToString(cmd), -1); + virBufferAdd(&buf, virCommandToString(cmd, false), -1); if (virBufferCheckError(&buf) < 0) goto cleanup; diff --git a/src/qemu/qemu_driver.c b/src/qemu/qemu_driver.c index f9a22f8a4b..67b6f9097b 100644 --- a/src/qemu/qemu_driver.c +++ b/src/qemu/qemu_driver.c @@ -7425,7 +7425,7 @@ static char *qemuConnectDomainXMLToNative(virConnectPtr conn, VIR_QEMU_PROCESS_START_COLD))) goto cleanup; - ret = virCommandToString(cmd); + ret = virCommandToString(cmd, false); cleanup: virCommandFree(cmd); diff --git a/src/qemu/qemu_interface.c b/src/qemu/qemu_interface.c index cea1fd3046..ac0a17acc3 100644 --- a/src/qemu/qemu_interface.c +++ b/src/qemu/qemu_interface.c @@ -368,7 +368,7 @@ qemuCreateInBridgePortWithHelper(virQEMUDriverConfigPtr cfg, char ebuf[1024]; char *errstr = NULL; - if (!(cmdstr = virCommandToString(cmd))) + if (!(cmdstr = virCommandToString(cmd, false))) goto cleanup; virCommandAbort(cmd); diff --git a/src/qemu/qemu_process.c b/src/qemu/qemu_process.c index 6de510660a..8d8145d18f 100644 --- a/src/qemu/qemu_process.c +++ b/src/qemu/qemu_process.c @@ -4360,7 +4360,7 @@ qemuLogOperation(virDomainObjPtr vm, goto cleanup; if (cmd) { - char *args = virCommandToString(cmd); + char *args = virCommandToString(cmd, true); qemuDomainLogContextWrite(logCtxt, "%s\n", args); VIR_FREE(args); } diff --git a/src/security/security_apparmor.c b/src/security/security_apparmor.c index 0d28cae0b7..43310361ba 100644 --- a/src/security/security_apparmor.c +++ b/src/security/security_apparmor.c @@ -654,7 +654,7 @@ AppArmorSetSecurityChildProcessLabel(virSecurityManagerPtr mgr ATTRIBUTE_UNUSED, if ((profile_name = get_profile_name(def)) == NULL) goto cleanup; - cmd_str = virCommandToString(cmd); + cmd_str = virCommandToString(cmd, false); VIR_DEBUG("Changing AppArmor profile to %s on %s", profile_name, cmd_str); virCommandSetAppArmorProfile(cmd, profile_name); rc = 0; diff --git a/src/util/vircommand.c b/src/util/vircommand.c index 6f106df33b..3559f4bafa 100644 --- a/src/util/vircommand.c +++ b/src/util/vircommand.c @@ -1950,6 +1950,7 @@ virCommandWriteArgLog(virCommandPtr cmd, int logfd) /** * virCommandToString: * @cmd: the command to convert + * @linebreaks: true to break line after each env var or option * * Call after adding all arguments and environment settings, but * before Run/RunAsync, to return a string representation of the @@ -1959,10 +1960,11 @@ virCommandWriteArgLog(virCommandPtr cmd, int logfd) * Caller is responsible for freeing the resulting string. */ char * -virCommandToString(virCommandPtr cmd) +virCommandToString(virCommandPtr cmd, bool linebreaks) { size_t i; virBuffer buf = VIR_BUFFER_INITIALIZER; + bool prevopt = false; /* Cannot assume virCommandRun will be called; so report the error * now. If virCommandRun is called, it will report the same error. */ @@ -1991,11 +1993,22 @@ virCommandToString(virCommandPtr cmd) virBufferAdd(&buf, cmd->env[i], eq - cmd->env[i]); virBufferEscapeShell(&buf, eq); virBufferAddChar(&buf, ' '); + if (linebreaks) + virBufferAddLit(&buf, "\\\n"); } virBufferEscapeShell(&buf, cmd->args[0]); for (i = 1; i < cmd->nargs; i++) { virBufferAddChar(&buf, ' '); + if (linebreaks) { + /* Line break if this is a --arg or if + * the previous arg was a positional option + */ + if (cmd->args[i][0] == '-' || + !prevopt) + virBufferAddLit(&buf, "\\\n"); + } virBufferEscapeShell(&buf, cmd->args[i]); + prevopt = (cmd->args[i][0] == '-'); } if (virBufferCheckError(&buf) < 0) @@ -2438,7 +2451,7 @@ virCommandRunAsync(virCommandPtr cmd, pid_t *pid) goto cleanup; } - str = virCommandToString(cmd); + str = virCommandToString(cmd, false); if (dryRunBuffer || dryRunCallback) { dryRunStatus = 0; if (!str) { @@ -2579,7 +2592,7 @@ virCommandWait(virCommandPtr cmd, int *exitstatus) if (exitstatus && (cmd->rawStatus || WIFEXITED(status))) { *exitstatus = cmd->rawStatus ? status : WEXITSTATUS(status); } else if (status) { - VIR_AUTOFREE(char *) str = virCommandToString(cmd); + VIR_AUTOFREE(char *) str = virCommandToString(cmd, false); VIR_AUTOFREE(char *) st = virProcessTranslateStatus(status); bool haveErrMsg = cmd->errbuf && *cmd->errbuf && (*cmd->errbuf)[0]; diff --git a/src/util/vircommand.h b/src/util/vircommand.h index f299acc775..dbf5041890 100644 --- a/src/util/vircommand.h +++ b/src/util/vircommand.h @@ -172,7 +172,7 @@ void virCommandSetPreExecHook(virCommandPtr cmd, void virCommandWriteArgLog(virCommandPtr cmd, int logfd); -char *virCommandToString(virCommandPtr cmd) ATTRIBUTE_RETURN_CHECK; +char *virCommandToString(virCommandPtr cmd, bool linebreaks) ATTRIBUTE_RETURN_CHECK; int virCommandExec(virCommandPtr cmd, gid_t *groups, int ngroups) ATTRIBUTE_RETURN_CHECK; diff --git a/src/util/virfirewall.c b/src/util/virfirewall.c index c25d2ddfad..5a0cf95a44 100644 --- a/src/util/virfirewall.c +++ b/src/util/virfirewall.c @@ -694,7 +694,7 @@ virFirewallApplyRuleDirect(virFirewallRulePtr rule, if (ignoreErrors) { VIR_DEBUG("Ignoring error running command"); } else { - VIR_AUTOFREE(char *) args = virCommandToString(cmd); + VIR_AUTOFREE(char *) args = virCommandToString(cmd, false); virReportError(VIR_ERR_INTERNAL_ERROR, _("Failed to apply firewall rules %s: %s"), NULLSTR(args), NULLSTR(error)); diff --git a/tests/bhyvexml2argvtest.c b/tests/bhyvexml2argvtest.c index 6d5f19e2c6..d1b486fa64 100644 --- a/tests/bhyvexml2argvtest.c +++ b/tests/bhyvexml2argvtest.c @@ -68,13 +68,13 @@ static int testCompareXMLToArgvFiles(const char *xml, goto out; } - if (!(actualargv = virCommandToString(cmd))) + if (!(actualargv = virCommandToString(cmd, false))) goto out; if (actualdm != NULL) virTrimSpaces(actualdm, NULL); - if (!(actualld = virCommandToString(ldcmd))) + if (!(actualld = virCommandToString(ldcmd, false))) goto out; if (virTestCompareToFile(actualargv, cmdline) < 0) diff --git a/tests/commanddata/test26.log b/tests/commanddata/test26.log new file mode 100644 index 0000000000..db0d424875 --- /dev/null +++ b/tests/commanddata/test26.log @@ -0,0 +1 @@ +A=B C=D E true --foo bar --oooh -f --wizz eek eek -w -z -l --mmm flash bang wallop diff --git a/tests/commandtest.c b/tests/commandtest.c index 4d9a468db2..816a70860f 100644 --- a/tests/commandtest.c +++ b/tests/commandtest.c @@ -630,7 +630,7 @@ static int test16(const void *unused ATTRIBUTE_UNUSED) virCommandAddArg(cmd, "F"); virCommandAddArg(cmd, "G H"); - if ((outactual = virCommandToString(cmd)) == NULL) { + if ((outactual = virCommandToString(cmd, false)) == NULL) { printf("Cannot convert to string: %s\n", virGetLastErrorMessage()); goto cleanup; } @@ -1135,6 +1135,67 @@ static int test25(const void *unused ATTRIBUTE_UNUSED) } +/* + * Don't run program; rather, log what would be run. + */ +static int test26(const void *unused ATTRIBUTE_UNUSED) +{ + virCommandPtr cmd = virCommandNew("true"); + char *outactual = NULL; + const char *outexpect = + "A=B \\\n" + "C='D E' \\\n" + "true \\\n" + "--foo bar \\\n" + "--oooh \\\n" + "-f \\\n" + "--wizz 'eek eek' \\\n" + "-w \\\n" + "-z \\\n" + "-l \\\n" + "--mmm flash \\\n" + "bang \\\n" + "wallop"; + + int ret = -1; + int fd = -1; + + virCommandAddEnvPair(cmd, "A", "B"); + virCommandAddEnvPair(cmd, "C", "D E"); + virCommandAddArgList(cmd, "--foo", "bar", "--oooh", "-f", + "--wizz", "eek eek", "-w", "-z", "-l", + "--mmm", "flash", "bang", "wallop", + NULL); + + if ((outactual = virCommandToString(cmd, true)) == NULL) { + printf("Cannot convert to string: %s\n", virGetLastErrorMessage()); + goto cleanup; + } + if ((fd = open(abs_builddir "/commandhelper.log", + O_CREAT | O_TRUNC | O_WRONLY, 0600)) < 0) { + printf("Cannot open log file: %s\n", strerror(errno)); + goto cleanup; + } + virCommandWriteArgLog(cmd, fd); + if (VIR_CLOSE(fd) < 0) { + printf("Cannot close log file: %s\n", strerror(errno)); + goto cleanup; + } + + if (STRNEQ(outactual, outexpect)) { + virTestDifference(stderr, outexpect, outactual); + goto cleanup; + } + + ret = checkoutput("test26", NULL); + + cleanup: + virCommandFree(cmd); + VIR_FORCE_CLOSE(fd); + VIR_FREE(outactual); + return ret; +} + static void virCommandThreadWorker(void *opaque) { virCommandTestDataPtr test = opaque; @@ -1288,6 +1349,7 @@ mymain(void) DO_TEST(test23); DO_TEST(test24); DO_TEST(test25); + DO_TEST(test26); virMutexLock(&test->lock); if (test->running) { diff --git a/tests/qemuxml2argvtest.c b/tests/qemuxml2argvtest.c index 287e9d4ea3..5812e85436 100644 --- a/tests/qemuxml2argvtest.c +++ b/tests/qemuxml2argvtest.c @@ -620,7 +620,7 @@ testCompareXMLToArgv(const void *data) goto cleanup; } - if (!(actualargv = virCommandToString(cmd))) + if (!(actualargv = virCommandToString(cmd, false))) goto cleanup; if (virTestCompareToFile(actualargv, args) < 0) diff --git a/tests/storagepoolxml2argvtest.c b/tests/storagepoolxml2argvtest.c index 196989cb6d..2f2d40e027 100644 --- a/tests/storagepoolxml2argvtest.c +++ b/tests/storagepoolxml2argvtest.c @@ -71,7 +71,7 @@ testCompareXMLToArgvFiles(bool shouldFail, goto cleanup; }; - if (!(actualCmdline = virCommandToString(cmd))) { + if (!(actualCmdline = virCommandToString(cmd, false))) { VIR_TEST_DEBUG("pool type %d failed to get commandline\n", def->type); goto cleanup; } diff --git a/tests/storagevolxml2argvtest.c b/tests/storagevolxml2argvtest.c index 105705f348..bc2da37410 100644 --- a/tests/storagevolxml2argvtest.c +++ b/tests/storagevolxml2argvtest.c @@ -104,14 +104,14 @@ testCompareXMLToArgvFiles(bool shouldFail, } if (convertStep != VIR_STORAGE_VOL_ENCRYPT_CONVERT) { - if (!(actualCmdline = virCommandToString(cmd))) + if (!(actualCmdline = virCommandToString(cmd, false))) goto cleanup; } else { char *createCmdline = actualCmdline; char *cvtCmdline; int rc; - if (!(cvtCmdline = virCommandToString(cmd))) + if (!(cvtCmdline = virCommandToString(cmd, false))) goto cleanup; rc = virAsprintf(&actualCmdline, "%s\n%s", -- 2.19.2