jasder
/
runc
1
0
Fork 0
Code Issues Pull Requests Releases Wiki Activity

Support for logging from children processes 

Add support for children processes logging (including nsexec).
A pipe is used to send logs from children to parent in JSON.
The JSON format used is the same used by logrus JSON formatted,
i.e. children process can use standard logrus APIs.

Signed-off-by: Marco Vedovati <mvedovati@suse.com>
This commit is contained in:
Marco Vedovati 2018-08-03 19:11:20 +02:00 committed by Danail Branekov
parent 029124da7a
commit 9a599f62fb
9 changed files with 257 additions and 6 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

15
init.go
View File

@ -3,9 +3,11 @@ package main
import (
"os"
"runtime"
"strconv"
"github.com/opencontainers/runc/libcontainer"
_ "github.com/opencontainers/runc/libcontainer/nsenter"
"github.com/sirupsen/logrus"
"github.com/urfave/cli"
)
@ -13,6 +15,19 @@ func init() {
if len(os.Args) > 1 && os.Args[1] == "init" {
runtime.GOMAXPROCS(1)
runtime.LockOSThread()
// in child process, we need to retrieve the log pipe
envLogPipe := os.Getenv("_LIBCONTAINER_LOGPIPE")
logPipeFd, err := strconv.Atoi(envLogPipe)
if err != nil {
return
}
logPipe := os.NewFile(uintptr(logPipeFd), "logpipe")
logrus.SetOutput(logPipe)
logrus.SetFormatter(&logrus.JSONFormatter{})
logrus.SetLevel(logrus.DebugLevel)
logrus.Debug("child process in init()")
}
}

28
libcontainer/container_linux.go
View File

