From 6acf5b1edb58f36fcadb90a7a940d1c1ab4ac830 Mon Sep 17 00:00:00 2001
From: Archit Bansal <arba@google.com>
Date: Thu, 16 Jul 2020 01:08:02 -0700
Subject: [PATCH] Capture the logs from stderr of custom plugins.

---
 pkg/custompluginmonitor/plugin/plugin.go      | 78 ++++++++++++++++++-
 pkg/custompluginmonitor/plugin/plugin_test.go |  2 +-
 2 files changed, 76 insertions(+), 4 deletions(-)

diff --git a/pkg/custompluginmonitor/plugin/plugin.go b/pkg/custompluginmonitor/plugin/plugin.go
index 60c7fb8c..45889e33 100644
--- a/pkg/custompluginmonitor/plugin/plugin.go
+++ b/pkg/custompluginmonitor/plugin/plugin.go
@@ -19,6 +19,8 @@ package plugin
 import (
 	"context"
 	"fmt"
+	"io"
+	"io/ioutil"
 	"os/exec"
 	"strings"
 	"sync"
@@ -30,6 +32,10 @@ import (
 	"k8s.io/node-problem-detector/pkg/util/tomb"
 )
 
+// maxCustomPluginBufferBytes is the max bytes that a custom plugin is allowed to
+// send to stdout/stderr. Any bytes exceeding this value will be truncated.
+const maxCustomPluginBufferBytes = 1024 * 4
+
 type Plugin struct {
 	config     cpmtypes.CustomPluginConfig
 	syncChan   chan struct{}
@@ -115,6 +121,20 @@ func (p *Plugin) runRules() {
 	glog.Info("Finish running custom plugins")
 }
 
+// readFromReader reads the maxBytes from the reader and drains the rest.
+func readFromReader(reader io.ReadCloser, maxBytes int64) ([]byte, error) {
+	limitReader := io.LimitReader(reader, maxBytes)
+	data, err := ioutil.ReadAll(limitReader)
+	if err != nil {
+		return []byte{}, err
+	}
+	// Drain the reader
+	if _, err := io.Copy(ioutil.Discard, reader); err != nil {
+		return []byte{}, err
+	}
+	return data, nil
+}
+
 func (p *Plugin) run(rule cpmtypes.CustomRule) (exitStatus cpmtypes.Status, output string) {
 	var ctx context.Context
 	var cancel context.CancelFunc
@@ -127,14 +147,66 @@ func (p *Plugin) run(rule cpmtypes.CustomRule) (exitStatus cpmtypes.Status, outp
 	defer cancel()
 
 	cmd := exec.CommandContext(ctx, rule.Path, rule.Args...)
-	stdout, err := cmd.Output()
+
+	stdoutPipe, err := cmd.StdoutPipe()
 	if err != nil {
+		glog.Errorf("Error creating stdout pipe for plugin %q: error - %v", rule.Path, err)
+		return cpmtypes.Unknown, "Error creating stdout pipe for plugin. Please check the error log"
+	}
+	stderrPipe, err := cmd.StderrPipe()
+	if err != nil {
+		glog.Errorf("Error creating stderr pipe for plugin %q: error - %v", rule.Path, err)
+		return cpmtypes.Unknown, "Error creating stderr pipe for plugin. Please check the error log"
+	}
+	if err := cmd.Start(); err != nil {
+		glog.Errorf("Error in starting plugin %q: error - %v", rule.Path, err)
+		return cpmtypes.Unknown, "Error in starting plugin. Please check the error log"
+	}
+
+	var (
+		wg        sync.WaitGroup
+		stdout    []byte
+		stderr    []byte
+		stdoutErr error
+		stderrErr error
+	)
+
+	wg.Add(2)
+	go func() {
+		stdout, stdoutErr = readFromReader(stdoutPipe, maxCustomPluginBufferBytes)
+		wg.Done()
+	}()
+	go func() {
+		stderr, stderrErr = readFromReader(stderrPipe, maxCustomPluginBufferBytes)
+		wg.Done()
+	}()
+	// This will wait for the reads to complete. If the execution times out, the pipes
+	// will be closed and the wait group unblocks.
+	wg.Wait()
+
+	if stdoutErr != nil {
+		glog.Errorf("Error reading stdout for plugin %q: error - %v", rule.Path, err)
+		return cpmtypes.Unknown, "Error reading stdout for plugin. Please check the error log"
+	}
+
+	if stderrErr != nil {
+		glog.Errorf("Error reading stderr for plugin %q: error - %v", rule.Path, err)
+		return cpmtypes.Unknown, "Error reading stderr for plugin. Please check the error log"
+	}
+
+	if err := cmd.Wait(); err != nil {
 		if _, ok := err.(*exec.ExitError); !ok {
-			glog.Errorf("Error in running plugin %q: error - %v. output - %q", rule.Path, err, string(stdout))
-			return cpmtypes.Unknown, "Error in running plugin. Please check the error log"
+			glog.Errorf("Error in waiting for plugin %q: error - %v. output - %q", rule.Path, err, string(stdout))
+			return cpmtypes.Unknown, "Error in waiting for plugin. Please check the error log"
 		}
 	}
 
+	// log the stderr from the plugin
+	if len(stderr) != 0 {
+		glog.Infof("Start logs from plugin %q \n %s", rule.Path, string(stderr))
+		glog.Infof("End logs from plugin %q", rule.Path)
+	}
+
 	// trim suffix useless bytes
 	output = string(stdout)
 	output = strings.TrimSpace(output)
diff --git a/pkg/custompluginmonitor/plugin/plugin_test.go b/pkg/custompluginmonitor/plugin/plugin_test.go
index 7503879c..845c356c 100644
--- a/pkg/custompluginmonitor/plugin/plugin_test.go
+++ b/pkg/custompluginmonitor/plugin/plugin_test.go
@@ -61,7 +61,7 @@ func TestNewPluginRun(t *testing.T) {
 				Timeout: &ruleTimeout,
 			},
 			ExitStatus: cpmtypes.Unknown,
-			Output:     "Error in running plugin. Please check the error log",
+			Output:     "Error in starting plugin. Please check the error log",
 		},
 		"longer than 80 stdout with ok exit status": {
 			Rule: cpmtypes.CustomRule{