From bc3c662b156174b3c0130da532bf9b674e35c5d8 Mon Sep 17 00:00:00 2001 From: Tom Godkin Date: Tue, 19 Mar 2019 11:19:38 +0000 Subject: [PATCH] Add dlogf facility for nsexec logging Co-authored-by: Danail Branekov Co-authored-by: Georgi Sabev Co-authored-by: Giuseppe Capizzi Signed-off-by: Tom Godkin --- exec.go | 5 ++ libcontainer/container_linux.go | 15 ++++++ libcontainer/nsenter/nsexec.c | 88 ++++++++++++++++++++++++++------- run.go | 4 ++ utils_linux.go | 12 +++++ 5 files changed, 107 insertions(+), 17 deletions(-) diff --git a/exec.go b/exec.go index 62ab4662548..4d03394b00d 100644 --- a/exec.go +++ b/exec.go @@ -93,6 +93,10 @@ following will output a list of processes running in the container: Name: "preserve-fds", Usage: "Pass N additional file descriptors to the container (stdio + $LISTEN_FDS + N in total)", }, + cli.StringFlag{ + Name: "exec-log", + Usage: "exec log file", + }, }, Action: func(context *cli.Context) error { if err := checkArgs(context, 1, minArgs); err != nil { @@ -143,6 +147,7 @@ func execProcess(context *cli.Context) (int, error) { consoleSocket: context.String("console-socket"), detach: detach, pidFile: context.String("pid-file"), + execLog: context.String("exec-log"), action: CT_ACT_RUN, init: false, preserveFDs: context.Int("preserve-fds"), diff --git a/libcontainer/container_linux.go b/libcontainer/container_linux.go index 7e58e5e0082..cc75726ae93 100644 --- a/libcontainer/container_linux.go +++ b/libcontainer/container_linux.go @@ -479,11 +479,17 @@ func (c *linuxContainer) commandTemplate(p *Process, childPipe *os.File) (*exec. fmt.Sprintf("_LIBCONTAINER_CONSOLE=%d", stdioFdCount+len(cmd.ExtraFiles)-1), ) } + cmd.ExtraFiles = append(cmd.ExtraFiles, childPipe) cmd.Env = append(cmd.Env, fmt.Sprintf("_LIBCONTAINER_INITPIPE=%d", stdioFdCount+len(cmd.ExtraFiles)-1), fmt.Sprintf("_LIBCONTAINER_STATEDIR=%s", c.root), ) + + if execLogEnv := getExecLogEnv(p.Env); execLogEnv != "" { + cmd.Env = append(cmd.Env, execLogEnv) + } + // NOTE: when running a container with no PID namespace and the parent process spawning the container is // PID1 the pdeathsig is being delivered to the container's init process by the kernel for some reason // even with the parent still running. @@ -522,6 +528,15 @@ func (c *linuxContainer) newInitProcess(p *Process, cmd *exec.Cmd, parentPipe, c return init, nil } +func getExecLogEnv(env []string) string { + for _, entry := range env { + if strings.HasPrefix(entry, "_LIBCONTAINER_EXECLOG=") { + return entry + } + } + return "" +} + func (c *linuxContainer) newSetnsProcess(p *Process, cmd *exec.Cmd, parentPipe, childPipe *os.File) (*setnsProcess, error) { cmd.Env = append(cmd.Env, "_LIBCONTAINER_INITTYPE="+string(initSetns)) state, err := c.currentState() diff --git a/libcontainer/nsenter/nsexec.c b/libcontainer/nsenter/nsexec.c index 7750af35ea9..3afeb705e59 100644 --- a/libcontainer/nsenter/nsexec.c +++ b/libcontainer/nsenter/nsexec.c @@ -14,11 +14,13 @@ #include #include #include +#include #include #include #include #include +#include #include #include @@ -110,6 +112,9 @@ struct nlconfig_t { #define UIDMAPPATH_ATTR 27288 #define GIDMAPPATH_ATTR 27289 +#define MAX_TIMESTAMP_LEN 32 +#define MAX_LOG_MESSAGE_LEN 256 + /* * Use the raw syscall for versions of glibc which don't include a function for * it, namely (glibc 2.12). @@ -331,25 +336,21 @@ static int clone_parent(jmp_buf *env, int jmpval) return clone(child_func, ca.stack_ptr, CLONE_PARENT | SIGCHLD, &ca); } -/* - * 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. - */ -static int initpipe(void) +/* Get the fd from given envrionment variable. */ +static int getfd(char *envfd) { - int pipenum; - char *initpipe, *endptr; + int fdnum; + char *fd, *endptr; - initpipe = getenv("_LIBCONTAINER_INITPIPE"); - if (initpipe == NULL || *initpipe == '\0') + fd = getenv(envfd); + if (fd == NULL || *fd == '\0') return -1; - pipenum = strtol(initpipe, &endptr, 10); + fdnum = strtol(fd, &endptr, 10); if (*endptr != '\0') - bail("unable to parse _LIBCONTAINER_INITPIPE"); + bail("unable to parse %s", envfd); - return pipenum; + return fdnum; } /* Returns the clone(2) flag for a namespace, given the name of a namespace. */ @@ -537,21 +538,74 @@ void join_namespaces(char *nslist) /* Defined in cloned_binary.c. */ extern int ensure_cloned_binary(void); +static int nowformatted(char *buf) +{ + struct timeb now; + + if (ftime(&now) < 0) return 1; + + if (strftime(buf, MAX_TIMESTAMP_LEN, "%Y-%m-%d-%H:%M:%S", localtime(&now.time)) == 0) return 1; + if (sprintf(&buf[strlen(buf)], ":%03u", now.millitm) == 0) return 1; + + return 0; +} + +/* Write a timestamp prefixed message into fd */ +static void dlog(int fd, const char *message) +{ + /* Logging is best effort, a failure to log shouldn't impact other + * operations so we just abort the logging attempt if we fail for any + * reason. */ + + char timestamp[MAX_TIMESTAMP_LEN], logline[MAX_LOG_MESSAGE_LEN]; + + /* There are two reasons for this to fail: either the attempt to open + * the log fd failed or the log fd wasn't set. Either way the outcome + * is the same - we won't or can't log. */ + if (fd < 0) return; + + if (nowformatted(timestamp) != 0) return; + if (snprintf(logline, MAX_LOG_MESSAGE_LEN, "[%s] %s\n", timestamp, message) == 0) return; + (void) write(fd, logline, strlen(logline)); +} + +static void dlogf(int fd, const char *fmt, ...) +{ + va_list argp; + char message[MAX_LOG_MESSAGE_LEN]; + + if (fd < 0) return; + + va_start(argp, fmt); + vsnprintf(message, MAX_LOG_MESSAGE_LEN, fmt, argp); + va_end(argp); + + dlog(fd, message); +} + void nsexec(void) { - int pipenum; + int pipenum, logfd; jmp_buf env; int sync_child_pipe[2], sync_grandchild_pipe[2]; struct nlconfig_t config = { 0 }; /* - * 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. + * 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. 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. */ - pipenum = initpipe(); + pipenum = getfd("_LIBCONTAINER_INITPIPE"); if (pipenum == -1) return; + logfd = getfd("_LIBCONTAINER_EXECLOG"); + + /* TODO: this is a showcase, remove it */ + dlogf(logfd, "Hi from nsexec! Pid is: %ld", getpid()); + /* * We need to re-exec if we are not in a cloned binary. This is necessary * to ensure that containers won't be able to access the host binary diff --git a/run.go b/run.go index f8d6317844d..694a6ce211f 100644 --- a/run.go +++ b/run.go @@ -61,6 +61,10 @@ command(s) that get executed on start, edit the args parameter of the spec. See Name: "preserve-fds", Usage: "Pass N additional file descriptors to the container (stdio + $LISTEN_FDS + N in total)", }, + cli.StringFlag{ + Name: "exec-log", + Usage: "exec log file", + }, }, Action: func(context *cli.Context) error { if err := checkArgs(context, 1, exactArgs); err != nil { diff --git a/utils_linux.go b/utils_linux.go index ce50db14537..60a3f85c4ed 100644 --- a/utils_linux.go +++ b/utils_linux.go @@ -258,6 +258,7 @@ type runner struct { listenFDs []*os.File preserveFDs int pidFile string + execLog string consoleSocket string container libcontainer.Container action CtAct @@ -279,6 +280,16 @@ func (r *runner) run(config *specs.Process) (int, error) { process.Env = append(process.Env, fmt.Sprintf("LISTEN_FDS=%d", len(r.listenFDs)), "LISTEN_PID=1") process.ExtraFiles = append(process.ExtraFiles, r.listenFDs...) } + if r.execLog != "" { + execLogFile, err := os.OpenFile(r.execLog, os.O_CREATE|os.O_WRONLY, 0755) + if err != nil { + return -1, err + } + defer execLogFile.Close() + + process.Env = append(process.Env, fmt.Sprintf("_LIBCONTAINER_EXECLOG=%d", 3+len(r.listenFDs))) + process.ExtraFiles = append(process.ExtraFiles, execLogFile) + } baseFd := 3 + len(process.ExtraFiles) for i := baseFd; i < baseFd+r.preserveFDs; i++ { _, err := os.Stat(fmt.Sprintf("/proc/self/fd/%d", i)) @@ -439,6 +450,7 @@ func startContainer(context *cli.Context, spec *specs.Spec, action CtAct, criuOp action: action, criuOpts: criuOpts, init: true, + execLog: context.String("exec-log"), } return r.run(spec.Process) }