[libvirt] [PATCH] qemu: use line breaks in command line args written to log

Daniel P. Berrangé posted 1 patch 5 years, 4 months ago
Test syntax-check passed
Patches applied successfully (tree, apply log)
git fetch https://github.com/patchew-project/libvirt tags/patchew/20181214130710.16442-1-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
[libvirt] [PATCH] qemu: use line breaks in command line args written to log
Posted by Daniel P. Berrangé 5 years, 4 months ago
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

--
libvir-list mailing list
libvir-list@redhat.com
https://www.redhat.com/mailman/listinfo/libvir-list
Re: [libvirt] [PATCH] qemu: use line breaks in command line args written to log
Posted by Michal Privoznik 5 years, 4 months ago
On 12/14/18 2:07 PM, Daniel P. Berrangé wrote:
> 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
> 


> @@ -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] == '-');

Unfortunately, cmd->args[i] can be NULL here. So I guess this needs to
look slightly different:

    for (i = 1; i < cmd->nargs; i++) {
        virBufferAddChar(&buf, ' ');

        if (!cmd->args[i])
            continue;

        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] == '-');
    }


ACK if you fix this.

Michal

--
libvir-list mailing list
libvir-list@redhat.com
https://www.redhat.com/mailman/listinfo/libvir-list
Re: [libvirt] [PATCH] qemu: use line breaks in command line args written to log
Posted by Daniel P. Berrangé 5 years, 4 months ago
On Fri, Dec 14, 2018 at 04:42:12PM +0100, Michal Privoznik wrote:
> On 12/14/18 2:07 PM, Daniel P. Berrangé wrote:
> > 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
> > 
> 
> 
> > @@ -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] == '-');
> 
> Unfortunately, cmd->args[i] can be NULL here. So I guess this needs to
> look slightly different:

Hmm, what scenario would make that happen ?  I didn't get that
failure in the test suite. 

> 
>     for (i = 1; i < cmd->nargs; i++) {
>         virBufferAddChar(&buf, ' ');
> 
>         if (!cmd->args[i])
>             continue;
> 
>         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] == '-');
>     }
> 
> 
> ACK if you fix this.
> 
> Michal

Regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

--
libvir-list mailing list
libvir-list@redhat.com
https://www.redhat.com/mailman/listinfo/libvir-list
Re: [libvirt] [PATCH] qemu: use line breaks in command line args written to log
Posted by Michal Prívozník 5 years, 4 months ago
On 12/14/18 4:55 PM, Daniel P. Berrangé wrote:
> On Fri, Dec 14, 2018 at 04:42:12PM +0100, Michal Privoznik wrote:
>> On 12/14/18 2:07 PM, Daniel P. Berrangé wrote:
>>> 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
>>>
>>
>>
>>> @@ -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] == '-');
>>
>> Unfortunately, cmd->args[i] can be NULL here. So I guess this needs to
>> look slightly different:
> 
> Hmm, what scenario would make that happen ?  I didn't get that
> failure in the test suite. 


Are you running against the latest HEAD?

Program received signal SIGSEGV, Segmentation fault.
0x000055555563040b in virCommandToString (cmd=0x555555964b10, linebreaks=false) at util/vircommand.c:2012
2012            prevopt = (cmd->args[i][0] == '-');

virCommandToString 1 $ bt
#0  0x000055555563040b in virCommandToString (cmd=0x555555964b10, linebreaks=false) at util/vircommand.c:2012
#1  0x0000555555587c0c in testCompareXMLToArgvFiles (shouldFail=false, poolxml=0x555555951990 "/home/zippy/work/libvirt/libvirt.git/tests/storagepoolxml2xmlin/pool-dir.xml", volxml=0x5555559582e0 "/home/zippy/work/libvirt/libvirt.git/tests/storagevolxml2xmlin/vol-qcow2-zerocapacity.xml", inputpoolxml=0x0, inputvolxml=0x0, cmdline=0x555555958350 "/home/zippy/work/libvirt/libvirt.git/tests/storagevolxml2argvdata/qcow2-zerocapacity.argv", flags=0, parse_flags=0) at storagevolxml2argvtest.c:107
#2  0x0000555555587fee in testCompareXMLToArgvHelper (data=0x7fffffffd4f0) at storagevolxml2argvtest.c:190
#3  0x0000555555588bc1 in virTestRun (title=0x5555556b4e30 "Storage Vol XML-2-argv qcow2-zerocapacity", body=0x555555587d86 <testCompareXMLToArgvHelper>, data=0x7fffffffd4f0) at testutils.c:176
#4  0x0000555555588508 in mymain () at storagevolxml2argvtest.c:259
#5  0x000055555558ac49 in virTestMain (argc=1, argv=0x7fffffffd798, func=0x555555588056 <mymain>) at testutils.c:1114
#6  0x0000555555588a08 in main (argc=1, argv=0x7fffffffd798) at storagevolxml2argvtest.c:307

virCommandToString 1 $ p cmd->args[i]
$1 = 0x0

virCommandToString 1 $ p i
$2 = 6

This happens because info.path or vol->target.path in virStorageBackendCreateQemuImgCmdFromVol() is NULL. Later, info.path is added to cmd on line 1182:

  virCommandAddArg(cmd, info.path);

One can argue that the bug is in fact that info.path is NULL and it may very well be so, but I think the following should not lead to a crash either:

  cmd = virCommandNew("/bin/bash");
  virCommandAddArg(cmd, NULL);
  virCommanRun(cmd);

Michal

--
libvir-list mailing list
libvir-list@redhat.com
https://www.redhat.com/mailman/listinfo/libvir-list