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

Daniel P. Berrange berrange at redhat.com
Wed May 16 18:09:16 UTC 2007


On Tue, May 15, 2007 at 11:27:11PM +0100, Daniel P. Berrange wrote:
> 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.

Bah, discovered a really nasty issue. The (existing) code assumed that the
revents field in poll struct would be POLLIN *or*  POLLHUP. 70% of the time
that was true, but sometimes it was POLLIN & POLLHUP in which case we were
throwing away valuable log output.

> 
>  - 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.

With my fix to deal with poll we can actually reliably get this info from
QEMU directly. Also having libvirt do stat() was failing with disk > 2GB
since we don't currently build with LFS enabled. So I've riped this out of
my latest patch.

> 
>  - 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.

This lets us also catch errors about missing 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

This now loooks like

# virsh --connect qemu:///system start wizz
libvir: QEMU error : internal error QEMU quit during console startup
qemu: could not open hard disk image '/home/berrange/src/xen/virtinst--devel/demo2'
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-16 13:55:00.000000000 -0400
@@ -1211,12 +1211,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
Only in libvirt-0.2.2.new/qemud: conf.c~
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-16 13:54:31.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,13 +662,15 @@ 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) {
             struct pollfd pfd = { .fd = fd, .events = POLLIN };
-            if (errno != EAGAIN &&
-                errno != EINTR) {
+            if (errno == EINTR)
+                continue;
+
+            if (errno != EAGAIN) {
                 qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
                                  "Failure while reading %s startup output: %s",
                                  what, strerror(errno));
@@ -680,11 +689,12 @@ qemudReadMonitorOutput(struct qemud_serv
                                      what, strerror(errno));
                     return -1;
                 }
-            } else if (pfd.revents & POLLHUP) {
-                qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
-                                 "End-of-file while reading %s startup output", what);
-                return -1;
-            } else if (pfd.revents != POLLIN) {
+            } else {
+                /* Make sure we continue loop & read any further data
+                   available before dealing with EOF */
+                if (pfd.revents & (POLLIN | POLLHUP))
+                    continue;
+
                 qemudReportError(server, VIR_ERR_INTERNAL_ERROR,
                                  "Failure while reading %s startup output", what);
                 return -1;
@@ -794,11 +804,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 +860,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 +881,49 @@ 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 (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,13 @@ int qemudShutdownVMDaemon(struct qemud_s
 
     qemudVMData(server, vm, vm->stdout);
     qemudVMData(server, vm, vm->stderr);
+    if (close(vm->logfile) < 0)
+        qemudLog(QEMUD_WARN, "Unable to close logfile %d: %s", errno, strerror(errno));
     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;
Only in libvirt-0.2.2.new/qemud: qemud.c~


More information about the libvir-list mailing list