[PATCH 14/19] qemu/dbus: log daemon stdout/err

marcandre.lureau@redhat.com posted 19 patches 7 months, 1 week ago
There is a newer version of this series
[PATCH 14/19] qemu/dbus: log daemon stdout/err
Posted by marcandre.lureau@redhat.com 7 months, 1 week ago
From: Marc-André Lureau <marcandre.lureau@redhat.com>

Currently, if dbus-daemon writes on errfd, it will SIGPIPE.

Signed-off-by: Marc-André Lureau <marcandre.lureau@redhat.com>
---
 src/qemu/qemu_dbus.c | 61 +++++++++++++++++++++++++++++++++++---------
 1 file changed, 49 insertions(+), 12 deletions(-)

diff --git a/src/qemu/qemu_dbus.c b/src/qemu/qemu_dbus.c
index 4a019ae092..0e22392e6f 100644
--- a/src/qemu/qemu_dbus.c
+++ b/src/qemu/qemu_dbus.c
@@ -18,12 +18,17 @@
 
 #include <config.h>
 
+#include <sys/types.h>
+#include <sys/stat.h>
+#include <fcntl.h>
+
 #include "qemu_dbus.h"
 #include "qemu_security.h"
 
 #include "virlog.h"
 #include "virtime.h"
 #include "virpidfile.h"
+#include "virutil.h"
 
 #define VIR_FROM_THIS VIR_FROM_NONE
 
@@ -67,6 +72,14 @@ qemuDBusCreateConfPath(virQEMUDriverConfig *cfg,
 }
 
 
+static char *
+qemuDBusCreateLogFilename(virQEMUDriverConfig *cfg,
+                          const char *shortName)
+{
+    return qemuDBusCreateFilename(cfg->dbusStateDir, shortName, ".log");
+}
+
+
 char *
 qemuDBusGetAddress(virQEMUDriver *driver,
                    virDomainObj *vm)
