Porter debug (#1225)

* Fix porter-debug parameter wiring

Ensure that --debug sets PORTER_DEBUG bundle parameter at runtime
when a bundle is executed.

* Wire up --debug to kubernetes mixin debug context

Use this to print commands run by the mixin in debug mode

* Improve detection of PORTER_DEBUG at runtime

The old code worked but only because Porter was helping by not setting PORTER_DEBUG
when it was false.

pkg/context/context.go

@@ -6,6 +6,7 @@ import (
 	"os"
 	"os/exec"
 	"path/filepath"
+	"strconv"
 	"strings"
 
 	"github.com/pkg/errors"
@@ -68,17 +69,19 @@ func (cw *CensoredWriter) Write(b []byte) (int, error) {
 }
 
 func New() *Context {
-	// Default to respecting the PORTER_DEBUG env variable, the cli will override if --debug is set otherwise
-	_, debug := os.LookupEnv("PORTER_DEBUG")
-
-	return &Context{
-		Debug:      debug,
+	c := &Context{
 		FileSystem: &afero.Afero{Fs: afero.NewOsFs()},
 		In:         os.Stdin,
 		Out:        NewCensoredWriter(os.Stdout),
 		Err:        NewCensoredWriter(os.Stderr),
 		NewCommand: exec.Command,
 	}
+
+	// Default to respecting the PORTER_DEBUG env variable, the cli will override if --debug is set otherwise
+	debug, _ := strconv.ParseBool(os.Getenv("PORTER_DEBUG"))
+	c.Debug = debug
+
+	return c
 }
 
 func (c *Context) CopyDirectory(srcDir, destDir string, includeBaseDir bool) error {

pkg/context/context_test.go

@@ -0,0 +1,37 @@
+package context
+
+import (
+	"os"
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+)
+
+func TestNew_Debug(t *testing.T) {
+	t.Run("porter_debug unset", func(t *testing.T) {
+		os.Unsetenv("PORTER_DEBUG")
+
+		c := New()
+		assert.False(t, c.Debug, "debug should be false when the env var is not present")
+	})
+
+	t.Run("porter_debug false", func(t *testing.T) {
+		defer os.Unsetenv("PORTER_DEBUG")
+		os.Setenv("PORTER_DEBUG", "false")
+		c := New()
+		assert.False(t, c.Debug, "debug should be false when the env var is set to 'false'")
+	})
+
+	t.Run("porter_debug invalid", func(t *testing.T) {
+		defer os.Unsetenv("PORTER_DEBUG")
+		os.Setenv("PORTER_DEBUG", "blorp")
+		c := New()
+		assert.False(t, c.Debug, "debug should be false when the env var is not a bool")
+	})
+
+	t.Run("porter_debug true", func(t *testing.T) {
+		os.Setenv("PORTER_DEBUG", "true")
+		c := New()
+		assert.True(t, c.Debug, "debug should be true when the env var is 'true'")
+	})
+}

pkg/exec/builder/execute.go

@@ -92,7 +92,7 @@ func ExecuteStep(cxt *context.Context, step ExecutableStep) (string, error) {
 	// Preallocate an array big enough to hold all arguments
 	arguments := step.GetArguments()
 	flags := step.GetFlags()
-	args := make([]string, len(arguments), 1+len(arguments)+len(flags)*2 + len(suffixArgs))
+	args := make([]string, len(arguments), 1+len(arguments)+len(flags)*2+len(suffixArgs))
 
 	// Copy all prefix arguments
 	copy(args, arguments)
@@ -133,7 +133,7 @@ func ExecuteStep(cxt *context.Context, step ExecutableStep) (string, error) {
 		cmd.Stdout = io.MultiWriter(cxt.Out, output)
 		cmd.Stderr = cxt.Err
 		if cxt.Debug {
-			fmt.Fprintln(cxt.Out, prettyCmd)
+			fmt.Fprintln(cxt.Err, prettyCmd)
 		}
 	}
 

pkg/kubernetes/kubernetes.go

@@ -100,9 +100,14 @@ func (m *Mixin) getOutput(resourceType, resourceName, namespace, jsonPath string
 	}
 	cmd := m.NewCommand("kubectl", args...)
 	cmd.Stderr = m.Err
+
+	prettyCmd := fmt.Sprintf("%s%s", cmd.Dir, strings.Join(cmd.Args, " "))
+	if m.Debug {
+		fmt.Fprintln(m.Err, prettyCmd)
+	}
 	out, err := cmd.Output()
+
 	if err != nil {
-		prettyCmd := fmt.Sprintf("%s%s", cmd.Dir, strings.Join(cmd.Args, " "))
 		return nil, errors.Wrap(err, fmt.Sprintf("couldn't run command %s", prettyCmd))
 	}
 	return out, nil

pkg/porter/cnab.go

@@ -229,7 +229,7 @@ func (o *sharedOptions) validateParams(p *Porter) error {
 		return err
 	}
 
-	o.combinedParameters = o.combineParameters()
+	o.combinedParameters = o.combineParameters(p.Context)
 
 	return nil
 }
@@ -260,7 +260,7 @@ func (o *sharedOptions) parseParamSets(p *Porter) error {
 // The params set on the command line take precedence over the params set in
 // parameter set files
 // Anything set multiple times, is decided by "last one set wins"
-func (o *sharedOptions) combineParameters() map[string]string {
+func (o *sharedOptions) combineParameters(c *context.Context) map[string]string {
 	final := make(map[string]string)
 
 	for k, v := range o.parsedParamSets {
@@ -271,6 +271,13 @@ func (o *sharedOptions) combineParameters() map[string]string {
 		final[k] = v
 	}
 
+	//
+	// Default the porter-debug param to --debug
+	//
+	if c.Debug {
+		final["porter-debug"] = "true"
+	}
+
 	return final
 }
 

pkg/porter/cnab_test.go

@@ -163,10 +163,13 @@ func TestParseParamSets_FileType(t *testing.T) {
 }
 
 func TestCombineParameters(t *testing.T) {
+	c := context.NewTestContext(t)
+	c.Debug = false
+
 	t.Run("no override present, no parameter set present", func(t *testing.T) {
 		opts := sharedOptions{}
 
-		params := opts.combineParameters()
+		params := opts.combineParameters(c.Context)
 		require.Equal(t, map[string]string{}, params,
 			"expected combined params to be empty")
 	})
@@ -178,7 +181,7 @@ func TestCombineParameters(t *testing.T) {
 			},
 		}
 
-		params := opts.combineParameters()
+		params := opts.combineParameters(c.Context)
 		require.Equal(t, "foo_cli_override", params["foo"],
 			"expected param 'foo' to have override value")
 	})
@@ -190,7 +193,7 @@ func TestCombineParameters(t *testing.T) {
 			},
 		}
 
-		params := opts.combineParameters()
+		params := opts.combineParameters(c.Context)
 		require.Equal(t, "foo_via_paramset", params["foo"],
 			"expected param 'foo' to have parameter set value")
 	})
@@ -205,8 +208,16 @@ func TestCombineParameters(t *testing.T) {
 			},
 		}
 
-		params := opts.combineParameters()
+		params := opts.combineParameters(c.Context)
 		require.Equal(t, "foo_cli_override", params["foo"],
 			"expected param 'foo' to have override value, which has precedence over the parameter set value")
 	})
