From 58a67e037eefae16bf2f831de482e9070d590151 Mon Sep 17 00:00:00 2001

Message-Id: <58a67e037eefae16bf2f831de482e9070d590151@dist-git>

From: =?UTF-8?q?Daniel=20P=2E=20Berrang=C3=A9?= <berrange@redhat.com>

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é <berrange@redhat.com>

(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é <berrange@redhat.com>

Message-Id: <20190521100213.16875-3-berrange@redhat.com>

Reviewed-by: Ján Tomko <jtomko@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 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