From f7eec3dd13aedc01f89ce9b0c1f7e6c65d2c9e38 Mon Sep 17 00:00:00 2001 From: Michael Crosby Date: Thu, 13 Mar 2014 10:35:16 -0700 Subject: [PATCH 1/2] Add initial logging to libcontainer Docker-DCO-1.1-Signed-off-by: Michael Crosby (github: crosbymichael) --- libcontainer/nsinit/command.go | 3 +- libcontainer/nsinit/exec.go | 16 ++++++++-- libcontainer/nsinit/execin.go | 3 ++ libcontainer/nsinit/init.go | 11 +++++-- libcontainer/nsinit/nsinit.go | 5 +++- libcontainer/nsinit/nsinit/main.go | 48 ++++++++++++++++++++++-------- 6 files changed, 68 insertions(+), 18 deletions(-) diff --git a/libcontainer/nsinit/command.go b/libcontainer/nsinit/command.go index 5546065..1d7c591 100644 --- a/libcontainer/nsinit/command.go +++ b/libcontainer/nsinit/command.go @@ -1,6 +1,7 @@ package nsinit import ( + "fmt" "github.com/dotcloud/docker/pkg/libcontainer" "github.com/dotcloud/docker/pkg/system" "os" @@ -25,7 +26,7 @@ func (c *DefaultCommandFactory) Create(container *libcontainer.Container, consol // get our binary name from arg0 so we can always reexec ourself command := exec.Command(os.Args[0], append([]string{ "-console", console, - "-pipe", "3", + "-pipe", fmt.Sprint(pipe.Fd()), "-root", c.Root, "init"}, args...)...) diff --git a/libcontainer/nsinit/exec.go b/libcontainer/nsinit/exec.go index 4963f12..074492a 100644 --- a/libcontainer/nsinit/exec.go +++ b/libcontainer/nsinit/exec.go @@ -28,6 +28,7 @@ func (ns *linuxNs) Exec(container *libcontainer.Container, term Terminal, args [ } if container.Tty { + ns.logger.Println("creating master and console") master, console, err = system.CreateMasterAndConsole() if err != nil { return -1, err @@ -36,31 +37,40 @@ func (ns *linuxNs) Exec(container *libcontainer.Container, term Terminal, args [ } command := ns.commandFactory.Create(container, console, syncPipe.child, args) + ns.logger.Println("attach terminal to command") if err := term.Attach(command); err != nil { return -1, err } defer term.Close() + ns.logger.Println("starting command") if err := command.Start(); err != nil { return -1, err } + ns.logger.Printf("writting pid %d to file\n", command.Process.Pid) if err := ns.stateWriter.WritePid(command.Process.Pid); err != nil { command.Process.Kill() return -1, err } - defer ns.stateWriter.DeletePid() + defer func() { + ns.logger.Println("removing pid file") + ns.stateWriter.DeletePid() + }() // Do this before syncing with child so that no children // can escape the cgroup + ns.logger.Println("setting cgroups") if err := ns.SetupCgroups(container, command.Process.Pid); err != nil { command.Process.Kill() return -1, err } + ns.logger.Println("setting up network") if err := ns.InitializeNetworking(container, command.Process.Pid, syncPipe); err != nil { command.Process.Kill() return -1, err } + ns.logger.Println("closing sync pipe with child") // Sync with child syncPipe.Close() @@ -69,7 +79,9 @@ func (ns *linuxNs) Exec(container *libcontainer.Container, term Terminal, args [ return -1, err } } - return command.ProcessState.Sys().(syscall.WaitStatus).ExitStatus(), nil + status := command.ProcessState.Sys().(syscall.WaitStatus).ExitStatus() + ns.logger.Printf("process exited with status %d\n", status) + return status, err } func (ns *linuxNs) SetupCgroups(container *libcontainer.Container, nspid int) error { diff --git a/libcontainer/nsinit/execin.go b/libcontainer/nsinit/execin.go index 488fe0e..39df476 100644 --- a/libcontainer/nsinit/execin.go +++ b/libcontainer/nsinit/execin.go @@ -14,6 +14,7 @@ import ( // ExecIn uses an existing pid and joins the pid's namespaces with the new command. func (ns *linuxNs) ExecIn(container *libcontainer.Container, nspid int, args []string) (int, error) { + ns.logger.Println("unshare namespaces") for _, ns := range container.Namespaces { if err := system.Unshare(ns.Value); err != nil { return -1, err @@ -33,6 +34,7 @@ func (ns *linuxNs) ExecIn(container *libcontainer.Container, nspid int, args []s // foreach namespace fd, use setns to join an existing container's namespaces for _, fd := range fds { if fd > 0 { + ns.logger.Printf("setns on %d\n", fd) if err := system.Setns(fd, 0); err != nil { closeFds() return -1, fmt.Errorf("setns %s", err) @@ -44,6 +46,7 @@ func (ns *linuxNs) ExecIn(container *libcontainer.Container, nspid int, args []s // if the container has a new pid and mount namespace we need to // remount proc and sys to pick up the changes if container.Namespaces.Contains("NEWNS") && container.Namespaces.Contains("NEWPID") { + ns.logger.Println("forking to remount /proc and /sys") pid, err := system.Fork() if err != nil { return -1, err diff --git a/libcontainer/nsinit/init.go b/libcontainer/nsinit/init.go index 5d47b95..6b05905 100644 --- a/libcontainer/nsinit/init.go +++ b/libcontainer/nsinit/init.go @@ -29,9 +29,11 @@ func (ns *linuxNs) Init(container *libcontainer.Container, uncleanRootfs, consol syncPipe.Close() return err } + ns.logger.Println("received context from parent") syncPipe.Close() if console != "" { + ns.logger.Printf("setting up %s as console\n", console) slave, err := system.OpenTerminal(console, syscall.O_RDWR) if err != nil { return fmt.Errorf("open terminal %s", err) @@ -51,6 +53,7 @@ func (ns *linuxNs) Init(container *libcontainer.Container, uncleanRootfs, consol if err := system.ParentDeathSignal(); err != nil { return fmt.Errorf("parent death signal %s", err) } + ns.logger.Println("setup mount namespace") if err := setupNewMountNamespace(rootfs, container.Mounts, console, container.ReadonlyFs, container.NoPivotRoot); err != nil { return fmt.Errorf("setup mount namespace %s", err) } @@ -64,9 +67,13 @@ func (ns *linuxNs) Init(container *libcontainer.Container, uncleanRootfs, consol return fmt.Errorf("finalize namespace %s", err) } - if err := apparmor.ApplyProfile(os.Getpid(), container.Context["apparmor_profile"]); err != nil { - return err + if profile := container.Context["apparmor_profile"]; profile != "" { + ns.logger.Printf("setting apparmor prifile %s\n", profile) + if err := apparmor.ApplyProfile(os.Getpid(), profile); err != nil { + return err + } } + ns.logger.Printf("execing %s\n", args[0]) return system.Execv(args[0], args[0:], container.Env) } diff --git a/libcontainer/nsinit/nsinit.go b/libcontainer/nsinit/nsinit.go index f09a130..c308692 100644 --- a/libcontainer/nsinit/nsinit.go +++ b/libcontainer/nsinit/nsinit.go @@ -2,6 +2,7 @@ package nsinit import ( "github.com/dotcloud/docker/pkg/libcontainer" + "log" ) // NsInit is an interface with the public facing methods to provide high level @@ -16,11 +17,13 @@ type linuxNs struct { root string commandFactory CommandFactory stateWriter StateWriter + logger *log.Logger } -func NewNsInit(command CommandFactory, state StateWriter) NsInit { +func NewNsInit(command CommandFactory, state StateWriter, logger *log.Logger) NsInit { return &linuxNs{ commandFactory: command, stateWriter: state, + logger: logger, } } diff --git a/libcontainer/nsinit/nsinit/main.go b/libcontainer/nsinit/nsinit/main.go index 916be66..df32d0b 100644 --- a/libcontainer/nsinit/nsinit/main.go +++ b/libcontainer/nsinit/nsinit/main.go @@ -5,6 +5,7 @@ import ( "flag" "github.com/dotcloud/docker/pkg/libcontainer" "github.com/dotcloud/docker/pkg/libcontainer/nsinit" + "io" "io/ioutil" "log" "os" @@ -13,14 +14,15 @@ import ( ) var ( - root, console string - pipeFd int + root, console, logs string + pipeFd int ) func registerFlags() { flag.StringVar(&console, "console", "", "console (pty slave) path") flag.IntVar(&pipeFd, "pipe", 0, "sync pipe fd") flag.StringVar(&root, "root", ".", "root for storing configuration data") + flag.StringVar(&logs, "log", "none", "set stderr or a filepath to enable logging") flag.Parse() } @@ -35,7 +37,12 @@ func main() { if err != nil { log.Fatalf("Unable to load container: %s", err) } - ns, err := newNsInit() + l, err := getLogger("[exec] ") + if err != nil { + log.Fatal(err) + } + + ns, err := newNsInit(l) if err != nil { log.Fatalf("Unable to initialize nsinit: %s", err) } @@ -46,7 +53,7 @@ func main() { nspid, err := readPid() if err != nil { if !os.IsNotExist(err) { - log.Fatalf("Unable to read pid: %s", err) + l.Fatalf("Unable to read pid: %s", err) } } if nspid > 0 { @@ -56,26 +63,26 @@ func main() { exitCode, err = ns.Exec(container, term, flag.Args()[1:]) } if err != nil { - log.Fatalf("Failed to exec: %s", err) + l.Fatalf("Failed to exec: %s", err) } os.Exit(exitCode) case "init": // this is executed inside of the namespace to setup the container cwd, err := os.Getwd() if err != nil { - log.Fatal(err) + l.Fatal(err) } if flag.NArg() < 2 { - log.Fatalf("wrong number of argments %d", flag.NArg()) + l.Fatalf("wrong number of argments %d", flag.NArg()) } syncPipe, err := nsinit.NewSyncPipeFromFd(0, uintptr(pipeFd)) if err != nil { - log.Fatalf("Unable to create sync pipe: %s", err) + l.Fatalf("Unable to create sync pipe: %s", err) } if err := ns.Init(container, cwd, console, syncPipe, flag.Args()[1:]); err != nil { - log.Fatalf("Unable to initialize for container: %s", err) + l.Fatalf("Unable to initialize for container: %s", err) } default: - log.Fatalf("command not supported for nsinit %s", flag.Arg(0)) + l.Fatalf("command not supported for nsinit %s", flag.Arg(0)) } } @@ -105,6 +112,23 @@ func readPid() (int, error) { return pid, nil } -func newNsInit() (nsinit.NsInit, error) { - return nsinit.NewNsInit(&nsinit.DefaultCommandFactory{root}, &nsinit.DefaultStateWriter{root}), nil +func newNsInit(l *log.Logger) (nsinit.NsInit, error) { + return nsinit.NewNsInit(&nsinit.DefaultCommandFactory{root}, &nsinit.DefaultStateWriter{root}, l), nil +} + +func getLogger(prefix string) (*log.Logger, error) { + var w io.Writer + switch logs { + case "", "none": + w = ioutil.Discard + case "stderr": + w = os.Stderr + default: // we have a filepath + f, err := os.OpenFile(logs, os.O_CREATE|os.O_RDWR|os.O_APPEND, 0755) + if err != nil { + return nil, err + } + w = f + } + return log.New(w, prefix, log.LstdFlags), nil } From 9183242a5dbb3adb6ed179dcc854f7d74eb89e1b Mon Sep 17 00:00:00 2001 From: Michael Crosby Date: Thu, 13 Mar 2014 10:43:15 -0700 Subject: [PATCH 2/2] Add stderr log ouput if in debug Docker-DCO-1.1-Signed-off-by: Michael Crosby (github: crosbymichael) --- libcontainer/nsinit/command.go | 3 +-- libcontainer/nsinit/exec.go | 1 + libcontainer/nsinit/init.go | 3 ++- 3 files changed, 4 insertions(+), 3 deletions(-) diff --git a/libcontainer/nsinit/command.go b/libcontainer/nsinit/command.go index 1d7c591..5546065 100644 --- a/libcontainer/nsinit/command.go +++ b/libcontainer/nsinit/command.go @@ -1,7 +1,6 @@ package nsinit import ( - "fmt" "github.com/dotcloud/docker/pkg/libcontainer" "github.com/dotcloud/docker/pkg/system" "os" @@ -26,7 +25,7 @@ func (c *DefaultCommandFactory) Create(container *libcontainer.Container, consol // get our binary name from arg0 so we can always reexec ourself command := exec.Command(os.Args[0], append([]string{ "-console", console, - "-pipe", fmt.Sprint(pipe.Fd()), + "-pipe", "3", "-root", c.Root, "init"}, args...)...) diff --git a/libcontainer/nsinit/exec.go b/libcontainer/nsinit/exec.go index 074492a..61286cc 100644 --- a/libcontainer/nsinit/exec.go +++ b/libcontainer/nsinit/exec.go @@ -26,6 +26,7 @@ func (ns *linuxNs) Exec(container *libcontainer.Container, term Terminal, args [ if err != nil { return -1, err } + ns.logger.Printf("created sync pipe parent fd %d child fd %d\n", syncPipe.parent.Fd(), syncPipe.child.Fd()) if container.Tty { ns.logger.Println("creating master and console") diff --git a/libcontainer/nsinit/init.go b/libcontainer/nsinit/init.go index 6b05905..e165de3 100644 --- a/libcontainer/nsinit/init.go +++ b/libcontainer/nsinit/init.go @@ -24,6 +24,7 @@ func (ns *linuxNs) Init(container *libcontainer.Container, uncleanRootfs, consol } // We always read this as it is a way to sync with the parent as well + ns.logger.Printf("reading from sync pipe fd %d\n", syncPipe.child.Fd()) context, err := syncPipe.ReadFromParent() if err != nil { syncPipe.Close() @@ -68,7 +69,7 @@ func (ns *linuxNs) Init(container *libcontainer.Container, uncleanRootfs, consol } if profile := container.Context["apparmor_profile"]; profile != "" { - ns.logger.Printf("setting apparmor prifile %s\n", profile) + ns.logger.Printf("setting apparmor profile %s\n", profile) if err := apparmor.ApplyProfile(os.Getpid(), profile); err != nil { return err }