[Libvir] PATCH: Create a logfile for each QEMU vm

Daniel P. Berrange berrange at redhat.com
Tue May 15 22:27:11 UTC 2007


On Tue, May 15, 2007 at 06:37:40PM +0100, Daniel P. Berrange wrote:
> On Tue, May 15, 2007 at 05:15:04PM +0100, Daniel P. Berrange wrote:
> > On Tue, May 15, 2007 at 05:09:56PM +0100, Mark McLoughlin wrote:
> > > On Tue, 2007-05-15 at 17:04 +0100, Daniel P. Berrange wrote:
> > > 
> > > > For every VM we start it will create a logfile
> > > > 
> > > >   /etc/libvirt/qemu/logs/[vmname].log
> > > 
> > > 	Why not /var/log? /etc/ isn't the place for this kind of stuff, surely.
> > 
> > True - though we'd have to code different behaviour when running as an
> > unprivileged user. Shouldn't complicate things too much i guess.
> 
> Attached a new version which does this. If using qemu:///system they get
> put into /var/log/libvirt/qemu, while if using qemu://session they go into
> $HOME/.libvirt/qemu/log

Ok, attached is my final version.

 - qemu:///system per-VM logs are created in /var/log/libvirt/qemu/[vmname].log

 - qemu:///session per-VM logs are created in $HOME/.libvirt/qemu/log/[vmname].log

 - The exact QEMU command line argv is logged in aforementioned files

 - All data written to stderr/out by QEMU is logged in aforementioned files

 - There is a qemudValidateConfig() method we call before starting a VM which
   checks the path for kernel, initrd, each disk, and any script given for
   a network device setup.

 - The horrible 'End-of-file while reading PTY startup output' is replaced
   with less horrible 'QEMU quit during console startup'. Though I might
   reword that a little more

 - If QEMU fails during startup, we capture the contents of stderr and
   include them in the libvirt error message reported. I'm not entirely
   happy with this because this can make messages quite verbose, but at
   the same time we really need to feed this info back to the user. This
   is even more important with remote management where there's no easy
   access to log files.

So, here's some examples:


 - Starting a guest with mem set to 8 G - in this case QEMU provides zero
   useful error message, so we get the generic:

    # virsh --connect qemu:///system start wizz
    libvir: QEMU error : internal error QEMU shutdown while reading console startup output
    error: Failed to start domain wizz

 - Starting a guest with mem set to 1.9 G - this this case there is not
   enough free ram:

   # virsh --connect qemu:///system start wizz
   libvir: QEMU error : internal error QEMU shutdown while reading console startup output
   You do not have enough space in '/dev/shm' for the 1503 MB of QEMU virtual RAM.
   To have more space available provided you have enough RAM and swap, do as root:
   umount /dev/shm
   mount -t tmpfs -o size=1519m none /dev/shm
   Or disable the accelerator module with -no-kqemu
   error: Failed to start domain wizz

 - Starting a guest with a disk which doesn't exist:

   # virsh --connect qemu:///system start wizz
   libvir: QEMU error : internal error Cannot access disk hda at /home/berrange/src/xen/virtinst--devel/demo2: No such file or directory
   error: Failed to start domain wizz



Regards,
Dan.
-- 
|=- Red Hat, Engineering, Emerging Technologies, Boston.  +1 978 392 2496 -=|
|=-           Perl modules: http://search.cpan.org/~danberr/              -=|
|=-               Projects: http://freshmeat.net/~danielpb/               -=|
|=-  GnuPG: 7D3B9505   F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505  -=| 
-------------- next part --------------
diff -rup libvirt-0.2.2.orig/libvirt.spec.in libvirt-0.2.2.new/libvirt.spec.in
--- libvirt-0.2.2.orig/libvirt.spec.in	2007-04-17 05:33:16.000000000 -0400
+++ libvirt-0.2.2.new/libvirt.spec.in	2007-05-15 13:11:28.000000000 -0400
@@ -137,6 +137,7 @@ fi
 %{_datadir}/libvirt/networks/default.xml
 %dir %{_localstatedir}/run/libvirt/
 %dir %{_localstatedir}/lib/libvirt/
+%dir %attr(0700, root, root) %{_localstatedir}/log/libvirt/qemu/
 %attr(4755, root, root) %{_libexecdir}/libvirt_proxy
 %attr(0755, root, root) %{_sbindir}/libvirt_qemud
 %doc docs/libvirt.rng
