plumb through combined stdout/stderr to diagnostics (#179)

previous:

```
╷
│ Error: failed to test feature: foo
│
│   with imagetest_feature.foo,
│   on main.tf line 24, in resource "imagetest_feature" "foo":
│   24: resource "imagetest_feature" "foo" {
│
│ assessment step 'Sample' failed: running step: command exited with non-zero exit code: 3
│
│ No resources found
│ * URL rejected: Port number was not a decimal number between 0 and 65535
│ * closing connection #-1
│ curl: (3) URL rejected: Port number was not a decimal number between 0 and 65535
│ : No resources found
│ * URL rejected: Port number was not a decimal number between 0 and 65535
│ * closing connection #-1
│ curl: (3) URL rejected: Port number was not a decimal number between 0 and 65535
│
╵
```

new:

```
╷
│ Error: failed to test feature: foo
│
│   with imagetest_feature.foo,
│   on main.tf line 24, in resource "imagetest_feature" "foo":
│   24: resource "imagetest_feature" "foo" {
│
│ assessment step 'Sample' failed:
│ Error executing command (exit code 3)
│
│ Command:
│       apk add curl jq
│
│       kubectl get po -A
│
│       curl -v --fail http://notarealzfhost:81234
│
│ Output:
│       fetch https://packages.wolfi.dev/os/aarch64/APKINDEX.tar.gz
│       (1/3) Installing curl (8.9.1-r3)
│       (2/3) Installing oniguruma (6.9.9-r3)
│       (3/3) Installing jq (1.7.1-r2)
│       OK: 118 MiB in 32 packages
│       No resources found
│       * URL rejected: Port number was not a decimal number between 0 and 65535
│       * closing connection #-1
│       curl: (3) URL rejected: Port number was not a decimal number between 0 and 65535
│
```

This also plumbs through stdout/stderr better to `TF_LOG=info` surfaced
log lines

internal/docker/docker.go

@@ -337,16 +337,16 @@ func (r *Response) Run(ctx context.Context, cmd harness.Command) error {
 		return fmt.Errorf("starting exec: %w", err)
 	}
 
-	var stdout, stderr bytes.Buffer
-	var stdoutw, stderrw io.Writer
-	stdoutw, stderrw = &stdout, &stderr
+	var stdout, stderr, stdall bytes.Buffer
+	var stdoutw, stderrw, stdallw io.Writer
+	stdoutw, stderrw, stdallw = &stdout, &stderr, &stdall
 
 	if cmd.Stdout != nil {
-		stdoutw = io.MultiWriter(stdoutw, cmd.Stdout)
+		stdoutw = io.MultiWriter(stdoutw, stdallw, cmd.Stdout)
 	}
 
 	if cmd.Stderr != nil {
-		stderrw = io.MultiWriter(stderrw, cmd.Stderr)
+		stderrw = io.MultiWriter(stderrw, stdallw, cmd.Stderr)
 	}
 
 	done := make(chan error, 1)
@@ -371,7 +371,11 @@ func (r *Response) Run(ctx context.Context, cmd harness.Command) error {
 	}
 
 	if exec.ExitCode != 0 {
-		return fmt.Errorf("command exited with non-zero exit code: %d\n\n%s", exec.ExitCode, stderr.String())
+		return &harness.RunError{
+			ExitCode:       exec.ExitCode,
+			CombinedOutput: stdall.String(),
+			Cmd:            cmd.Args,
+		}
 	}
 
 	return nil

internal/features/features.go

@@ -131,7 +131,7 @@ func (f *Feature) Test(ctx context.Context) error {
 	afters := func() {
 		for _, after := range f.afters {
 			if err := after.Fn(ctx); err != nil {
-				collectError(fmt.Errorf("after step '%s' failed: %v", after.Name, err))
+				collectError(fmt.Errorf("after step '%s' failed:\n%v", after.Name, err))
 				// Don't continue if we error
 				break
 			}
@@ -140,15 +140,15 @@ func (f *Feature) Test(ctx context.Context) error {
 
 	for _, before := range f.befores {
 		if err := before.Fn(ctx); err != nil {
-			collectError(fmt.Errorf("before step '%s' failed: %v", before.Name, err))
+			collectError(fmt.Errorf("before step '%s' failed:\n%v", before.Name, err))
 			afters()
 			return collectedError
 		}
 	}
 
 	for _, assessment := range f.assessments {
 		if err := assessment.Fn(ctx); err != nil {
-			collectError(fmt.Errorf("assessment step '%s' failed: %v", assessment.Name, err))
+			collectError(fmt.Errorf("assessment step '%s' failed:\n%v", assessment.Name, err))
 			afters()
 			return collectedError
 		}

internal/features/features_test.go

@@ -70,7 +70,7 @@ func TestFeature(t *testing.T) {
 				}
 			},
 			wantout: "after ",
-			wanterr: "before step 'Before Step' failed: before step error",
+			wanterr: "before step 'Before Step' failed:\nbefore step error",
 		},
 		{
 			name: "ShortCircuitAssessmentFailure",
@@ -100,7 +100,7 @@ func TestFeature(t *testing.T) {
 				}
 			},
 			wantout: "assessment after ",
-			wanterr: "assessment step 'Assessment Step' failed: assessment step error; after step 'After Step 2' failed: after step error",
+			wanterr: "assessment step 'Assessment Step' failed:\nassessment step error; after step 'After Step 2' failed:\nafter step error",
 		},
 		{
 			name: "Retry",
@@ -124,7 +124,7 @@ func TestFeature(t *testing.T) {
 			},
 			wantout: "foo foo foo ",
 			// This will always fail, so just grep on the error message
-			wanterr: "assessment step 'Assessment Step' failed: timed out waiting for the condition",
+			wanterr: "assessment step 'Assessment Step' failed:\ntimed out waiting for the condition",
 		},
 	}
 

internal/harness/harness.go

@@ -25,6 +25,19 @@ func DefaultEntrypoint() []string {
 	return []string{"/bin/sh", "-c"}
 }
 
+type RunError struct {
+	ExitCode int
+	Cmd      string
+	// CombinedOutput is intentional since when something goes wrong, it usually
+	// makes more sense to see the interweaved stdout/stderr since thats how they
+	// appear in a shell.
+	CombinedOutput string
+}
+
+func (e *RunError) Error() string {
+	return fmt.Sprintf("%s\n%s\nexit status %d", e.Cmd, e.CombinedOutput, e.ExitCode)
+}
+
 func DefaultCmd() []string {
 	return []string{"tail -f /dev/null"}
 }

internal/provider/feature_resource.go

@@ -4,6 +4,7 @@ import (
 	"bytes"
 	"context"
 	"fmt"
+	"io"
 	"time"
 
 	"github.com/chainguard-dev/terraform-provider-imagetest/internal/features"
@@ -364,22 +365,39 @@ func (r *FeatureResource) Delete(_ context.Context, _ resource.DeleteRequest, _
 
 func (r *FeatureResource) step(feat *features.Feature, h harness.Harness, data FeatureStepModel, level features.Level) error {
 	fn := features.StepFn(func(ctx context.Context) error {
-		ctx = log.With(ctx, "step_name", data.Name.ValueString())
+		ctx = log.With(ctx,
+			"step_name", data.Name.ValueString(),
+			"cmd", data.Cmd.ValueString(),
+			"feature", data.Name.ValueString(),
+		)
 
-		log.Info(ctx, "running step")
+		// capture a combined output buffer and a stderr buffer. the combined
+		// output is usually easier to reason that just stdout alone, and lets us
+		// return more information on failures.
+		var bufall, buferr bytes.Buffer
 
-		var bufout, buferr bytes.Buffer
 		err := h.Run(ctx, harness.Command{
 			Args:       data.Cmd.ValueString(),
 			WorkingDir: data.Workdir.ValueString(),
-			Stdout:     &bufout,
-			Stderr:     &buferr,
+			Stdout:     &bufall,
+			Stderr:     io.MultiWriter(&buferr, &bufall),
 		})
+
+		ctx = log.With(ctx,
+			"output", bufall.String(),
+		)
+
 		if err != nil {
-			return fmt.Errorf("running step: %w: %s", err, buferr.String())
+			if rerr, ok := err.(*harness.RunError); ok {
+				log.Warn(ctx, "feature step failed with non-zero exit code",
+					"exit_code", rerr.ExitCode,
+					"stderr", buferr.String())
+				return rerr
+			}
+			return fmt.Errorf("running step: %w", err)
 		}
 
-		log.Info(ctx, "step output", "stdout", bufout.String(), "stderr", buferr.String())
+		log.Info(ctx, "ran feature step")
 		return nil
 	})