@@ -183,10 +196,11 @@ qemuDBusStart(virQEMUDriver *driver,
     g_autofree char *pidfile = NULL;
     g_autofree char *configfile = NULL;
     g_autofree char *sockpath = NULL;
+    g_autofree char *logpath = NULL;
     g_autofree char *address = NULL;
     virTimeBackOffVar timebackoff;
     const unsigned long long timeout = 500 * 1000; /* ms */
-    VIR_AUTOCLOSE errfd = -1;
+    VIR_AUTOCLOSE logfd = -1;
     pid_t cpid = -1;
     int ret = -1;
 
@@ -219,10 +233,40 @@ qemuDBusStart(virQEMUDriver *driver,
     if (qemuSecurityDomainSetPathLabel(driver, vm, configfile, false) < 0)
         goto cleanup;
 
+    logpath = qemuDBusCreateLogFilename(cfg, shortName);
+
+    if (cfg->stdioLogD) {
+        g_autoptr(virLogManager) logManager = virLogManagerNew(driver->privileged);
+
+        if (!logManager)
+            goto cleanup;
+
+        if ((logfd = virLogManagerDomainOpenLogFile(logManager,
+                                                    "qemu",
+                                                    vm->def->uuid,
+                                                    vm->def->name,
+                                                    logpath,
+                                                    0,
+                                                    NULL, NULL)) < 0)
+            goto cleanup;
+    } else {
+        if ((logfd = open(logpath, O_WRONLY | O_CREAT | O_APPEND, S_IRUSR | S_IWUSR)) < 0) {
+            virReportSystemError(errno, _("failed to create logfile %1$s"),
+                                 logpath);
+            goto cleanup;
+        }
+        if (virSetCloseExec(logfd) < 0) {
+            virReportSystemError(errno, _("failed to set close-on-exec flag on %1$s"),
+                                 logpath);
+            goto cleanup;
+        }
+    }
+
     cmd = virCommandNew(dbusDaemonPath);
     virCommandClearCaps(cmd);
     virCommandSetPidFile(cmd, pidfile);
-    virCommandSetErrorFD(cmd, &errfd);
+    virCommandSetOutputFD(cmd, &logfd);
+    virCommandSetErrorFD(cmd, &logfd);
     virCommandDaemonize(cmd);
     virCommandAddArgFormat(cmd, "--config-file=%s", configfile);
 
@@ -239,22 +283,15 @@ qemuDBusStart(virQEMUDriver *driver,
     if (virTimeBackOffStart(&timebackoff, 1, timeout) < 0)
         goto cleanup;
     while (virTimeBackOffWait(&timebackoff)) {
-        char errbuf[1024] = { 0 };
-
         if (virFileExists(sockpath))
             break;
 
         if (virProcessKill(cpid, 0) == 0)
             continue;
 
-        if (saferead(errfd, errbuf, sizeof(errbuf) - 1) < 0) {
-            virReportSystemError(errno,
-                                 _("dbus-daemon %1$s died unexpectedly"),
-                                 dbusDaemonPath);
-        } else {
-            virReportError(VIR_ERR_OPERATION_FAILED,
-                           _("dbus-daemon died and reported: %1$s"), errbuf);
-        }
+        virReportSystemError(errno,
+                             _("dbus-daemon %1$s died unexpectedly, check the log"),
+                             dbusDaemonPath);
 
         goto cleanup;
     }
-- 
2.47.0
Re: [PATCH 14/19] qemu/dbus: log daemon stdout/err
Posted by Daniel P. Berrangé 6 months, 4 weeks ago
On Wed, Jan 29, 2025 at 05:40:36PM +0400, marcandre.lureau@redhat.com wrote:
> From: Marc-André Lureau <marcandre.lureau@redhat.com>
> 
> Currently, if dbus-daemon writes on errfd, it will SIGPIPE.
> 
> Signed-off-by: Marc-André Lureau <marcandre.lureau@redhat.com>
> ---
>  src/qemu/qemu_dbus.c | 61 +++++++++++++++++++++++++++++++++++---------
>  1 file changed, 49 insertions(+), 12 deletions(-)
> 
> diff --git a/src/qemu/qemu_dbus.c b/src/qemu/qemu_dbus.c
> index 4a019ae092..0e22392e6f 100644
> --- a/src/qemu/qemu_dbus.c
> +++ b/src/qemu/qemu_dbus.c
> @@ -18,12 +18,17 @@
>  
>  #include <config.h>
>  
> +#include <sys/types.h>
> +#include <sys/stat.h>
> +#include <fcntl.h>
> +
>  #include "qemu_dbus.h"
>  #include "qemu_security.h"
>  
>  #include "virlog.h"
>  #include "virtime.h"
>  #include "virpidfile.h"
> +#include "virutil.h"
>  
>  #define VIR_FROM_THIS VIR_FROM_NONE
>  
> @@ -67,6 +72,14 @@ qemuDBusCreateConfPath(virQEMUDriverConfig *cfg,
>  }
>  
>  
> +static char *
> +qemuDBusCreateLogFilename(virQEMUDriverConfig *cfg,
> +                          const char *shortName)
> +{
> +    return qemuDBusCreateFilename(cfg->dbusStateDir, shortName, ".log");
> +}
> +
> +
>  char *
>  qemuDBusGetAddress(virQEMUDriver *driver,
>                     virDomainObj *vm)
> @@ -183,10 +196,11 @@ qemuDBusStart(virQEMUDriver *driver,
>      g_autofree char *pidfile = NULL;
>      g_autofree char *configfile = NULL;
>      g_autofree char *sockpath = NULL;
> +    g_autofree char *logpath = NULL;
>      g_autofree char *address = NULL;
>      virTimeBackOffVar timebackoff;
>      const unsigned long long timeout = 500 * 1000; /* ms */
> -    VIR_AUTOCLOSE errfd = -1;
> +    VIR_AUTOCLOSE logfd = -1;
>      pid_t cpid = -1;
>      int ret = -1;
>  
> @@ -219,10 +233,40 @@ qemuDBusStart(virQEMUDriver *driver,
>      if (qemuSecurityDomainSetPathLabel(driver, vm, configfile, false) < 0)
>          goto cleanup;
>  
> +    logpath = qemuDBusCreateLogFilename(cfg, shortName);
> +
> +    if (cfg->stdioLogD) {
> +        g_autoptr(virLogManager) logManager = virLogManagerNew(driver->privileged);
> +
> +        if (!logManager)
> +            goto cleanup;
> +
> +        if ((logfd = virLogManagerDomainOpenLogFile(logManager,
> +                                                    "qemu",
> +                                                    vm->def->uuid,
> +                                                    vm->def->name,
> +                                                    logpath,
> +                                                    0,
> +                                                    NULL, NULL)) < 0)
> +            goto cleanup;

Hmm, this is going to make the dbus logs be intermingled with the
QEMU logs which feels undesirable to me.

IIUC for swtpm we have a dedicated log file per VM, and probably
ought to follow that pattern generally for any helper app we
spawn off.

> +    } else {
> +        if ((logfd = open(logpath, O_WRONLY | O_CREAT | O_APPEND, S_IRUSR | S_IWUSR)) < 0) {
> +            virReportSystemError(errno, _("failed to create logfile %1$s"),
> +                                 logpath);
> +            goto cleanup;
> +        }
> +        if (virSetCloseExec(logfd) < 0) {
> +            virReportSystemError(errno, _("failed to set close-on-exec flag on %1$s"),
> +                                 logpath);
> +            goto cleanup;
> +        }
> +    }
> +
>      cmd = virCommandNew(dbusDaemonPath);
>      virCommandClearCaps(cmd);
>      virCommandSetPidFile(cmd, pidfile);
> -    virCommandSetErrorFD(cmd, &errfd);
> +    virCommandSetOutputFD(cmd, &logfd);
> +    virCommandSetErrorFD(cmd, &logfd);
>      virCommandDaemonize(cmd);
>      virCommandAddArgFormat(cmd, "--config-file=%s", configfile);
>  
> @@ -239,22 +283,15 @@ qemuDBusStart(virQEMUDriver *driver,
>      if (virTimeBackOffStart(&timebackoff, 1, timeout) < 0)
>          goto cleanup;
>      while (virTimeBackOffWait(&timebackoff)) {
> -        char errbuf[1024] = { 0 };
> -
>          if (virFileExists(sockpath))
>              break;
>  
>          if (virProcessKill(cpid, 0) == 0)
>              continue;
>  
> -        if (saferead(errfd, errbuf, sizeof(errbuf) - 1) < 0) {
> -            virReportSystemError(errno,
> -                                 _("dbus-daemon %1$s died unexpectedly"),
> -                                 dbusDaemonPath);
> -        } else {
> -            virReportError(VIR_ERR_OPERATION_FAILED,
> -                           _("dbus-daemon died and reported: %1$s"), errbuf);
> -        }
> +        virReportSystemError(errno,
> +                             _("dbus-daemon %1$s died unexpectedly, check the log"),
> +                             dbusDaemonPath);
>  
>          goto cleanup;
>      }
> -- 
> 2.47.0
> 

With 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 :|
Re: [PATCH 14/19] qemu/dbus: log daemon stdout/err
Posted by Daniel P. Berrangé 6 months, 4 weeks ago
On Wed, Feb 12, 2025 at 04:18:49PM +0000, Daniel P. Berrangé wrote:
> On Wed, Jan 29, 2025 at 05:40:36PM +0400, marcandre.lureau@redhat.com wrote:
> > From: Marc-André Lureau <marcandre.lureau@redhat.com>
> > 
> > Currently, if dbus-daemon writes on errfd, it will SIGPIPE.
> > 
> > Signed-off-by: Marc-André Lureau <marcandre.lureau@redhat.com>
> > ---
> >  src/qemu/qemu_dbus.c | 61 +++++++++++++++++++++++++++++++++++---------
> >  1 file changed, 49 insertions(+), 12 deletions(-)
> > 
> > diff --git a/src/qemu/qemu_dbus.c b/src/qemu/qemu_dbus.c
> > index 4a019ae092..0e22392e6f 100644
> > --- a/src/qemu/qemu_dbus.c
> > +++ b/src/qemu/qemu_dbus.c
> > @@ -18,12 +18,17 @@
> >  
> >  #include <config.h>
> >  
> > +#include <sys/types.h>
> > +#include <sys/stat.h>
> > +#include <fcntl.h>
> > +
> >  #include "qemu_dbus.h"
> >  #include "qemu_security.h"
> >  
> >  #include "virlog.h"
> >  #include "virtime.h"
> >  #include "virpidfile.h"
> > +#include "virutil.h"
> >  
> >  #define VIR_FROM_THIS VIR_FROM_NONE
> >  
> > @@ -67,6 +72,14 @@ qemuDBusCreateConfPath(virQEMUDriverConfig *cfg,
> >  }
> >  
> >  
> > +static char *
> > +qemuDBusCreateLogFilename(virQEMUDriverConfig *cfg,
> > +                          const char *shortName)
> > +{
> > +    return qemuDBusCreateFilename(cfg->dbusStateDir, shortName, ".log");
> > +}
> > +
> > +
> >  char *
> >  qemuDBusGetAddress(virQEMUDriver *driver,
> >                     virDomainObj *vm)
> > @@ -183,10 +196,11 @@ qemuDBusStart(virQEMUDriver *driver,
> >      g_autofree char *pidfile = NULL;
> >      g_autofree char *configfile = NULL;
> >      g_autofree char *sockpath = NULL;
> > +    g_autofree char *logpath = NULL;
> >      g_autofree char *address = NULL;
> >      virTimeBackOffVar timebackoff;
> >      const unsigned long long timeout = 500 * 1000; /* ms */
> > -    VIR_AUTOCLOSE errfd = -1;
> > +    VIR_AUTOCLOSE logfd = -1;
> >      pid_t cpid = -1;
> >      int ret = -1;
> >  
> > @@ -219,10 +233,40 @@ qemuDBusStart(virQEMUDriver *driver,
> >      if (qemuSecurityDomainSetPathLabel(driver, vm, configfile, false) < 0)
> >          goto cleanup;
> >  
> > +    logpath = qemuDBusCreateLogFilename(cfg, shortName);
> > +
> > +    if (cfg->stdioLogD) {
> > +        g_autoptr(virLogManager) logManager = virLogManagerNew(driver->privileged);
> > +
> > +        if (!logManager)
> > +            goto cleanup;
> > +
> > +        if ((logfd = virLogManagerDomainOpenLogFile(logManager,
> > +                                                    "qemu",
> > +                                                    vm->def->uuid,
> > +                                                    vm->def->name,
> > +                                                    logpath,
> > +                                                    0,
> > +                                                    NULL, NULL)) < 0)
> > +            goto cleanup;
> 
> Hmm, this is going to make the dbus logs be intermingled with the
> QEMU logs which feels undesirable to me.
> 
> IIUC for swtpm we have a dedicated log file per VM, and probably
> ought to follow that pattern generally for any helper app we
> spawn off.

Nevermind, I was mis-reading the code - 'logpath' will of course
be different from the main qemu log.

> 

> > @@ -239,22 +283,15 @@ qemuDBusStart(virQEMUDriver *driver,
> >      if (virTimeBackOffStart(&timebackoff, 1, timeout) < 0)
> >          goto cleanup;
> >      while (virTimeBackOffWait(&timebackoff)) {
> > -        char errbuf[1024] = { 0 };
> > -
> >          if (virFileExists(sockpath))
> >              break;
> >  
> >          if (virProcessKill(cpid, 0) == 0)
> >              continue;
> >  
> > -        if (saferead(errfd, errbuf, sizeof(errbuf) - 1) < 0) {
> > -            virReportSystemError(errno,
> > -                                 _("dbus-daemon %1$s died unexpectedly"),
> > -                                 dbusDaemonPath);
> > -        } else {
> > -            virReportError(VIR_ERR_OPERATION_FAILED,
> > -                           _("dbus-daemon died and reported: %1$s"), errbuf);
> > -        }
> > +        virReportSystemError(errno,
> > +                             _("dbus-daemon %1$s died unexpectedly, check the log"),
> > +                             dbusDaemonPath);

Here we could call g_file_get_contents(logpath) and include that in
the error message still.


With 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 :|