diff -rup libvirt-0.2.2.orig/qemud/conf.c libvirt-0.2.2.new/qemud/conf.c
--- libvirt-0.2.2.orig/qemud/conf.c	2007-05-15 10:52:00.000000000 -0400
+++ libvirt-0.2.2.new/qemud/conf.c	2007-05-15 17:49:27.000000000 -0400
@@ -1189,6 +1189,58 @@ qemudNetworkIfaceConnect(struct qemud_se
     return NULL;
 }
 
+
+/* Does some basic sanity checking of config before a VM is run
+   to help improve error reporting */
+int qemudValidateConfig(struct qemud_server *server,
+                        struct qemud_vm *vm) {
+    struct stat sb;
+    struct qemud_vm_disk_def *disk = vm->def->disks;
+    struct qemud_vm_net_def *net = vm->def->nets;
+
+    if (vm->def->os.kernel[0] &&
+        stat(vm->def->os.kernel, &sb) < 0) {
+        qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
+                         "Cannot access kernel %s: %s",
+                         vm->def->os.kernel, strerror(errno));
+        return -1;
+    }
+
+    if (vm->def->os.initrd[0] &&
+        stat(vm->def->os.initrd, &sb) < 0) {
+        qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
+                         "Cannot access initrd %s: %s",
+                         vm->def->os.initrd, strerror(errno));
+        return -1;
+    }
+
+
+    while (disk) {
+        if (stat(disk->src, &sb) < 0) {
+            qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
+                             "Cannot access disk %s at %s: %s",
+                             disk->dst, disk->src, strerror(errno));
+            return -1;
+        }
+
+        disk = disk->next;
+    }
+
+    while (net) {
+        if (net->type == QEMUD_NET_ETHERNET &&
+            stat(net->dst.ethernet.script, &sb) < 0) {
+            qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
+                             "Cannot access network script %s: %s",
+                             net->dst.ethernet.script, strerror(errno));
+            return -1;
+        }
+
+        net = net->next;
+    }
+
+    return 0;
+}
+
 /*
  * Constructs a argv suitable for launching qemu with config defined
  * for a given virtual machine.
@@ -1211,12 +1263,12 @@ int qemudBuildCommandLine(struct qemud_s
 
     uname(&ut);
 
-    /* Nasty hack make i?86 look like i386 to simplify next comparison */
+    /* Nasty hack make i?86 look like i686 to simplify next comparison */
     if (ut.machine[0] == 'i' &&
         ut.machine[2] == '8' &&
         ut.machine[3] == '6' &&
         !ut.machine[4])
