Log debug output in helm.Config [#9]

Redacting KubeToken may not be sufficient, since it's possible that
someone would put secrets in Values or StringValues. Unilaterally
redacting those seems unhelpful, though, since they may be the very
thing the user is trying to debug. I've settled on redacting the obvious
field without trying to promise that all sensitive data will be hidden.

cmd/drone-helm/main.go

@@ -8,7 +8,7 @@ import (
 )
 
 func main() {
-	cfg, err := helm.NewConfig()
+	cfg, err := helm.NewConfig(os.Stdout, os.Stderr)
 
 	if err != nil {
 		fmt.Fprintf(os.Stderr, "%s\n", err.Error())

internal/helm/config.go

@@ -1,7 +1,9 @@
 package helm
 
 import (
+	"fmt"
 	"github.com/kelseyhightower/envconfig"
+	"io"
 )
 
 // The Config struct captures the `settings` and `environment` blocks in the application's drone
@@ -33,11 +35,17 @@ type Config struct {
 	Chart              string   ``                                   // Chart argument to use in applicable helm commands
 	Release            string   ``                                   // Release argument to use in applicable helm commands
 	Force              bool     ``                                   // Pass --force to applicable helm commands
+
+	Stdout io.Writer `ignored:"true"`
+	Stderr io.Writer `ignored:"true"`
 }
 
 // NewConfig creates a Config and reads environment variables into it, accounting for several possible formats.
-func NewConfig() (*Config, error) {
+func NewConfig(stdout, stderr io.Writer) (*Config, error) {
-	cfg := Config{}
+	cfg := Config{
+		Stdout: stdout,
+		Stderr: stderr,
+	}
 	if err := envconfig.Process("plugin", &cfg); err != nil {
 		return nil, err
 	}
@@ -54,5 +62,16 @@ func NewConfig() (*Config, error) {
 		}
 	}
 
+	if cfg.Debug && cfg.Stderr != nil {
+		cfg.logDebug()
+	}
+
 	return &cfg, nil
 }
+
+func (cfg Config) logDebug() {
+	if cfg.KubeToken != "" {
+		cfg.KubeToken = "(redacted)"
+	}
+	fmt.Fprintf(cfg.Stderr, "Generated config: %+v\n", cfg)
+}

internal/helm/config_test.go

@@ -3,6 +3,7 @@ package helm
 import (
 	"github.com/stretchr/testify/suite"
 	"os"
+	"strings"
 	"testing"
 )
 
@@ -27,7 +28,7 @@ func (suite *ConfigTestSuite) TestNewConfigWithPluginPrefix() {
 	suite.setenv("PLUGIN_UPDATE_DEPENDENCIES", "true")
 	suite.setenv("PLUGIN_DEBUG", "true")
 
-	cfg, err := NewConfig()
+	cfg, err := NewConfig(&strings.Builder{}, &strings.Builder{})
 	suite.Require().NoError(err)
 
 	suite.Equal("execute order 66", cfg.Command)
@@ -45,7 +46,7 @@ func (suite *ConfigTestSuite) TestNewConfigWithNoPrefix() {
 	suite.setenv("UPDATE_DEPENDENCIES", "true")
 	suite.setenv("DEBUG", "true")
 
-	cfg, err := NewConfig()
+	cfg, err := NewConfig(&strings.Builder{}, &strings.Builder{})
 	suite.Require().NoError(err)
 
 	suite.Equal("execute order 66", cfg.Command)
@@ -60,7 +61,7 @@ func (suite *ConfigTestSuite) TestNewConfigWithConfigurablePrefix() {
 	suite.setenv("PLUGIN_PREFIX", "prix_fixe")
 	suite.setenv("PRIX_FIXE_API_SERVER", "your waiter this evening")
 
-	cfg, err := NewConfig()
+	cfg, err := NewConfig(&strings.Builder{}, &strings.Builder{})
 	suite.Require().NoError(err)
 
 	suite.Equal("prix_fixe", cfg.Prefix)
@@ -72,7 +73,7 @@ func (suite *ConfigTestSuite) TestPrefixSettingDoesNotAffectPluginPrefix() {
 	suite.setenv("PLUGIN_HELM_COMMAND", "wake me up")
 	suite.setenv("IXFREP_PLUGIN_HELM_COMMAND", "send me to sleep inside")
 
-	cfg, err := NewConfig()
+	cfg, err := NewConfig(&strings.Builder{}, &strings.Builder{})
 	suite.Require().NoError(err)
 
 	suite.Equal("wake me up", cfg.Command)
@@ -84,7 +85,7 @@ func (suite *ConfigTestSuite) TestPrefixSettingMustHavePluginPrefix() {
 	suite.setenv("HELM_COMMAND", "gimme more")
 	suite.setenv("REFPIX_HELM_COMMAND", "gimme less")
 
-	cfg, err := NewConfig()
+	cfg, err := NewConfig(&strings.Builder{}, &strings.Builder{})
 	suite.Require().NoError(err)
 
 	suite.Equal("gimme more", cfg.Command)
@@ -98,13 +99,52 @@ func (suite *ConfigTestSuite) TestNewConfigWithConflictingVariables() {
 	suite.setenv("TIMEOUT", "5m0s")
 	suite.setenv("PROD_TIMEOUT", "2m30s") // values from prefixed env vars override those from non-prefixed ones
 
-	cfg, err := NewConfig()
+	cfg, err := NewConfig(&strings.Builder{}, &strings.Builder{})
 	suite.Require().NoError(err)
 
 	suite.Equal("defend the jedi", cfg.Command)
 	suite.Equal("2m30s", cfg.Timeout)
 }
 
+func (suite *ConfigTestSuite) TestNewConfigSetsWriters() {
+	stdout := &strings.Builder{}
+	stderr := &strings.Builder{}
+	cfg, err := NewConfig(stdout, stderr)
+	suite.Require().NoError(err)
+
+	suite.Equal(stdout, cfg.Stdout)
+	suite.Equal(stderr, cfg.Stderr)
+}
+
+func (suite *ConfigTestSuite) TestLogDebug() {
+	suite.setenv("DEBUG", "true")
+	suite.setenv("HELM_COMMAND", "upgrade")
+
+	stderr := strings.Builder{}
+	stdout := strings.Builder{}
+	_, err := NewConfig(&stdout, &stderr)
+	suite.Require().NoError(err)
+
+	suite.Equal("", stdout.String())
+
+	suite.Regexp(`^Generated config: \{Command:upgrade.*\}`, stderr.String())
+}
+
+func (suite *ConfigTestSuite) TestLogDebugCensorsKubeToken() {
+	stderr := &strings.Builder{}
+	kubeToken := "I'm shy! Don't put me in your build logs!"
+	cfg := Config{
+		Debug:     true,
+		KubeToken: kubeToken,
+		Stderr:    stderr,
+	}
+
+	cfg.logDebug()
+
+	suite.Contains(stderr.String(), "KubeToken:(redacted)")
+	suite.Equal(kubeToken, cfg.KubeToken) // The actual config value should be left unchanged
+}
+
 func (suite *ConfigTestSuite) setenv(key, val string) {
 	orig, ok := os.LookupEnv(key)
 	if ok {

internal/helm/plan.go

@@ -34,8 +34,8 @@ func NewPlan(cfg Config) (*Plan, error) {
 			StringValues: cfg.StringValues,
 			ValuesFiles:  cfg.ValuesFiles,
 			Namespace:    cfg.Namespace,
-			Stdout:       os.Stdout,
+			Stdout:       cfg.Stdout,
-			Stderr:       os.Stderr,
+			Stderr:       cfg.Stderr,
 		},
 	}
 
@@ -83,7 +83,7 @@ func determineSteps(cfg Config) *func(Config) []Step {
 func (p *Plan) Execute() error {
 	for i, step := range p.steps {
 		if p.cfg.Debug {
-			fmt.Fprintf(os.Stderr, "calling %T.Execute (step %d)\n", step, i)
+			fmt.Fprintf(p.cfg.Stderr, "calling %T.Execute (step %d)\n", step, i)
 		}
 
 		if err := step.Execute(p.runCfg); err != nil {

internal/helm/plan_test.go

@@ -4,7 +4,7 @@ import (
 	"fmt"
 	"github.com/golang/mock/gomock"
 	"github.com/stretchr/testify/suite"
-	"os"
+	"strings"
 	"testing"
 
 	"github.com/pelotech/drone-helm3/internal/run"
@@ -29,6 +29,8 @@ func (suite *PlanTestSuite) TestNewPlan() {
 	}
 	defer func() { help = origHelp }()
 
+	stdout := strings.Builder{}
+	stderr := strings.Builder{}
 	cfg := Config{
 		Command:      "help",
 		Debug:        false,
@@ -36,6 +38,8 @@ func (suite *PlanTestSuite) TestNewPlan() {
 		StringValues: "tensile_strength,flexibility",
 		ValuesFiles:  []string{"/root/price_inventory.yml"},
 		Namespace:    "outer",
+		Stdout:       &stdout,
+		Stderr:       &stderr,
 	}
 
 	runCfg := run.Config{
@@ -44,8 +48,8 @@ func (suite *PlanTestSuite) TestNewPlan() {
 		StringValues: "tensile_strength,flexibility",
 		ValuesFiles:  []string{"/root/price_inventory.yml"},
 		Namespace:    "outer",
-		Stdout:       os.Stdout,
+		Stdout:       &stdout,
-		Stderr:       os.Stderr,
+		Stderr:       &stderr,
 	}
 
 	stepOne.EXPECT().