fix debug handler and change assertions.OK()

README.md

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

assertion/json/json.go

@@ -5,6 +5,7 @@
 package json
 
 import (
+	"context"
 	"encoding/json"
 	"fmt"
 	"os"
@@ -170,7 +171,7 @@ func (a *assertions) Failures() []error {
 }
 
 // OK returns true if all contained assertions pass successfully
-func (a *assertions) OK() bool {
+func (a *assertions) OK(ctx context.Context) bool {
 	if a == nil || a.exp == nil {
 		return true
 	}

assertion/json/json_test.go

@@ -5,6 +5,7 @@
 package json_test
 
 import (
+	"context"
 	"io/ioutil"
 	"path/filepath"
 	"testing"
@@ -98,6 +99,7 @@ func content() []byte {
 func TestLength(t *testing.T) {
 	require := require.New(t)
 
+	ctx := context.TODO()
 	c := content()
 	expLen := len(c)
 
@@ -106,12 +108,12 @@ func TestLength(t *testing.T) {
 	}
 
 	a := gdtjson.New(&exp, c)
-	require.True(a.OK())
+	require.True(a.OK(ctx))
 	require.Empty(a.Failures())
 
 	expLen = 0
 	a = gdtjson.New(&exp, c)
-	require.False(a.OK())
+	require.False(a.OK(ctx))
 	failures := a.Failures()
 	require.Len(failures, 1)
 	require.ErrorIs(failures[0], gdterrors.ErrNotEqual)
@@ -120,6 +122,7 @@ func TestLength(t *testing.T) {
 func TestJSONUnmarshalError(t *testing.T) {
 	require := require.New(t)
 
+	ctx := context.TODO()
 	c := []byte(`not { value } json`)
 
 	exp := gdtjson.Expect{
@@ -129,7 +132,7 @@ func TestJSONUnmarshalError(t *testing.T) {
 	}
 
 	a := gdtjson.New(&exp, c)
-	require.False(a.OK())
+	require.False(a.OK(ctx))
 	failures := a.Failures()
 	require.Len(failures, 1)
 	require.ErrorIs(failures[0], gdtjson.ErrJSONUnmarshalError)
@@ -138,6 +141,7 @@ func TestJSONUnmarshalError(t *testing.T) {
 func TestJSONPathError(t *testing.T) {
 	require := require.New(t)
 
+	ctx := context.TODO()
 	c := content()
 
 	exp := gdtjson.Expect{
@@ -147,7 +151,7 @@ func TestJSONPathError(t *testing.T) {
 	}
 
 	a := gdtjson.New(&exp, c)
-	require.False(a.OK())
+	require.False(a.OK(ctx))
 	failures := a.Failures()
 	require.Len(failures, 1)
 	require.ErrorIs(failures[0], gdtjson.ErrJSONPathNotFound)
@@ -156,6 +160,7 @@ func TestJSONPathError(t *testing.T) {
 func TestJSONPathConversionError(t *testing.T) {
 	require := require.New(t)
 
+	ctx := context.TODO()
 	c := content()
 
 	exp := gdtjson.Expect{
@@ -165,7 +170,7 @@ func TestJSONPathConversionError(t *testing.T) {
 	}
 
 	a := gdtjson.New(&exp, c)
-	require.False(a.OK())
+	require.False(a.OK(ctx))
 	failures := a.Failures()
 	require.Len(failures, 1)
 	require.ErrorIs(failures[0], gdtjson.ErrJSONPathConversionError)
@@ -174,6 +179,7 @@ func TestJSONPathConversionError(t *testing.T) {
 func TestJSONPathNotEqual(t *testing.T) {
 	require := require.New(t)
 
+	ctx := context.TODO()
 	c := content()
 
 	exp := gdtjson.Expect{
@@ -183,7 +189,7 @@ func TestJSONPathNotEqual(t *testing.T) {
 	}
 
 	a := gdtjson.New(&exp, c)
-	require.True(a.OK())
+	require.True(a.OK(ctx))
 	require.Empty(a.Failures())
 
 	exp = gdtjson.Expect{
@@ -193,7 +199,7 @@ func TestJSONPathNotEqual(t *testing.T) {
 	}
 
 	a = gdtjson.New(&exp, c)
-	require.False(a.OK())
+	require.False(a.OK(ctx))
 	failures := a.Failures()
 	require.Len(failures, 1)
 	require.ErrorIs(failures[0], gdtjson.ErrJSONPathNotEqual)
@@ -202,6 +208,7 @@ func TestJSONPathNotEqual(t *testing.T) {
 func TestJSONPathFormatNotFound(t *testing.T) {
 	require := require.New(t)
 
+	ctx := context.TODO()
 	c := content()
 
 	exp := gdtjson.Expect{
@@ -211,7 +218,7 @@ func TestJSONPathFormatNotFound(t *testing.T) {
 	}
 
 	a := gdtjson.New(&exp, c)
-	require.False(a.OK())
+	require.False(a.OK(ctx))
 	failures := a.Failures()
 	require.Len(failures, 1)
 	require.ErrorIs(failures[0], gdtjson.ErrJSONPathNotFound)
@@ -220,6 +227,7 @@ func TestJSONPathFormatNotFound(t *testing.T) {
 func TestJSONPathFormatNotEqual(t *testing.T) {
 	require := require.New(t)
 
+	ctx := context.TODO()
 	c := content()
 
 	exp := gdtjson.Expect{
@@ -229,7 +237,7 @@ func TestJSONPathFormatNotEqual(t *testing.T) {
 	}
 
 	a := gdtjson.New(&exp, c)
-	require.True(a.OK())
+	require.True(a.OK(ctx))
 	require.Empty(a.Failures())
 
 	exp = gdtjson.Expect{
@@ -239,7 +247,7 @@ func TestJSONPathFormatNotEqual(t *testing.T) {
 	}
 
 	a = gdtjson.New(&exp, c)
-	require.False(a.OK())
+	require.False(a.OK(ctx))
 	failures := a.Failures()
 	require.Len(failures, 1)
 	require.ErrorIs(failures[0], gdtjson.ErrJSONFormatNotEqual)

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/assertions.go

@@ -6,6 +6,7 @@ package exec
 
 import (
 	"bytes"
+	"context"
 	"strings"
 
 	"github.com/gdt-dev/gdt/errors"
@@ -76,7 +77,7 @@ func (a *pipeAssertions) Terminal() bool {
 
 // OK checks all the assertions in the pipeAssertions against the supplied pipe
 // contents and returns true if all assertions pass.
-func (a *pipeAssertions) OK() bool {
+func (a *pipeAssertions) OK(ctx context.Context) bool {
 	if a == nil || a.pipe == nil {
 		return true
 	}
@@ -167,17 +168,17 @@ func (a *assertions) Terminal() bool {
 
 // OK checks all the assertions against the supplied arguments and returns true
 // if all assertions pass.
-func (a *assertions) OK() bool {
+func (a *assertions) OK(ctx context.Context) bool {
 	res := true
 	if a.expExitCode != a.exitCode {
 		a.Fail(errors.NotEqual(a.expExitCode, a.exitCode))
 		res = false
 	}
-	if !a.expOutPipe.OK() {
+	if !a.expOutPipe.OK(ctx) {
 		a.failures = append(a.failures, a.expOutPipe.Failures()...)
 		res = false
 	}
-	if !a.expErrPipe.OK() {
+	if !a.expErrPipe.OK(ctx) {
 		a.failures = append(a.failures, a.expErrPipe.Failures()...)
 		res = false
 	}

plugin/exec/eval.go

@@ -30,7 +30,7 @@ func (s *Spec) Eval(ctx context.Context, t *testing.T) *result.Result {
 		return result.New(result.WithRuntimeError(ExecRuntimeError(err)))
 	}
 	a := newAssertions(s.Assert, ec, outbuf, errbuf)
-	if !a.OK() {
+	if !a.OK(ctx) {
 		for _, fail := range a.Failures() {
 			t.Error(fail)
 		}
@@ -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) {

types/assertions.go

@@ -4,12 +4,14 @@
 
 package types
 
+import "context"
+
 // Assertions track zero or more assertions about some result
 type Assertions interface {
 	// OK returns true if all contained assertions pass successfully, false
 	// otherwise. If false is returned, Failures() is guaranteed to be
 	// non-empty.
-	OK() bool
+	OK(context.Context) bool
 	// Fail appends a supplied error to the set of failed assertions
 	Fail(error)
 	// Failures returns a slice of failure messages indicating which assertions