+
+	t.Run("debug on", func(t *testing.T) {
+		var opts sharedOptions
+		debugContext := context.NewTestContext(t)
+		debugContext.Debug = true
+		params := opts.combineParameters(debugContext.Context)
+		require.Equal(t, "true", params["porter-debug"], "porter-debug should be set to true when p.Debug is true")
+	})
 }

pkg/porter/install_test.go

@@ -58,27 +58,6 @@ func TestPorter_applyDefaultOptions_NoManifest(t *testing.T) {
 	assert.Equal(t, &manifest.Manifest{}, p.Manifest, "p.Manifest should be initialized to an empty manifest")
 }
 
-func TestPorter_applyDefaultOptions_DebugOff(t *testing.T) {
-	p := NewTestPorter(t)
-	p.TestConfig.SetupPorterHome()
-	err := p.Create()
-	require.NoError(t, err)
-
-	opts := &InstallOptions{}
-	opts.File = "porter.yaml"
-	err = opts.Validate([]string{}, p.Porter)
-	require.NoError(t, err)
-
-	p.Debug = false
-	err = p.applyDefaultOptions(&opts.sharedOptions)
-	require.NoError(t, err)
-
-	assert.Equal(t, p.Manifest.Name, opts.Name)
-
-	_, set := opts.parsedParams["porter-debug"]
-	assert.False(t, set)
-}
-
 func TestPorter_applyDefaultOptions_ParamSet(t *testing.T) {
 	p := NewTestPorter(t)
 	p.TestConfig.SetupPorterHome()
@@ -91,13 +70,9 @@ func TestPorter_applyDefaultOptions_ParamSet(t *testing.T) {
 	err = opts.Validate([]string{}, p.Porter)
 	require.NoError(t, err)
 
-	p.Debug = true
-	err = p.applyDefaultOptions(&opts.sharedOptions)
-	require.NoError(t, err)
-
-	debug, set := opts.parsedParams["porter-debug"]
+	debug, set := opts.combinedParameters["porter-debug"]
 	assert.True(t, set)
-	assert.Equal(t, "false", debug)
+	assert.Equal(t, "true", debug)
 }
 
 func TestInstallOptions_validateParams(t *testing.T) {

pkg/porter/lifecycle_test.go

@@ -149,8 +149,9 @@ func TestBundleLifecycleOpts_ToActionArgs(t *testing.T) {
 		args := opts.ToActionArgs(deps)
 
 		expectedParams := map[string]string{
-			"PARAM1": "VALUE1",
-			"PARAM2": "VALUE2",
+			"PARAM1":       "VALUE1",
+			"PARAM2":       "VALUE2",
+			"porter-debug": "true",
 		}
 
 		assert.Equal(t, opts.AllowAccessToDockerHost, args.AllowDockerHostAccess, "AllowDockerHostAccess not populated correctly")

pkg/porter/options.go

@@ -28,15 +28,5 @@ func (p *Porter) applyDefaultOptions(opts *sharedOptions) error {
 		opts.Name = p.Manifest.Name
 	}
 
-	//
-	// Default the porter-debug param to --debug
-	//
-	if _, set := opts.combinedParameters["porter-debug"]; !set && p.Debug {
-		if opts.combinedParameters == nil {
-			opts.combinedParameters = make(map[string]string)
-		}
-		opts.combinedParameters["porter-debug"] = "true"
-	}
-
 	return nil
 }