diff --git a/exec.go b/exec.go index f8baff3d152..65d0ce42e90 100644 --- a/exec.go +++ b/exec.go @@ -134,11 +134,6 @@ func execProcess(context *cli.Context) (int, error) { return -1, err } - logLevel := "info" - if context.GlobalBool("debug") { - logLevel = "debug" - } - r := &runner{ enableSubreaper: false, shouldDestroy: false, @@ -149,7 +144,6 @@ func execProcess(context *cli.Context) (int, error) { action: CT_ACT_RUN, init: false, preserveFDs: context.Int("preserve-fds"), - logLevel: logLevel, } return r.run(p) } diff --git a/init.go b/init.go index d39492952a3..24ca4847b4f 100644 --- a/init.go +++ b/init.go @@ -7,7 +7,6 @@ import ( "strconv" "github.com/opencontainers/runc/libcontainer" - "github.com/opencontainers/runc/libcontainer/logs" _ "github.com/opencontainers/runc/libcontainer/nsenter" "github.com/sirupsen/logrus" ) @@ -19,25 +18,22 @@ func init() { runtime.GOMAXPROCS(1) runtime.LockOSThread() - level := os.Getenv("_LIBCONTAINER_LOGLEVEL") - logLevel, err := logrus.ParseLevel(level) + // Configure logrus to talk to the parent. + level, err := strconv.Atoi(os.Getenv("_LIBCONTAINER_LOGLEVEL")) if err != nil { - panic(fmt.Sprintf("libcontainer: failed to parse log level: %q: %v", level, err)) + panic(fmt.Sprintf("libcontainer: failed to parse _LIBCONTAINER_LOGLEVEL: %s", err)) } + logrus.SetLevel(logrus.Level(level)) logPipeFdStr := os.Getenv("_LIBCONTAINER_LOGPIPE") logPipeFd, err := strconv.Atoi(logPipeFdStr) if err != nil { panic(fmt.Sprintf("libcontainer: failed to convert environment variable _LIBCONTAINER_LOGPIPE=%s to int: %s", logPipeFdStr, err)) } - err = logs.ConfigureLogging(logs.Config{ - LogPipeFd: logPipeFd, - LogFormat: "json", - LogLevel: logLevel, - }) - if err != nil { - panic(fmt.Sprintf("libcontainer: failed to configure logging: %v", err)) - } + + logrus.SetOutput(os.NewFile(uintptr(logPipeFd), "logpipe")) + + logrus.SetFormatter(new(logrus.JSONFormatter)) logrus.Debug("child process in init()") factory, _ := libcontainer.New("") diff --git a/libcontainer/logs/logs.go b/libcontainer/logs/logs.go index 07592176b51..95deb0d6ca7 100644 --- a/libcontainer/logs/logs.go +++ b/libcontainer/logs/logs.go @@ -3,37 +3,28 @@ package logs import ( "bufio" "encoding/json" - "errors" - "fmt" "io" - "os" - "sync" "github.com/sirupsen/logrus" ) -var ( - configureMutex sync.Mutex - // loggingConfigured will be set once logging has been configured via invoking `ConfigureLogging`. - // Subsequent invocations of `ConfigureLogging` would be no-op - loggingConfigured = false -) - -type Config struct { - LogLevel logrus.Level - LogFormat string - LogFilePath string - LogPipeFd int - LogCaller bool -} - func ForwardLogs(logPipe io.ReadCloser) chan error { done := make(chan error, 1) s := bufio.NewScanner(logPipe) + logger := logrus.StandardLogger() + if logger.ReportCaller { + // Need a copy of the standard logger, but with ReportCaller + // turned off, as the logs are merely forwarded and their + // true source is not this file/line/function. + logNoCaller := *logrus.StandardLogger() + logNoCaller.ReportCaller = false + logger = &logNoCaller + } + go func() { for s.Scan() { - processEntry(s.Bytes()) + processEntry(s.Bytes(), logger) } if err := logPipe.Close(); err != nil { logrus.Errorf("error closing log source: %v", err) @@ -47,60 +38,19 @@ func ForwardLogs(logPipe io.ReadCloser) chan error { return done } -func processEntry(text []byte) { +func processEntry(text []byte, logger *logrus.Logger) { if len(text) == 0 { return } var jl struct { - Level string `json:"level"` - Msg string `json:"msg"` + Level logrus.Level `json:"level"` + Msg string `json:"msg"` } if err := json.Unmarshal(text, &jl); err != nil { logrus.Errorf("failed to decode %q to json: %v", text, err) return } - lvl, err := logrus.ParseLevel(jl.Level) - if err != nil { - logrus.Errorf("failed to parse log level %q: %v", jl.Level, err) - return - } - logrus.StandardLogger().Logf(lvl, jl.Msg) -} - -func ConfigureLogging(config Config) error { - configureMutex.Lock() - defer configureMutex.Unlock() - - if loggingConfigured { - return errors.New("logging has already been configured") - } - - logrus.SetLevel(config.LogLevel) - logrus.SetReportCaller(config.LogCaller) - - // XXX: while 0 is a valid fd (usually stdin), here we assume - // that we never deliberately set LogPipeFd to 0. - if config.LogPipeFd > 0 { - logrus.SetOutput(os.NewFile(uintptr(config.LogPipeFd), "logpipe")) - } else if config.LogFilePath != "" { - f, err := os.OpenFile(config.LogFilePath, os.O_CREATE|os.O_WRONLY|os.O_APPEND|os.O_SYNC, 0o644) - if err != nil { - return err - } - logrus.SetOutput(f) - } - - switch config.LogFormat { - case "text": - // retain logrus's default. - case "json": - logrus.SetFormatter(new(logrus.JSONFormatter)) - default: - return fmt.Errorf("unknown log-format %q", config.LogFormat) - } - - loggingConfigured = true - return nil + logger.Log(jl.Level, jl.Msg) } diff --git a/libcontainer/logs/logs_linux_test.go b/libcontainer/logs/logs_linux_test.go index 7e2b59d9cd7..5f975c8da57 100644 --- a/libcontainer/logs/logs_linux_test.go +++ b/libcontainer/logs/logs_linux_test.go @@ -11,44 +11,51 @@ import ( "github.com/sirupsen/logrus" ) +const msgErr = `"level":"error"` + func TestLoggingToFile(t *testing.T) { l := runLogForwarding(t) - logToLogWriter(t, l, `{"level": "info","msg":"kitten"}`) + msg := `"level":"info","msg":"kitten"` + logToLogWriter(t, l, msg) finish(t, l) - check(t, l, "kitten") + check(t, l, msg, msgErr) } func TestLogForwardingDoesNotStopOnJsonDecodeErr(t *testing.T) { l := runLogForwarding(t) - logToLogWriter(t, l, "invalid-json-with-kitten") - checkWait(t, l, "failed to decode") + logToLogWriter(t, l, `"invalid-json-with-kitten"`) + checkWait(t, l, msgErr, "") truncateLogFile(t, l.file) - logToLogWriter(t, l, `{"level": "info","msg":"puppy"}`) + msg := `"level":"info","msg":"puppy"` + logToLogWriter(t, l, msg) finish(t, l) - check(t, l, "puppy") + check(t, l, msg, msgErr) } func TestLogForwardingDoesNotStopOnLogLevelParsingErr(t *testing.T) { l := runLogForwarding(t) - logToLogWriter(t, l, `{"level": "alert","msg":"puppy"}`) - checkWait(t, l, "failed to parse log level") + msg := `"level":"alert","msg":"puppy"` + logToLogWriter(t, l, msg) + checkWait(t, l, msgErr, msg) truncateLogFile(t, l.file) - logToLogWriter(t, l, `{"level": "info","msg":"puppy"}`) + msg = `"level":"info","msg":"puppy"` + logToLogWriter(t, l, msg) finish(t, l) - check(t, l, "puppy") + check(t, l, msg, msgErr) } func TestLogForwardingStopsAfterClosingTheWriter(t *testing.T) { l := runLogForwarding(t) - logToLogWriter(t, l, `{"level": "info","msg":"sync"}`) + msg := `"level":"info","msg":"sync"` + logToLogWriter(t, l, msg) // Do not use finish() here as we check done pipe ourselves. l.w.Close() @@ -58,12 +65,12 @@ func TestLogForwardingStopsAfterClosingTheWriter(t *testing.T) { t.Fatal("log forwarding did not stop after closing the pipe") } - check(t, l, "sync") + check(t, l, msg, msgErr) } func logToLogWriter(t *testing.T, l *log, message string) { t.Helper() - _, err := l.w.Write([]byte(message + "\n")) + _, err := l.w.Write([]byte("{" + message + "}\n")) if err != nil { t.Fatalf("failed to write %q to log writer: %v", message, err) } @@ -71,7 +78,7 @@ func logToLogWriter(t *testing.T, l *log, message string) { type log struct { w io.WriteCloser - file string + file *os.File done chan error } @@ -90,19 +97,16 @@ func runLogForwarding(t *testing.T) *log { if err != nil { t.Fatal(err) } - tempFile.Close() - logFile := tempFile.Name() - t.Cleanup(func() { os.Remove(logFile) }) - - logConfig := Config{LogLevel: logrus.InfoLevel, LogFormat: "json", LogFilePath: logFile} - loggingConfigured = false - if err := ConfigureLogging(logConfig); err != nil { - t.Fatal(err) - } + t.Cleanup(func() { + tempFile.Close() + os.Remove(tempFile.Name()) + }) + logrus.SetOutput(tempFile) + logrus.SetFormatter(&logrus.JSONFormatter{}) doneForwarding := ForwardLogs(logR) - return &log{w: logW, done: doneForwarding, file: logFile} + return &log{w: logW, done: doneForwarding, file: tempFile} } func finish(t *testing.T, l *log) { @@ -113,43 +117,40 @@ func finish(t *testing.T, l *log) { } } -func truncateLogFile(t *testing.T, logFile string) { +func truncateLogFile(t *testing.T, file *os.File) { t.Helper() - file, err := os.OpenFile(logFile, os.O_RDWR, 0o600) - if err != nil { - t.Fatalf("failed to open log file: %v", err) - return - } - defer file.Close() - err = file.Truncate(0) + err := file.Truncate(0) if err != nil { t.Fatalf("failed to truncate log file: %v", err) } } -// check checks that file contains txt -func check(t *testing.T, l *log, txt string) { +// check checks that the file contains txt and does not contain notxt. +func check(t *testing.T, l *log, txt, notxt string) { t.Helper() - contents, err := ioutil.ReadFile(l.file) + contents, err := ioutil.ReadFile(l.file.Name()) if err != nil { t.Fatal(err) } - if !bytes.Contains(contents, []byte(txt)) { - t.Fatalf("%q does not contain %q", string(contents), txt) + if txt != "" && !bytes.Contains(contents, []byte(txt)) { + t.Fatalf("%s does not contain %s", string(contents), txt) + } + if notxt != "" && bytes.Contains(contents, []byte(notxt)) { + t.Fatalf("%s does contain %s", string(contents), notxt) } } -// checkWait checks that file contains txt. If the file is empty, +// checkWait is like check, but if the file is empty, // it waits until it's not. -func checkWait(t *testing.T, l *log, txt string) { +func checkWait(t *testing.T, l *log, txt string, notxt string) { t.Helper() const ( delay = 100 * time.Millisecond iter = 3 ) for i := 0; ; i++ { - st, err := os.Stat(l.file) + st, err := l.file.Stat() if err != nil { t.Fatal(err) } @@ -157,10 +158,10 @@ func checkWait(t *testing.T, l *log, txt string) { break } if i == iter { - t.Fatalf("waited %s for file %s to be non-empty but it still is", iter*delay, l.file) + t.Fatalf("waited %s for file %s to be non-empty but it still is", iter*delay, l.file.Name()) } time.Sleep(delay) } - check(t, l, txt) + check(t, l, txt, notxt) } diff --git a/libcontainer/nsenter/nsenter_test.go b/libcontainer/nsenter/nsenter_test.go index 9627a61fe53..188a3fc5cd2 100644 --- a/libcontainer/nsenter/nsenter_test.go +++ b/libcontainer/nsenter/nsenter_test.go @@ -6,7 +6,6 @@ import ( "errors" "fmt" "io" - "io/ioutil" "os" "os/exec" "strings" @@ -17,21 +16,9 @@ import ( "golang.org/x/sys/unix" ) -type pid struct { - Pid int `json:"Pid"` -} - -type logentry struct { - Msg string `json:"msg"` - Level string `json:"level"` -} - func TestNsenterValidPaths(t *testing.T) { args := []string{"nsenter-exec"} - parent, child, err := newPipe() - if err != nil { - t.Fatalf("failed to create pipe %v", err) - } + parent, child := newPipe(t) namespaces := []string{ // join pid ns of the current process @@ -47,8 +34,9 @@ func TestNsenterValidPaths(t *testing.T) { } if err := cmd.Start(); err != nil { - t.Fatalf("nsenter failed to start %v", err) + t.Fatal("nsenter failed to start:", err) } + child.Close() // write cloneFlags r := nl.NewNetlinkRequest(int(libcontainer.InitMsg), 0) @@ -66,36 +54,18 @@ func TestNsenterValidPaths(t *testing.T) { initWaiter(t, parent) - decoder := json.NewDecoder(parent) - var pid *pid - if err := cmd.Wait(); err != nil { - t.Fatalf("nsenter exits with a non-zero exit status") - } - if err := decoder.Decode(&pid); err != nil { - dir, _ := ioutil.ReadDir(fmt.Sprintf("/proc/%d/ns", os.Getpid())) - for _, d := range dir { - t.Log(d.Name()) - } - t.Fatalf("%v", err) + t.Fatal("nsenter error:", err) } - p, err := os.FindProcess(pid.Pid) - if err != nil { - t.Fatalf("%v", err) - } - _, _ = p.Wait() + reapChild(t, parent) } func TestNsenterInvalidPaths(t *testing.T) { args := []string{"nsenter-exec"} - parent, child, err := newPipe() - if err != nil { - t.Fatalf("failed to create pipe %v", err) - } + parent, child := newPipe(t) namespaces := []string{ - // join pid ns of the current process fmt.Sprintf("pid:/proc/%d/ns/pid", -1), } cmd := &exec.Cmd{ @@ -106,8 +76,10 @@ func TestNsenterInvalidPaths(t *testing.T) { } if err := cmd.Start(); err != nil { - t.Fatal(err) + t.Fatal("nsenter failed to start:", err) } + child.Close() + // write cloneFlags r := nl.NewNetlinkRequest(int(libcontainer.InitMsg), 0) r.AddData(&libcontainer.Int32msg{ @@ -124,19 +96,15 @@ func TestNsenterInvalidPaths(t *testing.T) { initWaiter(t, parent) if err := cmd.Wait(); err == nil { - t.Fatalf("nsenter exits with a zero exit status") + t.Fatal("nsenter error:", err) } } func TestNsenterIncorrectPathType(t *testing.T) { args := []string{"nsenter-exec"} - parent, child, err := newPipe() - if err != nil { - t.Fatalf("failed to create pipe %v", err) - } + parent, child := newPipe(t) namespaces := []string{ - // join pid ns of the current process fmt.Sprintf("net:/proc/%d/ns/pid", os.Getpid()), } cmd := &exec.Cmd{ @@ -147,8 +115,10 @@ func TestNsenterIncorrectPathType(t *testing.T) { } if err := cmd.Start(); err != nil { - t.Fatal(err) + t.Fatal("nsenter failed to start:", err) } + child.Close() + // write cloneFlags r := nl.NewNetlinkRequest(int(libcontainer.InitMsg), 0) r.AddData(&libcontainer.Int32msg{ @@ -165,24 +135,14 @@ func TestNsenterIncorrectPathType(t *testing.T) { initWaiter(t, parent) if err := cmd.Wait(); err == nil { - t.Fatalf("nsenter exits with a zero exit status") + t.Fatal("nsenter error:", err) } } func TestNsenterChildLogging(t *testing.T) { args := []string{"nsenter-exec"} - parent, child, err := newPipe() - if err != nil { - t.Fatalf("failed to create exec pipe %v", err) - } - logread, logwrite, err := os.Pipe() - if err != nil { - t.Fatalf("failed to create log pipe %v", err) - } - defer func() { - _ = logwrite.Close() - _ = logread.Close() - }() + parent, child := newPipe(t) + logread, logwrite := newPipe(t) namespaces := []string{ // join pid ns of the current process @@ -198,8 +158,11 @@ func TestNsenterChildLogging(t *testing.T) { } if err := cmd.Start(); err != nil { - t.Fatalf("nsenter failed to start %v", err) + t.Fatal("nsenter failed to start:", err) } + child.Close() + logwrite.Close() + // write cloneFlags r := nl.NewNetlinkRequest(int(libcontainer.InitMsg), 0) r.AddData(&libcontainer.Int32msg{ @@ -216,20 +179,12 @@ func TestNsenterChildLogging(t *testing.T) { initWaiter(t, parent) - logsDecoder := json.NewDecoder(logread) - var logentry *logentry - - err = logsDecoder.Decode(&logentry) - if err != nil { - t.Fatalf("child log: %v", err) - } - if logentry.Level == "" || logentry.Msg == "" { - t.Fatalf("child log: empty log fileds: level=\"%s\" msg=\"%s\"", logentry.Level, logentry.Msg) - } - + getLogs(t, logread) if err := cmd.Wait(); err != nil { - t.Fatalf("nsenter exits with a non-zero exit status") + t.Fatal("nsenter error:", err) } + + reapChild(t, parent) } func init() { @@ -238,12 +193,19 @@ func init() { } } -func newPipe() (parent *os.File, child *os.File, err error) { +func newPipe(t *testing.T) (parent *os.File, child *os.File) { + t.Helper() fds, err := unix.Socketpair(unix.AF_LOCAL, unix.SOCK_STREAM|unix.SOCK_CLOEXEC, 0) if err != nil { - return nil, nil, err + t.Fatal("socketpair failed:", err) } - return os.NewFile(uintptr(fds[1]), "parent"), os.NewFile(uintptr(fds[0]), "child"), nil + parent = os.NewFile(uintptr(fds[1]), "parent") + child = os.NewFile(uintptr(fds[0]), "child") + t.Cleanup(func() { + parent.Close() + child.Close() + }) + return } // initWaiter reads back the initial \0 from runc init @@ -259,5 +221,47 @@ func initWaiter(t *testing.T, r io.Reader) { return } } - t.Fatalf("waiting for init preliminary setup: %v", err) + t.Fatal("waiting for init preliminary setup:", err) +} + +func reapChild(t *testing.T, parent *os.File) { + t.Helper() + decoder := json.NewDecoder(parent) + decoder.DisallowUnknownFields() + var pid struct { + Pid2 int `json:"stage2_pid"` + Pid1 int `json:"stage1_pid"` + } + if err := decoder.Decode(&pid); err != nil { + t.Fatal(err) + } + if pid.Pid1 == 0 || pid.Pid2 == 0 { + t.Fatal("got pids:", pid) + } + + // Reap children. + _, _ = unix.Wait4(pid.Pid1, nil, 0, nil) + _, _ = unix.Wait4(pid.Pid2, nil, 0, nil) +} + +func getLogs(t *testing.T, logread *os.File) { + logsDecoder := json.NewDecoder(logread) + logsDecoder.DisallowUnknownFields() + var logentry struct { + Level string `json:"level"` + Msg string `json:"msg"` + } + + for { + if err := logsDecoder.Decode(&logentry); err != nil { + if errors.Is(err, io.EOF) { + return + } + t.Fatal("init log decoding error:", err) + } + t.Logf("logentry: %+v", logentry) + if logentry.Level == "" || logentry.Msg == "" { + t.Fatalf("init log: empty log entry: %+v", logentry) + } + } } diff --git a/libcontainer/nsenter/nsexec.c b/libcontainer/nsenter/nsexec.c index ee7b75b1e5a..8d4d5dd1604 100644 --- a/libcontainer/nsenter/nsexec.c +++ b/libcontainer/nsenter/nsexec.c @@ -89,14 +89,21 @@ struct nlconfig_t { size_t gidmappath_len; }; -#define PANIC "panic" -#define FATAL "fatal" -#define ERROR "error" -#define WARNING "warning" -#define INFO "info" -#define DEBUG "debug" +/* + * Log levels are the same as in logrus. + */ +#define PANIC 0 +#define FATAL 1 +#define ERROR 2 +#define WARNING 3 +#define INFO 4 +#define DEBUG 5 +#define TRACE 6 + +static const char *level_str[] = { "panic", "fatal", "error", "warning", "info", "debug", "trace" }; static int logfd = -1; +static int loglevel = INFO; /* * List of netlink message types sent to us as part of bootstrapping the init. @@ -134,13 +141,13 @@ int setns(int fd, int nstype) } #endif -static void write_log(const char *level, const char *format, ...) +static void write_log(int level, const char *format, ...) { char *message = NULL, *stage = NULL, *json = NULL; va_list args; int ret; - if (logfd < 0 || level == NULL) + if (logfd < 0 || level > loglevel) goto out; va_start(args, format); @@ -158,7 +165,8 @@ static void write_log(const char *level, const char *format, ...) if (ret < 0) goto out; - ret = asprintf(&json, "{\"level\":\"%s\", \"msg\": \"%s[%d]: %s\"}\n", level, stage, getpid(), message); + ret = asprintf(&json, "{\"level\":\"%s\", \"msg\": \"%s[%d]: %s\"}\n", + level_str[level], stage, getpid(), message); if (ret < 0) { json = NULL; goto out; @@ -175,10 +183,14 @@ static void write_log(const char *level, const char *format, ...) /* XXX: This is ugly. */ static int syncfd = -1; -#define bail(fmt, ...) \ - do { \ - write_log(FATAL, fmt ": %m", ##__VA_ARGS__); \ - exit(1); \ +#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); \ } while(0) static int write_file(char *data, size_t data_len, char *pathfmt, ...) @@ -369,41 +381,55 @@ static int clone_parent(jmp_buf *env, int jmpval) } /* - * Gets the init pipe fd from the environment, which is used to read the - * bootstrap data and tell the parent what the new pid is after we finish - * setting up the environment. + * Returns an environment variable value as a non-negative integer, or -ENOENT + * if the variable was not found or has an empty value. + * + * If the value can not be converted to an integer, or the result is out of + * range, the function bails out. */ -static int initpipe(void) +static int getenv_int(const char *name) { - int pipenum; - char *initpipe, *endptr; + char *val, *endptr; + int ret; - initpipe = getenv("_LIBCONTAINER_INITPIPE"); - if (initpipe == NULL || *initpipe == '\0') - return -1; + val = getenv(name); + /* Treat empty value as unset variable. */ + if (val == NULL || *val == '\0') + return -ENOENT; - pipenum = strtol(initpipe, &endptr, 10); - if (*endptr != '\0') - bail("unable to parse _LIBCONTAINER_INITPIPE"); + ret = strtol(val, &endptr, 10); + if (val == endptr || *endptr != '\0') + bail("unable to parse %s=%s", name, val); + /* + * Sanity check: this must be a small non-negative number. + * Practically, we pass two fds (3 and 4) and a log level, + * for which the maximum is 6 (TRACE). + * */ + if (ret < 0 || ret > TRACE) + bail("bad value for %s=%s (%d)", name, val, ret); - return pipenum; + return ret; } +/* + * Sets up logging by getting log fd and log level from the environment, + * if available. + */ static void setup_logpipe(void) { - char *logpipe, *endptr; + int i; - logpipe = getenv("_LIBCONTAINER_LOGPIPE"); - if (logpipe == NULL || *logpipe == '\0') { + i = getenv_int("_LIBCONTAINER_LOGPIPE"); + if (i < 0) { + /* We are not runc init, or log pipe was not provided. */ return; } + logfd = i; - logfd = strtol(logpipe, &endptr, 10); - if (logpipe == endptr || *endptr != '\0') { - fprintf(stderr, "unable to parse _LIBCONTAINER_LOGPIPE, value: %s\n", logpipe); - /* It is too early to use bail */ - exit(1); - } + i = getenv_int("_LIBCONTAINER_LOGLEVEL"); + if (i < 0) + return; + loglevel = i; } /* Returns the clone(2) flag for a namespace, given the name of a namespace. */ @@ -614,12 +640,15 @@ void nsexec(void) setup_logpipe(); /* - * If we don't have an init pipe, just return to the go routine. - * We'll only get an init pipe for start or exec. + * Get the init pipe fd from the environment. The init pipe is used to + * read the bootstrap data and tell the parent what the new pids are + * after the setup is done. */ - pipenum = initpipe(); - if (pipenum == -1) + pipenum = getenv_int("_LIBCONTAINER_INITPIPE"); + if (pipenum < 0) { + /* We are not a runc init. Just return to go runtime. */ return; + } /* * We need to re-exec if we are not in a cloned binary. This is necessary diff --git a/main.go b/main.go index f141e79b443..ed00ce6ede1 100644 --- a/main.go +++ b/main.go @@ -1,13 +1,15 @@ package main import ( + "errors" "fmt" "io" "os" + "path/filepath" "runtime" + "strconv" "strings" - "github.com/opencontainers/runc/libcontainer/logs" "github.com/opencontainers/runc/libcontainer/seccomp" "github.com/opencontainers/runtime-spec/specs-go" @@ -149,7 +151,7 @@ func main() { return err } - return logs.ConfigureLogging(createLogConfig(context)) + return configLogrus(context) } // If the command returns an error, cli takes upon itself to print @@ -173,22 +175,43 @@ func (f *FatalWriter) Write(p []byte) (n int, err error) { return len(p), nil } -func createLogConfig(context *cli.Context) logs.Config { - logFilePath := context.GlobalString("log") - logPipeFd := 0 - if logFilePath == "" { - logPipeFd = 2 +func configLogrus(context *cli.Context) error { + if context.GlobalBool("debug") { + logrus.SetLevel(logrus.DebugLevel) + logrus.SetReportCaller(true) + // Shorten function and file names reported by the logger, by + // trimming common "github.com/opencontainers/runc" prefix. + // This is only done for text formatter. + _, file, _, _ := runtime.Caller(0) + prefix := filepath.Dir(file) + "/" + logrus.SetFormatter(&logrus.TextFormatter{ + CallerPrettyfier: func(f *runtime.Frame) (string, string) { + function := strings.TrimPrefix(f.Function, prefix) + "()" + fileLine := strings.TrimPrefix(f.File, prefix) + ":" + strconv.Itoa(f.Line) + return function, fileLine + }, + }) } - config := logs.Config{ - LogPipeFd: logPipeFd, - LogLevel: logrus.InfoLevel, - LogFilePath: logFilePath, - LogFormat: context.GlobalString("log-format"), - LogCaller: context.GlobalBool("debug"), + + if file := context.GlobalString("log"); file != "" { + f, err := os.OpenFile(file, os.O_CREATE|os.O_WRONLY|os.O_APPEND|os.O_SYNC, 0o644) + if err != nil { + return err + } + logrus.SetOutput(f) } - if context.GlobalBool("debug") { - config.LogLevel = logrus.DebugLevel + + fmt := context.GlobalString("log-format") + switch fmt { + case "": + // do nothing + case "text": + // do nothing + case "json": + logrus.SetFormatter(new(logrus.JSONFormatter)) + default: + return errors.New("invalid log-format: " + fmt) } - return config + return nil } diff --git a/utils_linux.go b/utils_linux.go index 8b8d9e57eaf..d21b194fa33 100644 --- a/utils_linux.go +++ b/utils_linux.go @@ -99,7 +99,7 @@ func getDefaultImagePath(context *cli.Context) string { // newProcess returns a new libcontainer Process with the arguments from the // spec and stdio from the current process. -func newProcess(p specs.Process, init bool, logLevel string) (*libcontainer.Process, error) { +func newProcess(p specs.Process) (*libcontainer.Process, error) { lp := &libcontainer.Process{ Args: p.Args, Env: p.Env, @@ -109,8 +109,6 @@ func newProcess(p specs.Process, init bool, logLevel string) (*libcontainer.Proc Label: p.SelinuxLabel, NoNewPrivileges: &p.NoNewPrivileges, AppArmorProfile: p.ApparmorProfile, - Init: init, - LogLevel: logLevel, } if p.ConsoleSize != nil { @@ -259,7 +257,6 @@ type runner struct { action CtAct notifySocket *notifySocket criuOpts *libcontainer.CriuOpts - logLevel string } func (r *runner) run(config *specs.Process) (int, error) { @@ -272,10 +269,13 @@ func (r *runner) run(config *specs.Process) (int, error) { if err = r.checkTerminal(config); err != nil { return -1, err } - process, err := newProcess(*config, r.init, r.logLevel) + process, err := newProcess(*config) if err != nil { return -1, err } + process.LogLevel = strconv.Itoa(int(logrus.GetLevel())) + // Populate the fields that come from runner. + process.Init = r.init if len(r.listenFDs) > 0 { process.Env = append(process.Env, "LISTEN_FDS="+strconv.Itoa(len(r.listenFDs)), "LISTEN_PID=1") process.ExtraFiles = append(process.ExtraFiles, r.listenFDs...) @@ -432,11 +432,6 @@ func startContainer(context *cli.Context, spec *specs.Spec, action CtAct, criuOp listenFDs = activation.Files(false) } - logLevel := "info" - if context.GlobalBool("debug") { - logLevel = "debug" - } - r := &runner{ enableSubreaper: !context.Bool("no-subreaper"), shouldDestroy: true, @@ -450,7 +445,6 @@ func startContainer(context *cli.Context, spec *specs.Spec, action CtAct, criuOp action: action, criuOpts: criuOpts, init: true, - logLevel: logLevel, } return r.run(spec.Process) }