From 9f5caf529c61429a83f9050afb09645e01311f7d Mon Sep 17 00:00:00 2001 From: Alexander Morozov Date: Tue, 8 Dec 2015 09:37:31 -0800 Subject: [PATCH 1/6] Add logging for started supervisor Signed-off-by: Alexander Morozov --- linux/linux.go | 4 ++++ runc/runc.go | 4 ++++ runtime/runtime.go | 1 + supervisor.go | 4 ++++ 4 files changed, 13 insertions(+) diff --git a/linux/linux.go b/linux/linux.go index 92110c4..8a97b4f 100644 --- a/linux/linux.go +++ b/linux/linux.go @@ -343,6 +343,10 @@ type libcontainerRuntime struct { factory libcontainer.Factory } +func (r *libcontainerRuntime) Type() string { + return "libcontainer" +} + func (r *libcontainerRuntime) Create(id, bundlePath string, stdio *runtime.Stdio) (runtime.Container, error) { spec, rspec, err := r.loadSpec( filepath.Join(bundlePath, "config.json"), diff --git a/runc/runc.go b/runc/runc.go index 967ddc9..ff429cb 100644 --- a/runc/runc.go +++ b/runc/runc.go @@ -135,6 +135,10 @@ type runcRuntime struct { stateDir string } +func (r *runcRuntime) Type() string { + return "runc" +} + func (r *runcRuntime) Create(id, bundlePath string, stdio *runtime.Stdio) (runtime.Container, error) { cmd := exec.Command("runc", "--root", r.stateDir, "--id", id, "start") cmd.Dir = bundlePath diff --git a/runtime/runtime.go b/runtime/runtime.go index b92861a..5a5e0d9 100644 --- a/runtime/runtime.go +++ b/runtime/runtime.go @@ -17,4 +17,5 @@ var ( type Runtime interface { Create(id, bundlePath string, stdio *Stdio) (Container, error) StartProcess(Container, specs.Process, *Stdio) (Process, error) + Type() string } diff --git a/supervisor.go b/supervisor.go index d411a30..b3938b2 100644 --- a/supervisor.go +++ b/supervisor.go @@ -149,6 +149,10 @@ func (s *Supervisor) Start() error { close(e.Err) } }() + logrus.WithFields(logrus.Fields{ + "runtime": s.runtime.Type(), + "stateDir": s.stateDir, + }).Debug("Supervisor started") return nil } From 46b2a560c00d77971d0cbd7dd83ad040f1bb69f9 Mon Sep 17 00:00:00 2001 From: Alexander Morozov Date: Tue, 8 Dec 2015 09:41:10 -0800 Subject: [PATCH 2/6] Add logging about subreaper Signed-off-by: Alexander Morozov --- containerd/main.go | 3 +++ 1 file changed, 3 insertions(+) diff --git a/containerd/main.go b/containerd/main.go index 6e9af13..88a5bc8 100644 --- a/containerd/main.go +++ b/containerd/main.go @@ -103,6 +103,9 @@ func daemon(id, stateDir string, concurrency, bufferSize int) error { } // only set containerd as the subreaper if it is not an init process if pid := os.Getpid(); pid != 1 { + logrus.WithFields(logrus.Fields{ + "pid": pid, + }).Debug("containerd is not init, set as subreaper") if err := setSubReaper(); err != nil { return err } From 64705f526318c0f7dfa3cd1cccc1428e5434da3e Mon Sep 17 00:00:00 2001 From: Alexander Morozov Date: Tue, 8 Dec 2015 09:43:49 -0800 Subject: [PATCH 3/6] Add buffer size to signal handler log Signed-off-by: Alexander Morozov --- containerd/reap_linux.go | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/containerd/reap_linux.go b/containerd/reap_linux.go index 33a5447..d739287 100644 --- a/containerd/reap_linux.go +++ b/containerd/reap_linux.go @@ -14,7 +14,9 @@ import ( ) func startSignalHandler(supervisor *containerd.Supervisor, bufferSize int) { - logrus.Debug("containerd: starting signal handler") + logrus.WithFields(logrus.Fields{ + "bufferSize": bufferSize, + }).Debug("containerd: starting signal handler") signals := make(chan os.Signal, bufferSize) signal.Notify(signals) for s := range signals { From 4adf5d2c0db85c6c6e531d499668f71423f6dbd6 Mon Sep 17 00:00:00 2001 From: Alexander Morozov Date: Tue, 8 Dec 2015 09:49:15 -0800 Subject: [PATCH 4/6] Add debug logging about events Signed-off-by: Alexander Morozov --- supervisor.go | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/supervisor.go b/supervisor.go index b3938b2..9291c68 100644 --- a/supervisor.go +++ b/supervisor.go @@ -133,6 +133,12 @@ func (s *Supervisor) Start() error { // so that nothing else is scheduled over the top of it. goruntime.LockOSThread() for e := range s.events { + logrus.WithFields(logrus.Fields{ + "type": e.Type, + "timestamp": e.Timestamp, + "id": e.ID, + "bundlePath": e.BundlePath, + }).Debug("event received") EventsCounter.Inc(1) h, ok := s.handlers[e.Type] if !ok { From cf3b72852a0a52d9f47ecc1a79b0664a856cccc5 Mon Sep 17 00:00:00 2001 From: Alexander Morozov Date: Tue, 8 Dec 2015 10:07:55 -0800 Subject: [PATCH 5/6] Add log and more context to errors in Create Signed-off-by: Alexander Morozov --- linux/linux.go | 15 ++++++++++----- 1 file changed, 10 insertions(+), 5 deletions(-) diff --git a/linux/linux.go b/linux/linux.go index 8a97b4f..6b4d274 100644 --- a/linux/linux.go +++ b/linux/linux.go @@ -14,6 +14,7 @@ import ( "strings" "syscall" + "github.com/Sirupsen/logrus" "github.com/docker/containerd/runtime" "github.com/opencontainers/runc/libcontainer" "github.com/opencontainers/runc/libcontainer/configs" @@ -355,13 +356,17 @@ func (r *libcontainerRuntime) Create(id, bundlePath string, stdio *runtime.Stdio if err != nil { return nil, err } + logrus.WithFields(logrus.Fields{ + "id": id, + "bundlePath": bundlePath, + }).Debugf("create container") config, err := r.createLibcontainerConfig(id, bundlePath, spec, rspec) if err != nil { return nil, err } container, err := r.factory.Create(id, config) if err != nil { - return nil, err + return nil, fmt.Errorf("create container: %v", err) } process, err := r.newProcess(spec.Process, stdio) if err != nil { @@ -413,14 +418,14 @@ func (r *libcontainerRuntime) newProcess(p specs.Process, stdio *runtime.Stdio) if stdio.Stdout != "" { f, err := os.OpenFile(stdio.Stdout, os.O_CREATE|os.O_WRONLY, 0755) if err != nil { - return nil, err + return nil, fmt.Errorf("open stdout: %v", err) } stdout = f } if stdio.Stderr != "" { f, err := os.OpenFile(stdio.Stderr, os.O_CREATE|os.O_WRONLY, 0755) if err != nil { - return nil, err + return nil, fmt.Errorf("open stderr: %v", err) } stderr = f } @@ -458,10 +463,10 @@ func (r *libcontainerRuntime) loadSpec(cPath, rPath string) (spec *specs.LinuxSp defer rf.Close() if err = json.NewDecoder(cf).Decode(&spec); err != nil { - return spec, rspec, err + return spec, rspec, fmt.Errorf("unmarshal %s: %v", cPath, err) } if err = json.NewDecoder(rf).Decode(&rspec); err != nil { - return spec, rspec, err + return spec, rspec, fmt.Errorf("unmarshal %s: %v", rPath, err) } return spec, rspec, r.checkSpecVersion(spec) } From 6bfc4df8a7f97792aa0b90402543f5e5084660a7 Mon Sep 17 00:00:00 2001 From: Alexander Morozov Date: Tue, 8 Dec 2015 10:16:30 -0800 Subject: [PATCH 6/6] Log start tasks Signed-off-by: Alexander Morozov --- worker.go | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/worker.go b/worker.go index d77ebef..244b91e 100644 --- a/worker.go +++ b/worker.go @@ -4,6 +4,7 @@ import ( "sync" "time" + "github.com/Sirupsen/logrus" "github.com/docker/containerd/runtime" ) @@ -33,6 +34,11 @@ func (w *worker) Start() { defer w.wg.Done() for t := range w.s.tasks { started := time.Now() + logrus.WithFields(logrus.Fields{ + "containerID": t.Container.ID(), + "checkpoint": t.Checkpoint, + "started": started, + }).Debug("worker received task") if t.Checkpoint != "" { if err := t.Container.Restore(t.Checkpoint); err != nil { evt := NewEvent(DeleteEventType)