Merge pull request #5040 from cyphar/1.4-better-init-errors-4928

[1.4] Better errors from `runc init`

Author: lifubang

libcontainer/container_linux.go

@@ -338,8 +338,6 @@ func (c *Container) start(process *Process) (retErr error) {
 	// We do not need the cloned binaries once the process is spawned.
 	defer process.closeClonedExes()
 
-	logsDone := parent.forwardChildLogs()
-
 	// Before starting "runc init", mark all non-stdio open files as O_CLOEXEC
 	// to make sure we don't leak any files into "runc init". Any files to be
 	// passed to "runc init" through ExtraFiles will get dup2'd by the Go
@@ -349,21 +347,28 @@ func (c *Container) start(process *Process) (retErr error) {
 	if err := utils.CloseExecFrom(3); err != nil {
 		return fmt.Errorf("unable to mark non-stdio fds as cloexec: %w", err)
 	}
-	if err := parent.start(); err != nil {
-		return fmt.Errorf("unable to start container process: %w", err)
-	}
 
-	if logsDone != nil {
+	if logsDone := parent.forwardChildLogs(); logsDone != nil {
 		defer func() {
 			// Wait for log forwarder to finish. This depends on
 			// runc init closing the _LIBCONTAINER_LOGPIPE log fd.
 			err := <-logsDone
-			if err != nil && retErr == nil {
-				retErr = fmt.Errorf("unable to forward init logs: %w", err)
+			if err != nil {
+				// runc init errors are important; make sure retErr has them.
+				err = fmt.Errorf("runc init error(s): %w", err)
+				if retErr != nil {
+					retErr = fmt.Errorf("%w; %w", retErr, err)
+				} else {
+					retErr = err
+				}
 			}
 		}()
 	}
 
+	if err := parent.start(); err != nil {
+		return fmt.Errorf("unable to start container process: %w", err)
+	}
+
 	if process.Init {
 		c.fifo.Close()
 		if c.config.HasHook(configs.Poststart) {

libcontainer/logs/logs.go

@@ -2,12 +2,16 @@ package logs
 
 import (
 	"bufio"
+	"bytes"
 	"encoding/json"
+	"errors"
 	"io"
 
 	"github.com/sirupsen/logrus"
 )
 
+var fatalsSep = []byte("; ")
+
 func ForwardLogs(logPipe io.ReadCloser) chan error {
 	done := make(chan error, 1)
 	s := bufio.NewScanner(logPipe)
@@ -23,24 +27,33 @@ func ForwardLogs(logPipe io.ReadCloser) chan error {
 	}
 
 	go func() {
+		fatals := []byte{}
 		for s.Scan() {
-			processEntry(s.Bytes(), logger)
+			fatals = processEntry(s.Bytes(), logger, fatals)
+		}
+		if err := s.Err(); err != nil {
+			logrus.Errorf("error reading from log source: %v", err)
 		}
 		if err := logPipe.Close(); err != nil {
 			logrus.Errorf("error closing log source: %v", err)
 		}
-		// The only error we want to return is when reading from
-		// logPipe has failed.
-		done <- s.Err()
+		// The only error we return is fatal messages from runc init.
+		var err error
+		if len(fatals) > 0 {
+			err = errors.New(string(bytes.TrimSuffix(fatals, fatalsSep)))
+		}
+		done <- err
 		close(done)
 	}()
 
 	return done
 }
 
-func processEntry(text []byte, logger *logrus.Logger) {
+// processEntry parses the error and either logs it via the standard logger or,
+// if this is a fatal error, appends its text to fatals.
+func processEntry(text []byte, logger *logrus.Logger, fatals []byte) []byte {
 	if len(text) == 0 {
-		return
+		return fatals
 	}
 
 	var jl struct {
@@ -49,8 +62,14 @@ func processEntry(text []byte, logger *logrus.Logger) {
 	}
 	if err := json.Unmarshal(text, &jl); err != nil {
 		logrus.Errorf("failed to decode %q to json: %v", text, err)
-		return
+		return fatals
 	}
 
-	logger.Log(jl.Level, jl.Msg)
+	if jl.Level == logrus.FatalLevel {
+		fatals = append(fatals, jl.Msg...)
+		fatals = append(fatals, fatalsSep...)
+	} else {
+		logger.Log(jl.Level, jl.Msg)
+	}
+	return fatals
 }

libcontainer/nsenter/log.h

@@ -26,15 +26,20 @@ bool log_enabled_for(int level);
 void write_log(int level, const char *format, ...) __attribute__((format(printf, 2, 3)));
 
 extern int logfd;
-#define bail(fmt, ...)                                               \
-	do {                                                         \
-		if (logfd < 0)                                       \
-			fprintf(stderr, "FATAL: " fmt ": %m\n",      \
-				##__VA_ARGS__);                      \
-		else                                                 \
-			write_log(FATAL, fmt ": %m", ##__VA_ARGS__); \
-		exit(1);                                             \
+
+/* bailx logs a message to logfd (or stderr, if logfd is not available)
+ * and terminates the program.
+ */
+#define bailx(fmt, ...)                                                     \
+	do {                                                                \
+		if (logfd < 0)                                              \
+			fprintf(stderr, "FATAL: " fmt "\n", ##__VA_ARGS__); \
+		else                                                        \
+			write_log(FATAL, fmt, ##__VA_ARGS__);               \
+		exit(1);                                                    \
 	} while(0)
 
+/* bail is the same as bailx, except it also adds ": %m" (errno). */
+#define bail(fmt, ...) bailx(fmt ": %m", ##__VA_ARGS__)
 
 #endif /* NSENTER_LOG_H */