add tracing

_example/echodeploy.yml

@@ -17,7 +17,7 @@ spec:
         command:
         - /bin/sh
         - "-c"
-        - while true; do date; sleep 1; done
+        - for i in $(seq 1 5); do echo "$i"; sleep 1; done
 ---
 kind: Service
 apiVersion: v1

controller.go

@@ -84,6 +84,7 @@ func (c *controller) Stop() {
 }
 
 func (c *controller) run(initial []*v1.Pod) {
+	defer c.log.Un(c.log.Trace("run"))
 	defer c.lc.ShutdownCompleted()
 	defer c.pods.Close()
 
@@ -115,6 +116,7 @@ func (c *controller) run(initial []*v1.Pod) {
 			c.handlePodEvent(ev)
 
 		case source := <-c.monitorch:
+			c.log.Debugf("removing source %v", source)
 			if pms, ok := c.monitors[source.id]; ok {
 				delete(pms, source)
 			}
@@ -152,10 +154,14 @@ func (c *controller) ensureMonitorsForPod(pod *v1.Pod) {
 		}
 	}
 
+	c.log.Debugf("pod %v/%v: %v containers ready",
+		pod.GetNamespace(), pod.GetName(), len(sources))
+
 	// delete monitors of not-ready containers
 	if pms, ok := c.monitors[id]; ok {
 		for source, pm := range pms {
 			if !sources[source] {
+				c.log.Debugf("shutting down %v", source)
 				pm.Shutdown()
 			}
 		}
@@ -189,19 +195,21 @@ func (c *controller) shutdownMonitors() {
 }
 
 func (c *controller) createMonitor(source eventSource) monitor {
+	defer c.log.Un(c.log.Trace("createMonitor(%v)", source))
 	m := newMonitor(c, &source)
 	go func() {
 		<-m.Done()
 		select {
 		case c.monitorch <- source:
 		case <-c.lc.Done():
-			c.log.Warnf("done before monitor %v:%v complete", source.id, source.container)
+			c.log.Warnf("done before monitor %v complete", source)
 		}
 	}()
 	return m
 }
 
 func (c *controller) createInitialMonitors(pods []*v1.Pod) {
+	defer c.log.Un(c.log.Trace("createInitialMonitors(pods=%v)", len(pods)))
 	for _, pod := range pods {
 		c.ensureMonitorsForPod(pod)
 	}

monitor.go

@@ -27,8 +27,7 @@ func newMonitor(c *controller, source EventSource) monitor {
 	go lc.WatchContext(c.ctx)
 
 	log := c.log.WithComponent(
-		fmt.Sprintf("monitor %v/%v:%v",
-			source.Namespace(), source.Name(), source.Container()))
+		fmt.Sprintf("monitor [%v]", source))
 
 	m := &_monitor{
 		core:    c.cs.CoreV1(),

util.go

@@ -1,6 +1,10 @@
 package kail
 
-import "github.com/boz/kcache/nsname"
+import (
+	"fmt"
+
+	"github.com/boz/kcache/nsname"
+)
 
 type EventSource interface {
 	Namespace() string
@@ -31,6 +35,11 @@ func (es eventSource) Node() string {
 	return es.node
 }
 
+func (es eventSource) String() string {
+	return fmt.Sprintf("%v/%v@%v",
+		es.id.Namespace, es.id.Name, es.container)
+}
+
 type Event interface {
 	Source() EventSource
 	Log() string

vendor/vendor.json

@@ -57,80 +57,80 @@
 		{
 			"checksumSHA1": "MTH+ZMsTbcZInzBxH6cBUcietJ8=",
 			"path": "github.com/boz/kcache",
-			"revision": "d2f10b0f1364575eafda6aa523ff57e517f5923d",
-			"revisionTime": "2017-08-16T01:20:11Z"
+			"revision": "b28bcad231e6355b610e343fed66eb7efa697cee",
+			"revisionTime": "2017-08-16T03:00:13Z"
 		},
 		{
 			"checksumSHA1": "RGlf5AzjJwJDpwCJWUZKRX+lfgw=",
 			"path": "github.com/boz/kcache/client",
-			"revision": "d2f10b0f1364575eafda6aa523ff57e517f5923d",
-			"revisionTime": "2017-08-16T01:20:11Z"
+			"revision": "b28bcad231e6355b610e343fed66eb7efa697cee",
+			"revisionTime": "2017-08-16T03:00:13Z"
 		},
 		{
 			"checksumSHA1": "/ay4kraaeIMXx8DN4u0fg7Qhyvs=",
 			"path": "github.com/boz/kcache/filter",
-			"revision": "d2f10b0f1364575eafda6aa523ff57e517f5923d",
-			"revisionTime": "2017-08-16T01:20:11Z"
+			"revision": "b28bcad231e6355b610e343fed66eb7efa697cee",
+			"revisionTime": "2017-08-16T03:00:13Z"
 		},
 		{
-			"checksumSHA1": "a2Z8yzTfbPbPubiU07q652qGuuM=",
+			"checksumSHA1": "SgiDp8QPnFLsSRky67DNg553ZIQ=",
 			"path": "github.com/boz/kcache/join",
-			"revision": "d2f10b0f1364575eafda6aa523ff57e517f5923d",
-			"revisionTime": "2017-08-16T01:20:11Z"
+			"revision": "b28bcad231e6355b610e343fed66eb7efa697cee",
+			"revisionTime": "2017-08-16T03:00:13Z"
 		},
 		{
 			"checksumSHA1": "cVUF28ARwaKHooP4gpYjH9+TMmc=",
 			"path": "github.com/boz/kcache/nsname",
-			"revision": "d2f10b0f1364575eafda6aa523ff57e517f5923d",
-			"revisionTime": "2017-08-16T01:20:11Z"
+			"revision": "b28bcad231e6355b610e343fed66eb7efa697cee",
+			"revisionTime": "2017-08-16T03:00:13Z"
 		},
 		{
 			"checksumSHA1": "LLPh76DEtyGTFSzdtyDNG9wVc6o=",
 			"path": "github.com/boz/kcache/types/daemonset",
-			"revision": "d2f10b0f1364575eafda6aa523ff57e517f5923d",
-			"revisionTime": "2017-08-16T01:20:11Z"
+			"revision": "b28bcad231e6355b610e343fed66eb7efa697cee",
+			"revisionTime": "2017-08-16T03:00:13Z"
 		},
 		{
 			"checksumSHA1": "YCva3SLoR0G2EWSJrmQdnLrwa/k=",
 			"path": "github.com/boz/kcache/types/deployment",
-			"revision": "d2f10b0f1364575eafda6aa523ff57e517f5923d",
-			"revisionTime": "2017-08-16T01:20:11Z"
+			"revision": "b28bcad231e6355b610e343fed66eb7efa697cee",
+			"revisionTime": "2017-08-16T03:00:13Z"
 		},
 		{
 			"checksumSHA1": "qGyOw78D3ReTEqlAYOID7kmv/54=",
 			"path": "github.com/boz/kcache/types/node",
-			"revision": "d2f10b0f1364575eafda6aa523ff57e517f5923d",
-			"revisionTime": "2017-08-16T01:20:11Z"
+			"revision": "b28bcad231e6355b610e343fed66eb7efa697cee",
+			"revisionTime": "2017-08-16T03:00:13Z"
 		},
 		{
 			"checksumSHA1": "YwjQRO3f2HS0v+1QTvjfzuqLuVY=",
 			"path": "github.com/boz/kcache/types/pod",
-			"revision": "d2f10b0f1364575eafda6aa523ff57e517f5923d",
-			"revisionTime": "2017-08-16T01:20:11Z"
+			"revision": "b28bcad231e6355b610e343fed66eb7efa697cee",
+			"revisionTime": "2017-08-16T03:00:13Z"
 		},
 		{
 			"checksumSHA1": "Zw3JhS3LsYifU6pKQmPB40qlFcY=",
 			"path": "github.com/boz/kcache/types/replicaset",
-			"revision": "d2f10b0f1364575eafda6aa523ff57e517f5923d",
-			"revisionTime": "2017-08-16T01:20:11Z"
+			"revision": "b28bcad231e6355b610e343fed66eb7efa697cee",
+			"revisionTime": "2017-08-16T03:00:13Z"
 		},
 		{
 			"checksumSHA1": "H1CywbM6uH3hoEUrbu185emQXHI=",
 			"path": "github.com/boz/kcache/types/replicationcontroller",
-			"revision": "d2f10b0f1364575eafda6aa523ff57e517f5923d",
-			"revisionTime": "2017-08-16T01:20:11Z"
+			"revision": "b28bcad231e6355b610e343fed66eb7efa697cee",
+			"revisionTime": "2017-08-16T03:00:13Z"
 		},
 		{
 			"checksumSHA1": "Qu+4+QsMlwBMVPidPoJqlTFyFIM=",
 			"path": "github.com/boz/kcache/types/service",
-			"revision": "d2f10b0f1364575eafda6aa523ff57e517f5923d",
-			"revisionTime": "2017-08-16T01:20:11Z"
+			"revision": "b28bcad231e6355b610e343fed66eb7efa697cee",
+			"revisionTime": "2017-08-16T03:00:13Z"
 		},
 		{
 			"checksumSHA1": "hvQV7lHc5IoAGsNQRuO+19v9n1A=",
 			"path": "github.com/boz/kcache/util",
-			"revision": "d2f10b0f1364575eafda6aa523ff57e517f5923d",
-			"revisionTime": "2017-08-16T01:20:11Z"
+			"revision": "b28bcad231e6355b610e343fed66eb7efa697cee",
+			"revisionTime": "2017-08-16T03:00:13Z"
 		},
 		{
 			"checksumSHA1": "mrz/kicZiUaHxkyfvC/DyQcr8Do=",

writer.go

@@ -40,9 +40,6 @@ func (w *writer) Fprint(out io.Writer, ev Event) error {
 	if _, err := out.Write([]byte(ev.Log())); err != nil {
 		return err
 	}
-	if _, err := out.Write([]byte("\n")); err != nil {
-		return err
-	}
 	return nil
 }