exec: fix debug handler

.github/workflows/gate-tests.yml

@@ -13,7 +13,7 @@ jobs:
   test:
     strategy:
       matrix:
-        go-version: [1.19.x, 1.20.x]
+        go: ['1.19', '1.20', '1.21']
         os: [ubuntu-latest, macos-latest, windows-latest]
     runs-on: ${{ matrix.os }}
     steps:
@@ -24,11 +24,16 @@ jobs:
          disable-sudo: true
          allowed-endpoints: >
            github.com:443
+           api.github.com:443
+           proxy.github.com:443
+           raw.githubusercontent.com:443
+           objects.githubusercontent.com:443
            proxy.golang.org:443
      - name: checkout code
        uses: actions/checkout@c85c95e3d7251135ab7dc9ce3241c5835cc595a9 # v3.5.3
      - name: setup go
-       uses: actions/setup-go@fac708d6674e30b6ba41289acaab6d4b75aa0753 # v4.0.1
+       uses: actions/setup-go@cdcb36043654635271a94b9a6d1392de5bb323a7 # v5.0.1
        with:
          go-version: ${{ matrix.go }}
+         check-latest: true
      - run: go test -v ./...

README.md

@@ -402,7 +402,7 @@ tests:
      headers:
       - Location
  - name: look up that created book
-   GET: $LOCATION
+   GET: $$LOCATION
    response:
      status: 200
      json:

debug/print.go

@@ -23,13 +23,10 @@ func Printf(
 ) {
 	t.Helper()
 	writers := gdtcontext.Debug(ctx)
-	if writers == nil {
-		return
-	}
-	t.Logf(format, args...)
 	if len(writers) == 0 {
 		return
 	}
+	t.Logf(format, args...)
 
 	if !strings.HasPrefix(format, "[gdt] ") {
 		format = "[gdt] " + t.Name() + " " + format
@@ -50,14 +47,11 @@ func Println(
 ) {
 	t.Helper()
 	writers := gdtcontext.Debug(ctx)
-	if writers == nil {
+	if len(writers) == 0 {
 		return
 	}
 	// NOTE(jaypipes): T.Logf() automatically adds newlines...
 	t.Logf(format, args...)
-	if len(writers) == 0 {
-		return
-	}
 
 	if !strings.HasPrefix(format, "[gdt] ") {
 		format = "[gdt] " + t.Name() + " " + format

plugin/exec/action.go

@@ -79,9 +79,15 @@ func (a *Action) Do(
 	}
 	if outbuf != nil {
 		outbuf.ReadFrom(outpipe)
+		if outbuf.Len() > 0 {
+			debug.Println(ctx, t, "exec: stdout: %s", outbuf.String())
+		}
 	}
 	if errbuf != nil {
 		errbuf.ReadFrom(errpipe)
+		if errbuf.Len() > 0 {
+			debug.Println(ctx, t, "exec: stderr: %s", errbuf.String())
+		}
 	}
 
 	err = cmd.Wait()

plugin/exec/eval.go

@@ -42,16 +42,6 @@ func (s *Spec) Eval(ctx context.Context, t *testing.T) *result.Result {
 				if err != nil {
 					debug.Println(ctx, t, "error in on.fail.exec: %s", err)
 				}
-				if outbuf.Len() > 0 {
-					debug.Println(
-						ctx, t, "on.fail.exec: stdout: %s", outbuf.String(),
-					)
-				}
-				if errbuf.Len() > 0 {
-					debug.Println(
-						ctx, t, "on.fail.exec: stderr: %s", errbuf.String(),
-					)
-				}
 			}
 		}
 	}

plugin/exec/eval_test.go

@@ -199,7 +199,9 @@ func TestDebugWriter(t *testing.T) {
 	require.NotEqual(b.Len(), 0)
 	debugout := b.String()
 	require.Contains(debugout, "exec: echo [cat]")
+	require.Contains(debugout, "exec: stdout: cat")
 	require.Contains(debugout, "exec: sh [-c echo cat 1>&2]")
+	require.Contains(debugout, "exec: stderr: cat")
 }
 
 func TestWait(t *testing.T) {

scenario/run_test.go

@@ -5,6 +5,8 @@
 package scenario_test
 
 import (
+	"bufio"
+	"bytes"
 	"context"
 	"os"
 	"path/filepath"
@@ -72,16 +74,21 @@ func TestDebugFlushing(t *testing.T) {
 	f, err := os.Open(fp)
 	require.Nil(err)
 
-	ctx := gdtcontext.New(
-		gdtcontext.WithDebug(),
-	)
+	var b bytes.Buffer
+	w := bufio.NewWriter(&b)
+	ctx := gdtcontext.New(gdtcontext.WithDebug(w))
 
 	s, err := scenario.FromReader(f, scenario.WithPath(fp))
 	require.Nil(err)
 	require.NotNil(s)
 
 	err = s.Run(ctx, t)
 	require.Nil(err)
+	require.False(t.Failed())
+	w.Flush()
+	require.NotEqual(b.Len(), 0)
+	debugout := b.String()
+	require.Contains(debugout, "TestDebugFlushing/foo-debug-wait-flush wait: 250ms before")
 }
 
 func TestTimeoutCascade(t *testing.T) {