@ -337,6 +337,7 @@ func (c *linuxContainer) start(process *Process) error {
if err != nil {
return newSystemErrorWithCause(err, "creating new parent process")
}
parent.getChildLogs()
if err := parent.start(); err != nil {
// terminate the process to ensure that it properly is reaped.
if err := ignoreTerminateErrors(parent.terminate()); err != nil {
@ -442,12 +443,19 @@ func (c *linuxContainer) newParentProcess(p *Process) (parentProcess, error) {
if err != nil {
return nil, newSystemErrorWithCause(err, "creating new init pipe")
}
cmd, err := c.commandTemplate(p, childPipe)
r, w, err := os.Pipe()
if err != nil {
return nil, fmt.Errorf("Unable to create the log pipe: %s", err)
}
logPipe := pipePair{r, w}
cmd, err := c.commandTemplate(p, childPipe, logPipe.w)
if err != nil {
return nil, newSystemErrorWithCause(err, "creating new command template")
}
if !p.Init {
return c.newSetnsProcess(p, cmd, parentPipe, childPipe)
return c.newSetnsProcess(p, cmd, parentPipe, childPipe, &logPipe)
}
// We only set up fifoFd if we're not doing a `runc exec`. The historic
@ -458,10 +466,10 @@ func (c *linuxContainer) newParentProcess(p *Process) (parentProcess, error) {
if err := c.includeExecFifo(cmd); err != nil {
return nil, newSystemErrorWithCause(err, "including execfifo in cmd.Exec setup")
}
return c.newInitProcess(p, cmd, parentPipe, childPipe)
return c.newInitProcess(p, cmd, parentPipe, childPipe, &logPipe)
}
func (c *linuxContainer) commandTemplate(p *Process, childPipe *os.File) (*exec.Cmd, error) {
func (c *linuxContainer) commandTemplate(p *Process, childPipe *os.File, logPipe *os.File) (*exec.Cmd, error) {
cmd := exec.Command(c.initPath, c.initArgs[1:]...)
cmd.Args[0] = c.initArgs[0]
cmd.Stdin = p.Stdin
@ -484,6 +492,12 @@ func (c *linuxContainer) commandTemplate(p *Process, childPipe *os.File) (*exec.
fmt.Sprintf("_LIBCONTAINER_INITPIPE=%d", stdioFdCount+len(cmd.ExtraFiles)-1),
fmt.Sprintf("_LIBCONTAINER_STATEDIR=%s", c.root),
)
cmd.ExtraFiles = append(cmd.ExtraFiles, logPipe)
cmd.Env = append(cmd.Env,
fmt.Sprintf("_LIBCONTAINER_LOGPIPE=%d", stdioFdCount+len(cmd.ExtraFiles)-1),
)
// 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.
@ -493,7 +507,7 @@ func (c *linuxContainer) commandTemplate(p *Process, childPipe *os.File) (*exec.
return cmd, nil
}
func (c *linuxContainer) newInitProcess(p *Process, cmd *exec.Cmd, parentPipe, childPipe *os.File) (*initProcess, error) {
func (c *linuxContainer) newInitProcess(p *Process, cmd *exec.Cmd, parentPipe, childPipe *os.File, logPipe *pipePair) (*initProcess, error) {
cmd.Env = append(cmd.Env, "_LIBCONTAINER_INITTYPE="+string(initStandard))
nsMaps := make(map[configs.NamespaceType]string)
for _, ns := range c.config.Namespaces {
@ -510,6 +524,7 @@ func (c *linuxContainer) newInitProcess(p *Process, cmd *exec.Cmd, parentPipe, c
cmd: cmd,
childPipe: childPipe,
parentPipe: parentPipe,
logPipe: *logPipe,
manager: c.cgroupManager,
intelRdtManager: c.intelRdtManager,
config: c.newInitConfig(p),
@ -522,7 +537,7 @@ func (c *linuxContainer) newInitProcess(p *Process, cmd *exec.Cmd, parentPipe, c
return init, nil
}
func (c *linuxContainer) newSetnsProcess(p *Process, cmd *exec.Cmd, parentPipe, childPipe *os.File) (*setnsProcess, error) {
func (c *linuxContainer) newSetnsProcess(p *Process, cmd *exec.Cmd, parentPipe, childPipe *os.File, logPipe *pipePair) (*setnsProcess, error) {
cmd.Env = append(cmd.Env, "_LIBCONTAINER_INITTYPE="+string(initSetns))
state, err := c.currentState()
if err != nil {
@ -541,6 +556,7 @@ func (c *linuxContainer) newSetnsProcess(p *Process, cmd *exec.Cmd, parentPipe,
intelRdtPath: state.IntelRdtPath,
childPipe: childPipe,
parentPipe: parentPipe,
logPipe: *logPipe,
config: c.newInitConfig(p),
process: p,
bootstrapData: data,

70
libcontainer/logs.go Normal file
View File

@ -0,0 +1,70 @@
package libcontainer
import (
"encoding/json"
"fmt"
"io"
"os"
"github.com/sirupsen/logrus"
)
func forwardLogs(p *os.File) {
defer p.Close()
type jsonLog struct {
Level string `json:"level"`
Msg string `json:"msg"`
}
dec := json.NewDecoder(p)
for {
var jl jsonLog
type logFuncTable map[logrus.Level]func(args ...interface{})
logMapping := logFuncTable{
logrus.PanicLevel: logrus.Panic,
logrus.FatalLevel: logrus.Fatal,
logrus.ErrorLevel: logrus.Error,
logrus.WarnLevel: logrus.Warn,
logrus.InfoLevel: logrus.Info,
logrus.DebugLevel: logrus.Debug,
}
err := dec.Decode(&jl)
if err != nil {
if err == io.EOF {
logrus.Debug("child pipe closed")
return
}
logrus.Errorf("json logs decoding error: %+v", err)
return
}
lvl, err := logrus.ParseLevel(jl.Level)
if err != nil {
fmt.Printf("parsing error\n")
}
if logMapping[lvl] != nil {
logMapping[lvl](jl.Msg)
}
}
}
func rawLogs(p *os.File) {
defer p.Close()
data := make([]byte, 128)
for {
_, err := p.Read(data)
if err != nil {
if err == io.EOF {
logrus.Debug("child pipe closed")
return
}
return
}
fmt.Printf("Read data: %s\n", string(data))
}
}

59
libcontainer/nsenter/nsenter_test.go
View File

@ -21,6 +21,11 @@ type pid struct {
Pid int `json:"Pid"`
}
type logentry struct {
Msg string
Level string
}
func TestNsenterValidPaths(t *testing.T) {
args := []string{"nsenter-exec"}
parent, child, err := newPipe()
@ -159,6 +164,60 @@ func TestNsenterIncorrectPathType(t *testing.T) {
}
}
func TestNsenterChildLogging(t *testing.T) {
args := []string{"nsenter-exec"}
parent, child, err := newPipe()
logread, logwrite, err := os.Pipe()
if err != nil {
t.Fatalf("failed to create pipe %v", err)
}
namespaces := []string{
// join pid ns of the current process
fmt.Sprintf("pid:/proc/%d/ns/pid", os.Getpid()),
}
cmd := &exec.Cmd{
Path: os.Args[0],
Args: args,
ExtraFiles: []*os.File{child, logwrite},
Env: []string{"_LIBCONTAINER_INITPIPE=3", "_LIBCONTAINER_LOGPIPE=4"},
Stdout: os.Stdout,
Stderr: os.Stderr,
}
if err := cmd.Start(); err != nil {
t.Fatalf("nsenter failed to start %v", err)
}
// write cloneFlags
r := nl.NewNetlinkRequest(int(libcontainer.InitMsg), 0)
r.AddData(&libcontainer.Int32msg{
Type: libcontainer.CloneFlagsAttr,
Value: uint32(unix.CLONE_NEWNET),
})
r.AddData(&libcontainer.Bytemsg{
Type: libcontainer.NsPathsAttr,
Value: []byte(strings.Join(namespaces, ",")),
})
if _, err := io.Copy(parent, bytes.NewReader(r.Serialize())); err != nil {
t.Fatal(err)
}
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)
}
if err := cmd.Wait(); err != nil {
t.Fatalf("nsenter exits with a non-zero exit status")
}
}
func init() {
if strings.HasPrefix(os.Args[0], "nsenter-") {
os.Exit(0)

53
libcontainer/nsenter/nsexec.c
View File

@ -95,6 +95,17 @@ struct nlconfig_t {
size_t gidmappath_len;
};
typedef enum {
PANIC = 0,
FATAL,
ERROR,
WARNING,
INFO,
DEBUG,
} loglevel_t;
int logfd;
/*
* List of netlink message types sent to us as part of bootstrapping the init.
* These constants are defined in libcontainer/message_linux.go.
@ -352,6 +363,22 @@ static int initpipe(void)
return pipenum;
}
static int logpipe(void)
{
int pipenum;
char *logpipe, *endptr;
logpipe = getenv("_LIBCONTAINER_LOGPIPE");
if (logpipe == NULL || *logpipe == '\0')
return -1;
pipenum = strtol(logpipe, &endptr, 10);
if (*endptr != '\0')
bail("unable to parse _LIBCONTAINER_LOGPIPE");
return pipenum;
}
/* Returns the clone(2) flag for a namespace, given the name of a namespace. */
static int nsflag(char *name)
{
@ -537,6 +564,27 @@ void join_namespaces(char *nslist)
/* Defined in cloned_binary.c. */
extern int ensure_cloned_binary(void);
void write_log(loglevel_t level, const char *format, ...)
{
static const char *strlevel[] = {"panic", "fatal", "error", "warning", "info", "debug"};
static char jsonbuffer[1024];
int len;
va_list args;
if (logfd < 0 || level >= sizeof(strlevel) / sizeof(strlevel[0])) {
return;
}
len = snprintf(jsonbuffer, sizeof(jsonbuffer),
"{\"level\":\"%s\", \"msg\": \"", strlevel[level]);
va_start(args, format);
len += vsnprintf(&jsonbuffer[len], sizeof(jsonbuffer) - len, format, args);
va_end(args);
len += snprintf(&jsonbuffer[len], sizeof(jsonbuffer) - len, "\"}");
write(logfd, jsonbuffer, len);
}
void nsexec(void)
{
int pipenum;
@ -560,6 +608,11 @@ void nsexec(void)
if (ensure_cloned_binary() < 0)
bail("could not ensure we are a cloned binary");
/* Get the log pipe */
logfd = logpipe();
write_log(DEBUG, "%s started", __FUNCTION__);
/* Parse all of the netlink configuration. */
nl_parse(pipenum, &config);

21
libcontainer/process_linux.go
View File

@ -47,12 +47,20 @@ type parentProcess interface {
externalDescriptors() []string
setExternalDescriptors(fds []string)
getChildLogs()
}
type pipePair struct {
r *os.File
w *os.File
}
type setnsProcess struct {
cmd *exec.Cmd
parentPipe *os.File
childPipe *os.File
logPipe pipePair
cgroupPaths map[string]string
rootlessCgroups bool
intelRdtPath string
@ -78,7 +86,9 @@ func (p *setnsProcess) signal(sig os.Signal) error {
func (p *setnsProcess) start() (err error) {
defer p.parentPipe.Close()
err = p.cmd.Start()
// close the write-side of the pipes (controlled by child)
p.childPipe.Close()
p.logPipe.w.Close()
if err != nil {
return newSystemErrorWithCause(err, "starting setns process")
}
@ -205,10 +215,15 @@ func (p *setnsProcess) setExternalDescriptors(newFds []string) {
p.fds = newFds
}
func (p *setnsProcess) getChildLogs() {
go forwardLogs(p.logPipe.r)
}
type initProcess struct {
cmd *exec.Cmd
parentPipe *os.File
childPipe *os.File
logPipe pipePair
config *initConfig
manager cgroups.Manager
intelRdtManager intelrdt.Manager
@ -269,7 +284,9 @@ func (p *initProcess) start() error {
defer p.parentPipe.Close()
err := p.cmd.Start()
p.process.ops = p
// close the write-side of the pipes (controlled by child)
p.childPipe.Close()
p.logPipe.w.Close()
if err != nil {
p.process.ops = nil
return newSystemErrorWithCause(err, "starting init process command")
@ -508,6 +525,10 @@ func (p *initProcess) setExternalDescriptors(newFds []string) {
p.fds = newFds
}
func (p *initProcess) getChildLogs() {
go forwardLogs(p.logPipe.r)
}
func getPipeFds(pid int) ([]string, error) {
fds := make([]string, 3)

6
libcontainer/restored_process.go
View File

@ -76,6 +76,9 @@ func (p *restoredProcess) setExternalDescriptors(newFds []string) {
p.fds = newFds
}
func (p *restoredProcess) getChildLogs() {
}
// nonChildProcess represents a process where the calling process is not
// the parent process. This process is created when a factory loads a container from
// a persisted state.
@ -120,3 +123,6 @@ func (p *nonChildProcess) externalDescriptors() []string {
func (p *nonChildProcess) setExternalDescriptors(newFds []string) {
p.fds = newFds
}
func (p *nonChildProcess) getChildLogs() {
}

5
libcontainer/standard_init_linux.go
View File

@ -16,6 +16,7 @@ import (
"github.com/opencontainers/runc/libcontainer/system"
"github.com/opencontainers/selinux/go-selinux/label"
"github.com/pkg/errors"
"github.com/sirupsen/logrus"
"golang.org/x/sys/unix"
)
@ -207,6 +208,10 @@ func (l *linuxStandardInit) Init() error {
return newSystemErrorWithCause(err, "init seccomp")
}
}
logPipe, _ := (logrus.StandardLogger().Out).(*(os.File))
logPipe.Close()
if err := syscall.Exec(name, l.config.Args[0:], os.Environ()); err != nil {
return newSystemErrorWithCause(err, "exec user process")
}

6
main.go
View File

@ -133,6 +133,12 @@ func main() {
updateCommand,
}
app.Before = func(context *cli.Context) error {
// do nothing if logrus was already initialized in init.go
if logrus.StandardLogger().Out != logrus.New().Out {
return nil
}
if context.GlobalBool("debug") {
logrus.SetLevel(logrus.DebugLevel)
}