From 58a67e037eefae16bf2f831de482e9070d590151 Mon Sep 17 00:00:00 2001 Message-Id: <58a67e037eefae16bf2f831de482e9070d590151@dist-git> From: =?UTF-8?q?Daniel=20P=2E=20Berrang=C3=A9?= Date: Tue, 21 May 2019 11:02:13 +0100 Subject: [PATCH] qemu: use line breaks in command line args written to log MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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é (cherry picked from commit 07c9d6601d0b440acd13794b258bdcb570ae93f4) https://bugzilla.redhat.com/show_bug.cgi?id=1672957 Conflicts: src/util/vircommand.c src/util/virfirewall.c - Not using auto cleanup macros in old branch Signed-off-by: Daniel P. Berrangé Message-Id: <20190521100213.16875-3-berrange@redhat.com> Reviewed-by: Ján Tomko --- 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 9284b51783..ae611fdb60 100644 --- a/src/bhyve/bhyve_driver.c +++ b/src/bhyve/bhyve_driver.c @@ -736,14 +736,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 3b3281c13f..704ba24215 100644 --- a/src/qemu/qemu_driver.c +++ b/src/qemu/qemu_driver.c @@ -7171,7 +7171,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 a3f13093f5..afef30d7cf 100644 --- a/src/qemu/qemu_interface.c +++ b/src/qemu/qemu_interface.c @@ -363,7 +363,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 8811aefb95..2795796166 100644 --- a/src/qemu/qemu_process.c +++ b/src/qemu/qemu_process.c @@ -4327,7 +4327,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 cb41df71a9..bb1742a686 100644 --- a/src/security/security_apparmor.c +++ b/src/security/security_apparmor.c @@ -661,7 +661,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 68cf63c28a..f539bafab6 100644 --- a/src/util/vircommand.c +++ b/src/util/vircommand.c @@ -1971,6 +1971,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 @@ -1980,10 +1981,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. */ @@ -2012,11 +2014,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) @@ -2459,7 +2472,7 @@ virCommandRunAsync(virCommandPtr cmd, pid_t *pid) goto cleanup; } - str = virCommandToString(cmd); + str = virCommandToString(cmd, false); if (dryRunBuffer || dryRunCallback) { dryRunStatus = 0; if (!str) { @@ -2599,7 +2612,7 @@ virCommandWait(virCommandPtr cmd, int *exitstatus) if (exitstatus && (cmd->rawStatus || WIFEXITED(status))) { *exitstatus = cmd->rawStatus ? status : WEXITSTATUS(status); } else if (status) { - char *str = virCommandToString(cmd); + char *str = virCommandToString(cmd, false); 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 883e212959..5ea2998f77 100644 --- a/src/util/vircommand.h +++ b/src/util/vircommand.h @@ -171,7 +171,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 10c370a2ae..79c2ef87e2 100644 --- a/src/util/virfirewall.c +++ b/src/util/virfirewall.c @@ -703,7 +703,7 @@ virFirewallApplyRuleDirect(virFirewallRulePtr rule, if (ignoreErrors) { VIR_DEBUG("Ignoring error running command"); } else { - char *args = virCommandToString(cmd); + 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 744a387aa0..4edef6157a 100644 --- a/tests/commandtest.c +++ b/tests/commandtest.c @@ -633,7 +633,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; } @@ -1138,6 +1138,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; @@ -1291,6 +1352,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 a29e63d950..9933e4bde1 100644 --- a/tests/qemuxml2argvtest.c +++ b/tests/qemuxml2argvtest.c @@ -575,7 +575,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 1e48910566..19a64303a7 100644 --- a/tests/storagepoolxml2argvtest.c +++ b/tests/storagepoolxml2argvtest.c @@ -60,7 +60,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.21.0