Information messages should be written to stdout

pkg/build/dockerfile-generator_test.go

@@ -169,7 +169,7 @@ func TestPorter_generateDockerfile(t *testing.T) {
 	require.NoError(t, err)
 
 	// Verify that we logged the dockerfile contents
-	tests.RequireOutputContains(t, c.TestContext.GetError(), string(gotDockerfile), "expected the dockerfile to be printed to the logs")
+	tests.RequireOutputContains(t, c.TestContext.GetOutput(), string(gotDockerfile), "expected the dockerfile to be printed to the logs")
 	test.CompareGoldenFile(t, "testdata/buildkit.Dockerfile", string(gotDockerfile))
 
 	// Verify that we didn't generate a Dockerfile at the root of the bundle dir

pkg/manifest/manifest_test.go

@@ -310,7 +310,7 @@ func TestManifest_Validate_SchemaVersion(t *testing.T) {
 
 		// Check that a warning is printed
 		// We aren't returning an error because we want to give it a chance to work first. Later we may turn this into a hard error after people have had time to migrate.
-		assert.Contains(t, cfg.TestContext.GetError(), invalidVersionErr)
+		assert.Contains(t, cfg.TestContext.GetOutput(), invalidVersionErr)
 	})
 }
 
@@ -549,7 +549,7 @@ func TestSetDefaults(t *testing.T) {
 		err := m.validateMetadata(ctx, cfg.Config)
 		require.NoError(t, err)
 		require.Contains(t,
-			cfg.TestContext.GetError(),
+			cfg.TestContext.GetOutput(),
 			"WARNING: both registry and reference were provided; using the reference value of getporter/org/mybun:v1.2.3 for the bundle reference\n",
 		)
 

pkg/porter/credentials.go

@@ -397,7 +397,7 @@ func (p *Porter) CredentialsApply(ctx context.Context, o ApplyOptions) error {
 		return err
 	}
 
-	span.Infof("Applied %s credential set", creds)
+	fmt.Fprintf(p.Out, "Applied %s credential set\n", creds)
 	return nil
 }
 

pkg/porter/parameters.go

@@ -557,7 +557,7 @@ func (p *Porter) ParametersApply(ctx context.Context, o ApplyOptions) error {
 		return err
 	}
 
-	span.Infof("Applied %s parameter set", params)
+	fmt.Fprintf(p.Out, "Applied %s parameter set\n", params)
 	return nil
 }
 

pkg/porter/reconcile_test.go

