lxc: Improve guest startup error reporting

Add a simple handshake with the lxc_controller process so we can detect
process startup failures. We do this by adding a new --handshake cli arg
to lxc_controller for passing a file descriptor. If the process fails to
launch, we scrape all output from the logfile and report it to the user.

src/lxc/lxc_container.c

@@ -213,7 +213,7 @@ error_out:
  *
  * Returns 0 on success or -1 in case of error
  */
-static int lxcContainerWaitForContinue(int control)
+int lxcContainerWaitForContinue(int control)
 {
     lxc_message_t msg;
     int readLen;

src/lxc/lxc_container.h

@@ -46,6 +46,7 @@ enum {
 # define LXC_DEV_MAJ_PTY     136
 
 int lxcContainerSendContinue(int control);
+int lxcContainerWaitForContinue(int control);
 
 int lxcContainerStart(virDomainDefPtr def,
                       unsigned int nveths,

src/lxc/lxc_controller.c

@@ -612,7 +612,8 @@ lxcControllerRun(virDomainDefPtr def,
                  char **veths,
                  int monitor,
                  int client,
-                 int appPty)
+                 int appPty,
+                 int handshakefd)
 {
     int rc = -1;
     int control[2] = { -1, -1};
@@ -742,6 +743,13 @@ lxcControllerRun(virDomainDefPtr def,
     if (lxcControllerClearCapabilities() < 0)
         goto cleanup;
 
+    if (lxcContainerSendContinue(handshakefd) < 0) {
+        virReportSystemError(errno, "%s",
+                             _("error sending continue signal to parent"));
+        goto cleanup;
+    }
+    VIR_FORCE_CLOSE(handshakefd);
+
     rc = lxcControllerMain(monitor, client, appPty, containerPty, container);
 
 cleanup:
@@ -751,6 +759,7 @@ cleanup:
     VIR_FORCE_CLOSE(control[1]);
     VIR_FREE(containerPtyPath);
     VIR_FORCE_CLOSE(containerPty);
+    VIR_FORCE_CLOSE(handshakefd);
 
     if (container > 1) {
         int status;
@@ -774,6 +783,7 @@ int main(int argc, char *argv[])
     char **veths = NULL;
     int monitor = -1;
     int appPty = -1;
+    int handshakefd = -1;
     int bg = 0;
     virCapsPtr caps = NULL;
     virDomainDefPtr def = NULL;
@@ -784,6 +794,7 @@ int main(int argc, char *argv[])
         { "name",   1, NULL, 'n' },
         { "veth",   1, NULL, 'v' },
         { "console", 1, NULL, 'c' },
+        { "handshakefd", 1, NULL, 's' },
         { "help", 0, NULL, 'h' },
         { 0, 0, 0, 0 },
     };
@@ -798,7 +809,7 @@ int main(int argc, char *argv[])
     while (1) {
         int c;
 
-        c = getopt_long(argc, argv, "dn:v:m:c:h",
+        c = getopt_long(argc, argv, "dn:v:m:c:s:h",
                        options, NULL);
 
         if (c == -1)
@@ -834,6 +845,14 @@ int main(int argc, char *argv[])
             }
             break;
 
+        case 's':
+            if (virStrToLong_i(optarg, NULL, 10, &handshakefd) < 0) {
+                fprintf(stderr, "malformed --handshakefd argument '%s'",
+                        optarg);
+                goto cleanup;
+            }
+            break;
+
         case 'h':
         case '?':
             fprintf(stderr, "\n");
@@ -845,6 +864,7 @@ int main(int argc, char *argv[])
             fprintf(stderr, "  -n NAME, --name NAME\n");
             fprintf(stderr, "  -c FD, --console FD\n");
             fprintf(stderr, "  -v VETH, --veth VETH\n");
+            fprintf(stderr, "  -s FD, --handshakefd FD\n");
             fprintf(stderr, "  -h, --help\n");
             fprintf(stderr, "\n");
             goto cleanup;
@@ -862,6 +882,12 @@ int main(int argc, char *argv[])
         goto cleanup;
     }
 
+    if (handshakefd < 0) {
+        fprintf(stderr, "%s: missing --handshake argument for container PTY\n",
+                argv[0]);
+        goto cleanup;
+    }
+
     if (getuid() != 0) {
         fprintf(stderr, "%s: must be run as the 'root' user\n", argv[0]);
         goto cleanup;
@@ -932,7 +958,8 @@ int main(int argc, char *argv[])
         goto cleanup;
     }
 
-    rc = lxcControllerRun(def, nveths, veths, monitor, client, appPty);
+    rc = lxcControllerRun(def, nveths, veths, monitor, client, appPty,
+                          handshakefd);
 
 
 cleanup:

src/lxc/lxc_driver.c

@@ -1287,7 +1287,8 @@ lxcBuildControllerCmd(lxc_driver_t *driver,
                       int nveths,
                       char **veths,
                       int appPty,
-                      int logfile)
+                      int logfile,
+                      int handshakefd)
 {
     int i;
     char *filterstr;
@@ -1332,6 +1333,8 @@ lxcBuildControllerCmd(lxc_driver_t *driver,
 
     virCommandAddArgList(cmd, "--name", vm->def->name, "--console", NULL);
     virCommandAddArgFormat(cmd, "%d", appPty);
+    virCommandAddArg(cmd, "--handshake");
+    virCommandAddArgFormat(cmd, "%d", handshakefd);
     virCommandAddArg(cmd, "--background");
 
     for (i = 0 ; i < nveths ; i++) {
@@ -1355,6 +1358,7 @@ lxcBuildControllerCmd(lxc_driver_t *driver,
     }
 
     virCommandPreserveFD(cmd, appPty);
+    virCommandPreserveFD(cmd, handshakefd);
     virCommandSetOutputFD(cmd, &logfile);
     virCommandSetErrorFD(cmd, &logfile);
 
@@ -1364,6 +1368,78 @@ cleanup:
     return NULL;
 }
 
+static int
+lxcReadLogOutput(virDomainObjPtr vm,
+                 char *logfile,
+                 off_t pos,
+                 char *buf,
+                 size_t buflen)
+{
+    int fd;
+    off_t off;
+    int whence;
+    int got = 0, ret = -1;
+    int retries = 10;
+
+    if ((fd = open(logfile, O_RDONLY)) < 0) {
+        virReportSystemError(errno, _("failed to open logfile %s"),
+                             logfile);
+        goto cleanup;
+    }
+
+    if (pos < 0) {
+        off = 0;
+        whence = SEEK_END;
+    } else {
+        off = pos;
+        whence = SEEK_SET;
+    }
+
+    if (lseek(fd, off, whence) < 0) {
+        if (whence == SEEK_END)
+            virReportSystemError(errno,
+                                 _("unable to seek to end of log for %s"),
+                                 logfile);
+        else
+            virReportSystemError(errno,
+                                 _("unable to seek to %lld from start for %s"),
+                                 (long long)off, logfile);
+        goto cleanup;
+    }
+
+    while (retries) {
+        ssize_t bytes;
+        int isdead = 0;
+
+        if (kill(vm->pid, 0) == -1 && errno == ESRCH)
+            isdead = 1;
+
+        /* Any failures should be detected before we read the log, so we
+         * always have something useful to report on failure. */
+        bytes = saferead(fd, buf+got, buflen-got-1);
+        if (bytes < 0) {
+            virReportSystemError(errno, "%s",
+                                 _("Failure while reading guest log output"));
+            goto cleanup;
+        }
+
+        got += bytes;
+        buf[got] = '\0';
+
+        if ((got == buflen-1) || isdead) {
+            break;
+        }
+
+        usleep(100*1000);
+        retries--;
+    }
+
+
+    ret = got;
+cleanup:
+    VIR_FORCE_CLOSE(fd);
+    return ret;
+}
 
 /**
  * lxcVmStart:
@@ -1389,6 +1465,7 @@ static int lxcVmStart(virConnectPtr conn,
     int logfd = -1;
     unsigned int nveths = 0;
     char **veths = NULL;
+    int handshakefds[2] = { -1, -1 };
     off_t pos = -1;
     char ebuf[1024];
     char *timestamp;
@@ -1462,10 +1539,16 @@ static int lxcVmStart(virConnectPtr conn,
         goto cleanup;
     }
 
+    if (pipe(handshakefds) < 0) {
+        virReportSystemError(errno, "%s",
+                             _("Unable to create pipe"));
+        goto cleanup;
+    }
+
     if (!(cmd = lxcBuildControllerCmd(driver,
                                       vm,
                                       nveths, veths,
-                                      parentTty, logfd)))
+                                      parentTty, logfd, handshakefds[1])))
         goto cleanup;
 
     /* Log timestamp */
@@ -1489,6 +1572,11 @@ static int lxcVmStart(virConnectPtr conn,
     if (virCommandRun(cmd, NULL) < 0)
         goto cleanup;
 
+    if (VIR_CLOSE(handshakefds[1]) < 0) {
+        virReportSystemError(errno, "%s", _("could not close handshake fd"));
+        goto cleanup;
+    }
+
     /* Connect to the controller as a client *first* because
      * this will block until the child has written their
      * pid file out to disk */
@@ -1506,6 +1594,18 @@ static int lxcVmStart(virConnectPtr conn,
     vm->def->id = vm->pid;
     virDomainObjSetState(vm, VIR_DOMAIN_RUNNING, reason);
 
+    if (lxcContainerWaitForContinue(handshakefds[0]) < 0) {
+        char out[1024];
+
+        if (!(lxcReadLogOutput(vm, logfile, pos, out, 1024) < 0)) {
+            lxcError(VIR_ERR_INTERNAL_ERROR,
+                     _("guest failed to start: %s"), out);
+        }
+
+        lxcVmTerminate(driver, vm, VIR_DOMAIN_SHUTOFF_FAILED);
+        goto cleanup;
+    }
+
     if ((priv->monitorWatch = virEventAddHandle(
              priv->monitor,
              VIR_EVENT_HANDLE_ERROR | VIR_EVENT_HANDLE_HANGUP,
@@ -1545,6 +1645,8 @@ cleanup:
     if (rc != 0)
         VIR_FORCE_CLOSE(priv->monitor);
     VIR_FORCE_CLOSE(parentTty);
+    VIR_FORCE_CLOSE(handshakefds[0]);
+    VIR_FORCE_CLOSE(handshakefds[1]);
     VIR_FREE(logfile);
     return rc;
 }