Repository: honeycombio/honeycomb-kubernetes-agent
Pull request #48 (2019-06-21 01:23:17)

Fix container filtering issue introduced by new log pattern, bump 1.3.2
For users who are using containerName to filter the containers being watched by the agent, K8S cluster versions published after this change: kubernetes/kubernetes#74441 stop sending events to Honeycomb.

This commit fixes that issue, adds additional debug logging to allow us to find these issues faster and bumps up the version number.


Patch:
diff --git a/CHANGELOG.md b/CHANGELOG.md
index 4896865..499f24f 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -1,5 +1,11 @@
 # Honeycomb Kubernetes Agent Changelog
 
+## 1.3.2 2019-06-21 Update recommended
+
+Fixes
+
+- Supports new log path pattern for container filtering used in K8s versions published after [this](https://github.com/kubernetes/kubernetes/pull/74441) change. If using containerNames in your watchers configuration and have stopped receiving log data for those containers, this is likely your issue.
+
 ## 1.3.1 2019-06-12 Update recommended
 
 Fixes
@@ -12,7 +18,7 @@ Features
 
 - New `additional_field` processor for adding arbitrary fields to events. Docs [here](https://github.com/honeycombio/honeycomb-kubernetes-agent/blob/master/docs/configuration-reference.md#additional_fields).
 - New `rename_field` processor for renaming event fields. See docs [here](https://github.com/honeycombio/honeycomb-kubernetes-agent/blob/master/docs/configuration-reference.md#rename_field).
-- New global `additionalFields` opton for adding arbitrary fields to *all* event sent by the agent. Click [here](https://github.com/honeycombio/honeycomb-kubernetes-agent/blob/master/docs/configuration-reference.md#additionalfields) for more information.
+- New global `additionalFields` option for adding arbitrary fields to _all_ events sent by the agent. Click [here](https://github.com/honeycombio/honeycomb-kubernetes-agent/blob/master/docs/configuration-reference.md#additionalfields) for more information.
 
 Improvements
 
diff --git a/examples/quickstart.yaml b/examples/quickstart.yaml
index 722820e..8d5376b 100644
--- a/examples/quickstart.yaml
+++ b/examples/quickstart.yaml
@@ -65,8 +65,8 @@ metadata:
   labels:
     k8s-app: honeycomb-agent
     kubernetes.io/cluster-service: 'true'
-    version: v1.3.1
-  name: honeycomb-agent-v1.3.1
+    version: v1.3.2
+  name: honeycomb-agent-v1.3.2
   namespace: kube-system
 spec:
   updateStrategy:
@@ -78,7 +78,7 @@ spec:
       labels:
         k8s-app: honeycomb-agent
         kubernetes.io/cluster-service: 'true'
-        version: v1.3.1
+        version: v1.3.2
     spec:
       tolerations:
         - operator: Exists
@@ -94,7 +94,7 @@ spec:
           valueFrom:
             fieldRef:
               fieldPath: spec.nodeName
-        image: honeycombio/honeycomb-kubernetes-agent:1.3.1
+        image: honeycombio/honeycomb-kubernetes-agent:1.3.2
         imagePullPolicy: IfNotPresent
         name: honeycomb-agent
         resources:
diff --git a/main.go b/main.go
index 1fec304..b6de9d1 100644
--- a/main.go
+++ b/main.go
@@ -53,6 +53,9 @@ func init() {
 	}
 	// init libhoney user agent properly
 	libhoney.UserAgentAddition = fmt.Sprintf("kubernetes/" + version.VERSION)
+	logrus.WithFields(logrus.Fields{
+		"version": version.VERSION,
+	}).Info("Initializing agent")
 }
 
 func main() {
@@ -129,6 +132,9 @@ func main() {
 
 	for _, watcherConfig := range config.Watchers {
 		for _, path := range watcherConfig.FilePaths {
+			logrus.WithFields(logrus.Fields{
+				"path": path,
+			}).Debug("FilePath specified in config")
 			handlerFactory, err := handlers.NewLineHandlerFactoryFromConfig(
 				watcherConfig,
 				&unwrappers.RawLogUnwrapper{},
diff --git a/podtailer/podtailer.go b/podtailer/podtailer.go
index 3fe03a7..8dad1c1 100644
--- a/podtailer/podtailer.go
+++ b/podtailer/podtailer.go
@@ -113,9 +113,10 @@ loop:
 			}
 			if watcher != nil {
 				logrus.WithFields(logrus.Fields{
-					"name":      pod.Name,
-					"uid":       pod.UID,
-					"namespace": pod.Namespace,
+					"labelselector": labelSelector,
+					"name":          pod.Name,
+					"uid":           pod.UID,
+					"namespace":     pod.Namespace,
 				}).Info("starting watcher for pod")
 				watcher.Start()
 				watcherMap[pod.UID] = watcher
@@ -155,10 +156,13 @@ func (pt *PodSetTailer) Stop() {
 	pt.wg.Wait()
 }
 
+// If you change the log pattern, make sure to check that the filter pattern still works
+// (in determineFilterFunc)
 func determineLogPattern(pod *v1.Pod, basePath string, legacyLogPaths bool) (string, error) {
 	if basePath == "" {
 		basePath = logsBasePath
 	}
+
 	// Legacy pattern was:
 	// /var/log/containers/<pod_name>_<pod_namespace>_<container_name>-<container_id>.log`
 	// For now, this is still supported on newer k8s clusters with a symlink
@@ -243,17 +247,24 @@ func determineLogPattern(pod *v1.Pod, basePath string, legacyLogPaths bool) (str
 	return "", fmt.Errorf("Could not find specified log path for pod %s", pod.UID)
 }
 
-func determineFilterFunc(pod *v1.Pod, containerName string, legacyLogPaths bool) func(fileName string) bool {
+func determineFilterFunc(pod *v1.Pod, basePath string, containerName string, legacyLogPaths bool) func(fileName string) bool {
+
 	if containerName == "" {
+		logrus.Debug("No container name specified, no filter function needed")
 		return nil
 	}
 	if legacyLogPaths {
 		re := fmt.Sprintf(
-			"^/var/log/containers/%s_%s_%s-.+\\.log",
+			"^%s/containers/%s_%s_%s-.+\\.log",
+			basePath,
 			pod.Name,
 			pod.Namespace,
 			containerName,
 		)
+		logrus.WithFields(logrus.Fields{
+			"regex": re,
+		}).Debug("Container filter function")
+
 		return func(fileName string) bool {
 			ok, _ := regexp.Match(re, []byte(fileName))
 			return ok
@@ -262,18 +273,33 @@ func determineFilterFunc(pod *v1.Pod, containerName string, legacyLogPaths bool)
 
 	uid := string(pod.UID)
 	if hash, ok := pod.Annotations["kubernetes.io/config.hash"]; ok {
+		logrus.WithFields(logrus.Fields{
+			"hash": hash,
+		}).Debug("Using hash for uID")
 		uid = hash
 	}
 
-	// HACK: try the k8s 1.10 log pattern first, then fall back to our original log pattern
-	re1 := fmt.Sprintf("^/var/log/pods/%s/%s/[0-9]*\\.log", uid, regexp.QuoteMeta(containerName))
-	re2 := fmt.Sprintf("^/var/log/pods/%s/%s_[0-9]*\\.log", uid, regexp.QuoteMeta(containerName))
+	// HACK: try the https://github.com/kubernetes/kubernetes/pull/74441 log pattern
+	re1 := fmt.Sprintf("^%s/pods/%s_%s_%s/%s/[0-9]*\\.log", basePath, pod.Namespace, pod.Name, uid, regexp.QuoteMeta(containerName))
+	// HACK: try the k8s 1.10 log pattern next, then fall back to our original log pattern
+	re2 := fmt.Sprintf("^%s/pods/%s/%s/[0-9]*\\.log", basePath, uid, regexp.QuoteMeta(containerName))
+	re3 := fmt.Sprintf("^%s/pods/%s/%s_[0-9]*\\.log", basePath, uid, regexp.QuoteMeta(containerName))
+	logrus.WithFields(logrus.Fields{
+		"regex1": re1,
+		"regex2": re2,
+		"regex3": re3,
+	}).Debug("Container filter function")
+
 	return func(fileName string) bool {
 		ok, _ := regexp.Match(re1, []byte(fileName))
 		if ok {
 			return ok
 		}
 		ok, _ = regexp.Match(re2, []byte(fileName))
+		if ok {
+			return ok
+		}
+		ok, _ = regexp.Match(re3, []byte(fileName))
 		return ok
 	}
 }
@@ -287,7 +313,7 @@ func (pt *PodSetTailer) watcherForPod(pod *v1.Pod, containerName string, podWatc
 
 	// only watch logs for containers matching the given name, if
 	// one is specified
-	filterFunc := determineFilterFunc(pod, containerName, pt.legacyLogPaths)
+	filterFunc := determineFilterFunc(pod, logsBasePath, containerName, pt.legacyLogPaths)
 
 	additionalProcessors := []processors.Processor{
 		&processors.KubernetesMetadataProcessor{
diff --git a/tailer/tailer.go b/tailer/tailer.go
index c61677f..d6dd6fb 100644
--- a/tailer/tailer.go
+++ b/tailer/tailer.go
@@ -183,6 +183,10 @@ func (p *PathWatcher) check() {
 
 		// save the pattern so we don't have to keep running our pattern function
 		p.savedPattern = pt
+
+		logrus.WithFields(logrus.Fields{
+			"log pattern": pt,
+		}).Info("Log pattern")
 	}
 	files, err := filepath.Glob(p.savedPattern)
 	if err != nil {
@@ -198,6 +202,9 @@ func (p *PathWatcher) check() {
 		_, ok := p.tailers[file]
 		if !ok {
 			if p.filter != nil && !p.filter(file) {
+				logrus.WithFields(logrus.Fields{
+					"file": file,
+				}).Warn("File filtered out of tailing list based on containerName")
 				continue
 			}
 			handler := p.handlerFactory.New(file)
diff --git a/version.txt b/version.txt
index 1527a8d..971711a 100644
--- a/version.txt
+++ b/version.txt
@@ -1,2 +1,2 @@
-1.3.1
+1.3.2
 


Test patch:
diff --git a/podtailer/podtailer_test.go b/podtailer/podtailer_test.go
index 5765a82..d11fa91 100644
--- a/podtailer/podtailer_test.go
+++ b/podtailer/podtailer_test.go
@@ -130,7 +130,7 @@ func TestDetermineFilterFuncLegacyLogs(t *testing.T) {
 		return ok
 	}
 
-	f := determineFilterFunc(pod, "wibble", true)
+	f := determineFilterFunc(pod, "/var/log", "wibble", true)
 	// functions should have same output
 	assert.Equal(
 		t,
@@ -160,7 +160,7 @@ func TestDetermineFilterFunc(t *testing.T) {
 		return ok
 	}
 
-	f := determineFilterFunc(pod, "wibble", false)
+	f := determineFilterFunc(pod, "/var/log", "wibble", false)
 	assert.Equal(
 		t,
 		expected("/var/log/pods/123456/wibble_0.log"),
@@ -192,7 +192,7 @@ func TestDetermineFilterFuncK8S1Dot10(t *testing.T) {
 		return ok
 	}
 
-	f := determineFilterFunc(pod, "wibble", false)
+	f := determineFilterFunc(pod, "/var/log", "wibble", false)
 	assert.Equal(
 		t,
 		expected("/var/log/pods/123456/wibble/0.log"),
@@ -205,3 +205,48 @@ func TestDetermineFilterFuncK8S1Dot10(t *testing.T) {
 		f("/var/log/pods/123456/wobble/0.log"),
 	)
 }
+
+func TestDetermineFilterFuncK8S74441(t *testing.T) {
+	t.Parallel()
+	// Format changed after https://github.com/kubernetes/kubernetes/pull/74441
+	// to /var/log/pods/<namespace>_<name>_<uid>/<containerName>/N.log
+	// Handle it if we see it
+	pod := &v1.Pod{}
+	pod.Namespace = "asdf"
+	pod.Name = "foo"
+	pod.UID = "123456"
+	podDirName := fmt.Sprintf("%s_%s_%s", pod.Namespace, pod.Name, pod.UID)
+
+	basePath, err := ioutil.TempDir("", "")
+	assert.Nil(t, err)
+	defer os.RemoveAll(basePath)
+
+	err = os.Mkdir(filepath.Join(basePath, "pods"), 0777)
+	assert.Nil(t, err)
+	err = os.Mkdir(filepath.Join(basePath, "pods", podDirName), 0777)
+	assert.Nil(t, err)
+	err = os.Mkdir(filepath.Join(basePath, "pods", podDirName, "container1"), 0777)
+	assert.Nil(t, err)
+	err = os.Mkdir(filepath.Join(basePath, "pods", podDirName, "container2"), 0777)
+	assert.Nil(t, err)
+	file1 := filepath.Join(basePath, "pods", podDirName, "container1", "0.log")
+	_, err = os.Create(file1)
+	assert.Nil(t, err)
+	file2 := filepath.Join(basePath, "pods", podDirName, "container2", "0.log")
+	_, err = os.Create(file2)
+	assert.Nil(t, err)
+
+	f := determineFilterFunc(pod, basePath, "container1", false)
+
+	assert.Equal(
+		t,
+		f(file1),
+		true,
+	)
+
+	assert.Equal(
+		t,
+		f(file2),
+		false,
+	)
+}