@@ -35,7 +35,7 @@ func TestPorter_IsInstallationInSync(t *testing.T) {
 		insync, err := p.IsInstallationInSync(p.RootContext, i, nil, opts)
 		require.NoError(t, err)
 		assert.True(t, insync)
-		assert.Contains(t, p.TestConfig.TestContext.GetError(), "Ignoring because installation.uninstalled is true but the installation doesn't exist yet")
+		assert.Contains(t, p.TestConfig.TestContext.GetOutput(), "Ignoring because installation.uninstalled is true but the installation doesn't exist yet")
 	})
 
 	t.Run("new installation with uninstalled false", func(t *testing.T) {
@@ -51,7 +51,7 @@ func TestPorter_IsInstallationInSync(t *testing.T) {
 		insync, err := p.IsInstallationInSync(p.RootContext, i, nil, opts)
 		require.NoError(t, err)
 		assert.False(t, insync)
-		assert.Contains(t, p.TestConfig.TestContext.GetError(), "Triggering because the installation has not completed successfully yet")
+		assert.Contains(t, p.TestConfig.TestContext.GetOutput(), "Triggering because the installation has not completed successfully yet")
 	})
 
 	t.Run("installed - no changes", func(t *testing.T) {
@@ -104,7 +104,7 @@ func TestPorter_IsInstallationInSync(t *testing.T) {
 		insync, err := p.IsInstallationInSync(p.RootContext, i, &run, upgradeOpts)
 		require.NoError(t, err)
 		assert.False(t, insync)
-		assert.Contains(t, p.TestConfig.TestContext.GetError(), "Triggering because the bundle definition has changed")
+		assert.Contains(t, p.TestConfig.TestContext.GetOutput(), "Triggering because the bundle definition has changed")
 	})
 
 	t.Run("installed - param changed", func(t *testing.T) {
@@ -123,7 +123,7 @@ func TestPorter_IsInstallationInSync(t *testing.T) {
 		insync, err := p.IsInstallationInSync(p.RootContext, i, &run, upgradeOpts)
 		require.NoError(t, err)
 		assert.False(t, insync)
-		assert.Contains(t, p.TestConfig.TestContext.GetError(), "Triggering because the parameters have changed")
+		assert.Contains(t, p.TestConfig.TestContext.GetOutput(), "Triggering because the parameters have changed")
 
 	})
 
@@ -146,7 +146,7 @@ func TestPorter_IsInstallationInSync(t *testing.T) {
 		insync, err := p.IsInstallationInSync(p.RootContext, i, &run, upgradeOpts)
 		require.NoError(t, err)
 		assert.False(t, insync)
-		assert.Contains(t, p.TestConfig.TestContext.GetError(), "Triggering because the credential set names have changed")
+		assert.Contains(t, p.TestConfig.TestContext.GetOutput(), "Triggering because the credential set names have changed")
 
 	})
 
@@ -165,7 +165,7 @@ func TestPorter_IsInstallationInSync(t *testing.T) {
 		insync, err := p.IsInstallationInSync(p.RootContext, i, nil, opts)
 		require.NoError(t, err)
 		assert.False(t, insync)
-		assert.Contains(t, p.TestConfig.TestContext.GetError(), "Triggering because installation.uninstalled is true")
+		assert.Contains(t, p.TestConfig.TestContext.GetOutput(), "Triggering because installation.uninstalled is true")
 	})
 
 	t.Run("uninstalled: uninstalled set to back to false", func(t *testing.T) {
@@ -185,6 +185,6 @@ func TestPorter_IsInstallationInSync(t *testing.T) {
 		insync, err := p.IsInstallationInSync(p.RootContext, i, nil, NewUninstallOptions())
 		require.NoError(t, err)
 		assert.True(t, insync)
-		assert.Contains(t, p.TestConfig.TestContext.GetError(), "Ignoring because the installation is uninstalled")
+		assert.Contains(t, p.TestConfig.TestContext.GetOutput(), "Ignoring because the installation is uninstalled")
 	})
 }

pkg/portercontext/context.go

@@ -213,10 +213,18 @@ func (c *Context) configureLoggingWith(ctx context.Context, baseLogger zapcore.C
 func (c *Context) makeConsoleLogger() zapcore.Core {
 	encoding := c.makeLogEncoding()
 
+	stdout := c.Out
 	stderr := c.Err
+	if f, ok := stdout.(*os.File); ok {
+		if isatty.IsTerminal(f.Fd()) {
+			stdout = colorable.NewColorable(f)
+			encoding.EncodeLevel = zapcore.LowercaseColorLevelEncoder
+		}
+	}
+
 	if f, ok := stderr.(*os.File); ok {
 		if isatty.IsTerminal(f.Fd()) {
-			stderr = colorable.NewColorable(f)
+			stdout = colorable.NewColorable(f)
 			encoding.EncodeLevel = zapcore.LowercaseColorLevelEncoder
 		}
 	}
@@ -227,7 +235,20 @@ func (c *Context) makeConsoleLogger() zapcore.Core {
 		encoding.LevelKey = ""
 	}
 	consoleEncoder := zapcore.NewConsoleEncoder(encoding)
-	return zapcore.NewCore(consoleEncoder, zapcore.AddSync(stderr), c.logCfg.Verbosity)
+
+	isInformational := func(lvl zapcore.Level) bool {
+		return lvl < zapcore.ErrorLevel && lvl >= c.logCfg.Verbosity
+	}
+	stdoutEnabler := zap.LevelEnablerFunc(isInformational)
+	stderrEnabler := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool {
+		return !isInformational(lvl)
+	})
+
+	return zapcore.NewTee(
+		zapcore.NewCore(consoleEncoder, zapcore.AddSync(stdout), stdoutEnabler),
+		zapcore.NewCore(consoleEncoder, zapcore.AddSync(stderr), stderrEnabler),
+	)
+	// return zapcore.NewCore(consoleEncoder, zapcore.AddSync(stdout), c.logCfg.Verbosity)
 }
 
 func (c *Context) configureFileLog(dir string) (zapcore.Core, error) {

pkg/portercontext/context_test.go

@@ -58,8 +58,8 @@ func TestContext_LogToFile(t *testing.T) {
 
 	// Compare the human readable logs sent to stderr
 	if runtime.GOOS == "windows" {
-		c.CompareGoldenFile("testdata/expected-output-windows.txt", c.GetError())
+		c.CompareGoldenFile("testdata/expected-output-windows.txt", c.GetAllLogs())
 	} else {
-		c.CompareGoldenFile("testdata/expected-output.txt", c.GetError())
+		c.CompareGoldenFile("testdata/expected-output.txt", c.GetAllLogs())
 	}
 }

pkg/portercontext/helpers.go

@@ -28,6 +28,7 @@ type TestContext struct {
 	cleanupDirs []string
 	capturedErr *bytes.Buffer
 	capturedOut *bytes.Buffer
+	captureLogs *bytes.Buffer
 	T           *testing.T
 }
 
@@ -37,10 +38,11 @@ type TestContext struct {
 func NewTestContext(t *testing.T) *TestContext {
 	// Provide a way for tests to provide and capture stdin and stdout
 	// Copy output to the test log simultaneously, use go test -v to see the output
+	logs := &bytes.Buffer{}
 	err := &bytes.Buffer{}
-	aggErr := io.MultiWriter(err, test.Logger{T: t})
+	aggErr := io.MultiWriter(err, test.Logger{T: t}, logs)
 	out := &bytes.Buffer{}
-	aggOut := io.MultiWriter(out, test.Logger{T: t})
+	aggOut := io.MultiWriter(out, test.Logger{T: t}, logs)
 
 	innerContext := New()
 	innerContext.correlationId = "0"
@@ -64,6 +66,7 @@ func NewTestContext(t *testing.T) *TestContext {
 		Context:     innerContext,
 		capturedOut: out,
 		capturedErr: err,
+		captureLogs: logs,
 		T:           t,
 	}
 
@@ -266,6 +269,11 @@ func (c *TestContext) GetError() string {
 	return c.capturedErr.String()
 }
 
+// GetAllLogs returns all text logged both on stdout and stderr
+func (c *TestContext) GetAllLogs() string {
+	return c.captureLogs.String()
+}
+
 func (c *TestContext) ClearOutputs() {
 	c.capturedOut.Truncate(0)
 	c.capturedErr.Truncate(0)

tests/smoke/desiredstate_test.go

@@ -64,8 +64,8 @@ func TestDesiredState(t *testing.T) {
 	// This also tests out that --allow-docker-host-access is being defaulted properly from the Porter config file
 	output, stderr, err := test.RunPorter("installation", "apply", "mybuns.yaml", "--namespace", "operator")
 	require.NoError(t, err)
-	require.Contains(t, stderr, "The installation is out-of-sync, running the install action")
-	require.Contains(t, stderr, "Triggering because the installation has not completed successfully yet")
+	require.Contains(t, output, "The installation is out-of-sync, running the install action")
+	require.Contains(t, output, "Triggering because the installation has not completed successfully yet")
 	installation := test.RequireInstallationExists("operator", "mybuns")
 	require.Equal(t, "succeeded", installation.Status.ResultStatus)
 

tests/smoke/hello_test.go

@@ -29,7 +29,7 @@ func TestHelloBundle(t *testing.T) {
 	// This also does a quick regression test to validate that we can change the verbosity to a different value than what is in the config file and have it respected
 	_, output := test.RequirePorter("plugins", "install", "-f", "plugins.yaml", "--verbosity=info")
 	require.Contains(t, output, "installed azure plugin", "expected to see plugin successfully installed")
-	require.NotContainsf(t, output, "Downloading https://cdn.porter.sh/plugins/atom.xml", "Debug information should not have been printed because verbosity is set to info")
+	require.Containsf(t, output, "Downloading https://cdn.porter.sh/plugins/atom.xml", "Debug information should be printed because verbosity is set to info")
 
 	// Run a stateless action before we install and make sure nothing is persisted
 	_, output = test.RequirePorter("invoke", testdata.MyBuns, "--action=dry-run", "--reference", testdata.MyBunsRef, "-c=mybuns")

tests/tester/helpers.go

@@ -55,7 +55,7 @@ func (t Tester) MakeTestBundle(name string, ref string) {
 }
 
 func (t Tester) ShowInstallation(namespace string, name string) (porter.DisplayInstallation, error) {
-	stdout, _, err := t.RunPorter("show", name, "--namespace", namespace, "--output=json")
+	stdout, _, err := t.RunPorter("show", name, "--namespace", namespace, "--output=json", "--verbosity=info")
 	if err != nil {
 		return porter.DisplayInstallation{}, err
 	}
@@ -91,6 +91,7 @@ func (t Tester) ListInstallations(allNamespaces bool, namespace string, name str
 		"list",
 		"--output=json",
 		"--name", name,
+		"--verbosity=info",
 	}
 	if allNamespaces {
 		args = append(args, "--all-namespaces")