-        ut.machine[1] = '3';
+        ut.machine[1] = '6';
 
     /* Need to explicitly disable KQEMU if
      * 1. Arch matches host arch
diff -rup libvirt-0.2.2.orig/qemud/conf.h libvirt-0.2.2.new/qemud/conf.h
--- libvirt-0.2.2.orig/qemud/conf.h	2007-03-15 13:24:57.000000000 -0400
+++ libvirt-0.2.2.new/qemud/conf.h	2007-05-15 15:21:51.000000000 -0400
@@ -27,6 +27,8 @@
 #include "internal.h"
 
 int         qemudExtractVersion         (struct qemud_server *server);
+int         qemudValidateConfig         (struct qemud_server *server,
+                                         struct qemud_vm *vm);
 int         qemudBuildCommandLine       (struct qemud_server *server,
                                          struct qemud_vm *vm,
                                          char ***argv);
Only in libvirt-0.2.2.new/qemud: conf.h~
diff -rup libvirt-0.2.2.orig/qemud/internal.h libvirt-0.2.2.new/qemud/internal.h
--- libvirt-0.2.2.orig/qemud/internal.h	2007-05-15 10:52:00.000000000 -0400
+++ libvirt-0.2.2.new/qemud/internal.h	2007-05-15 15:27:50.000000000 -0400
@@ -213,6 +213,7 @@ struct qemud_vm {
     int stdout;
     int stderr;
     int monitor;
+    int logfile;
     int pid;
     int id;
     int state;
@@ -319,6 +320,7 @@ struct qemud_server {
     char *autostartDir;
     char *networkConfigDir;
     char *networkAutostartDir;
+    char logDir[PATH_MAX];
     char errorMessage[QEMUD_MAX_ERROR_LEN];
     int errorCode;
     unsigned int shutdown : 1;
diff -rup libvirt-0.2.2.orig/qemud/Makefile.am libvirt-0.2.2.new/qemud/Makefile.am
--- libvirt-0.2.2.orig/qemud/Makefile.am	2007-04-06 07:12:29.000000000 -0400
+++ libvirt-0.2.2.new/qemud/Makefile.am	2007-05-15 13:15:52.000000000 -0400
@@ -29,6 +29,7 @@ install-data-local:
 	sed -i -e "s,</name>,</name>\n  <uuid>$(UUID)</uuid>," $(DESTDIR)$(sysconfdir)/libvirt/qemu/networks/default.xml
 	test -e $(DESTDIR)$(sysconfdir)/libvirt/qemu/networks/autostart/default.xml || \
            ln -s ../default.xml $(DESTDIR)$(sysconfdir)/libvirt/qemu/networks/autostart/default.xml
+	mkdir -p $(DESTDIR)$(localstatedir)/log/libvirt/qemu
 	mkdir -p $(DESTDIR)$(localstatedir)/run/libvirt
 	mkdir -p $(DESTDIR)$(localstatedir)/lib/libvirt
 
@@ -36,6 +37,7 @@ uninstall-local:
 	rm -f $(DESTDIR)$(sysconfdir)/libvirt/qemu/networks/autostart/default.xml
 	rm -f $(DESTDIR)$(sysconfdir)/libvirt/qemu/networks/default.xml
 	rmdir $(DESTDIR)$(sysconfdir)/libvirt/qemu/networks/autostart || :
+	rmdir $(DESTDIR)$(localstatedir)/log/libvirt/qemu || :
 	rmdir $(DESTDIR)$(localstatedir)/run/libvirt || :
 	rmdir $(DESTDIR)$(localstatedir)/lib/libvirt || :
 
diff -rup libvirt-0.2.2.orig/qemud/qemud.c libvirt-0.2.2.new/qemud/qemud.c
--- libvirt-0.2.2.orig/qemud/qemud.c	2007-05-15 10:52:00.000000000 -0400
+++ libvirt-0.2.2.new/qemud/qemud.c	2007-05-15 18:03:58.000000000 -0400
@@ -439,6 +439,9 @@ static int qemudInitPaths(struct qemud_s
             goto snprintf_error;
 
         unlink(roSockname);
+
+        if (snprintf(server->logDir, PATH_MAX, "%s/log/libvirt/qemu", LOCAL_STATE_DIR) >= PATH_MAX)
+            goto snprintf_error;
     } else {
         if (!(pw = getpwuid(uid))) {
             qemudLog(QEMUD_ERR, "Failed to find user record for uid '%d': %s",
@@ -451,6 +454,9 @@ static int qemudInitPaths(struct qemud_s
 
         if (snprintf(base, PATH_MAX, "%s/.", pw->pw_dir) >= PATH_MAX)
             goto snprintf_error;
+
+        if (snprintf(server->logDir, PATH_MAX, "%s/.libvirt/qemu/log", pw->pw_dir) >= PATH_MAX)
+            goto snprintf_error;
     }
 
     for (i = 0; i < QEMUD_N_CONFIG_DIRS; i++)
@@ -647,6 +653,7 @@ qemudReadMonitorOutput(struct qemud_serv
 #define MONITOR_TIMEOUT 3000
 
     int got = 0;
+    buffer[0] = '\0';
 
    /* Consume & discard the initial greeting */
     while (got < (buflen-1)) {
@@ -655,7 +662,7 @@ qemudReadMonitorOutput(struct qemud_serv
         ret = read(fd, buffer+got, buflen-got-1);
         if (ret == 0) {
             qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
-                             "End-of-file while reading %s startup output", what);
+                             "QEMU quit during %s startup\n%s", what, buffer);
             return -1;
         }
         if (ret < 0) {
@@ -682,7 +689,7 @@ qemudReadMonitorOutput(struct qemud_serv
                 }
             } else if (pfd.revents & POLLHUP) {
                 qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
-                                 "End-of-file while reading %s startup output", what);
+                                 "QEMU quit during %s startup\n%s", what, buffer);
                 return -1;
             } else if (pfd.revents != POLLIN) {
                 qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
@@ -794,11 +801,22 @@ qemudOpenMonitorPath(struct qemud_server
 
 static int qemudWaitForMonitor(struct qemud_server *server, struct qemud_vm *vm) {
     char buffer[1024]; /* Plenty of space to get startup greeting */
+    int ret = qemudReadMonitorOutput(server, vm, vm->stderr,
+                                     buffer, sizeof(buffer),
+                                     qemudOpenMonitorPath,
+                                     "console");
 
-    return qemudReadMonitorOutput(server, vm, vm->stderr,
-                                  buffer, sizeof(buffer),
-                                  qemudOpenMonitorPath,
-                                  "PTY");
+    buffer[sizeof(buffer)-1] = '\0';
+ retry:
+    if (write(vm->logfile, buffer, strlen(buffer)) < 0) {
+        /* Log, but ignore failures to write logfile for VM */
+        if (errno == EINTR)
+            goto retry;
+        qemudLog(QEMUD_WARN, "Unable to log VM console data: %s",
+                 strerror(errno));
+    }
+
+    return ret;
 }
 
 static int qemudNextFreeVNCPort(struct qemud_server *server ATTRIBUTE_UNUSED) {
@@ -839,8 +857,9 @@ static int qemudNextFreeVNCPort(struct q
 
 int qemudStartVMDaemon(struct qemud_server *server,
                        struct qemud_vm *vm) {
-    char **argv = NULL;
+    char **argv = NULL, **tmp;
     int i, ret = -1;
+    char logfile[PATH_MAX];
 
     if (qemudIsActiveVM(vm)) {
         qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
@@ -859,8 +878,52 @@ int qemudStartVMDaemon(struct qemud_serv
     } else
         vm->def->vncActivePort = vm->def->vncPort;
 
-    if (qemudBuildCommandLine(server, vm, &argv) < 0)
+    if ((strlen(server->logDir) + /* path */
+         1 + /* Separator */
+         strlen(vm->def->name) + /* basename */
+         4 + /* suffix .log */
+         1 /* NULL */) > PATH_MAX) {
+        qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
+                         "config file path too long: %s/%s.log",
+                         server->logDir, vm->def->name);
         return -1;
+    }
+    strcpy(logfile, server->logDir);
+    strcat(logfile, "/");
+    strcat(logfile, vm->def->name);
+    strcat(logfile, ".log");
+
+    if (qemudValidateConfig(server, vm) < 0)
+        return -1;
+
+    if (qemudEnsureDir(server->logDir) < 0) {
+        qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
+                         "cannot create log directory %s: %s",
+                         server->logDir, strerror(errno));
+        return -1;
+    }
+
+    if ((vm->logfile = open(logfile, O_CREAT | O_TRUNC | O_WRONLY,
+                            S_IRUSR | S_IWUSR)) < 0) {
+        qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
+                         "failed to create logfile %s: %s",
+                         logfile, strerror(errno));
+        return -1;
+    }
+
+    if (qemudBuildCommandLine(server, vm, &argv) < 0) {
+        close(vm->logfile);
+        vm->logfile = -1;
+        return -1;
+    }
+
+    tmp = argv;
+    while (*tmp) {
+        write(vm->logfile, *tmp, strlen(*tmp));
+        write(vm->logfile, " ", 1);
+        tmp++;
+    }
+    write(vm->logfile, "\n", 1);
 
     if (qemudExec(server, argv, &vm->pid, &vm->stdout, &vm->stderr) == 0) {
         vm->id = server->nextvmid++;
@@ -1038,7 +1101,14 @@ static int qemudVMData(struct qemud_serv
         }
         buf[ret] = '\0';
 
-        qemudDebug("[%s]", buf);
+    retry:
+        if (write(vm->logfile, buf, ret) < 0) {
+            /* Log, but ignore failures to write logfile for VM */
+            if (errno == EINTR)
+                goto retry;
+            qemudLog(QEMUD_WARN, "Unable to log VM console data: %s",
+                     strerror(errno));
+        }
     }
 }
 
@@ -1053,10 +1123,12 @@ int qemudShutdownVMDaemon(struct qemud_s
 
     qemudVMData(server, vm, vm->stdout);
     qemudVMData(server, vm, vm->stderr);
+    close(vm->logfile);
     close(vm->stdout);
     close(vm->stderr);
     if (vm->monitor != -1)
         close(vm->monitor);
+    vm->logfile = -1;
     vm->stdout = -1;
     vm->stderr = -1;
     vm->monitor = -1;


More information about the libvir-list mailing list