feat(cmd/gno): move test output within gno code (#1594)

Once again, welcome to "I was annoyed by a small thing that I wanted to
do a 10 minute fix for and ended up on a refactoring detour".

This PR moves the output of the `gno test` function to happen within the
gno code. This solves a number of issues:

- filtered tests are no longer printed to the console with `--- FILT`
(my original 10-minute fix)
- test output is no longer buffered
- success of subtests is reported correctly
- run/success report of subtests goes to stderr instead of stdout
- `--- FAIL` is not printed for every time a Fail function is called
(ie. only once)
- as a bonus, `SkipNow` and `FailNow` actually work, so now you can Skip
and Fatal your way out of test functions.

Fixes #665

gnovm/cmd/gno/test.go

@@ -499,22 +499,15 @@ func runTestFiles(
 	m.RunFiles(n)
 
 	for _, test := range testFuncs.Tests {
-		if verbose {
-			io.ErrPrintfln("=== RUN   %s", test.Name)
-		}
-
 		testFuncStr := fmt.Sprintf("%q", test.Name)
 
-		startedAt := time.Now()
 		eval := m.Eval(gno.Call("runtest", testFuncStr))
-		duration := time.Since(startedAt)
-		dstr := fmtDuration(duration)
 
 		ret := eval[0].GetString()
 		if ret == "" {
 			err := errors.New("failed to execute unit test: %q", test.Name)
 			errs = multierr.Append(errs, err)
-			io.ErrPrintfln("--- FAIL: %s (%v)", test.Name, duration)
+			io.ErrPrintfln("--- FAIL: %s [internal gno testing error]", test.Name)
 			continue
 		}
 
@@ -523,30 +516,13 @@ func runTestFiles(
 		err = json.Unmarshal([]byte(ret), &rep)
 		if err != nil {
 			errs = multierr.Append(errs, err)
-			io.ErrPrintfln("--- FAIL: %s (%s)", test.Name, dstr)
+			io.ErrPrintfln("--- FAIL: %s [internal gno testing error]", test.Name)
 			continue
 		}
 
-		switch {
-		case rep.Filtered:
-			io.ErrPrintfln("--- FILT: %s", test.Name)
-			// noop
-		case rep.Skipped:
-			if verbose {
-				io.ErrPrintfln("--- SKIP: %s", test.Name)
-			}
-		case rep.Failed:
+		if rep.Failed {
 			err := errors.New("failed: %q", test.Name)
 			errs = multierr.Append(errs, err)
-			io.ErrPrintfln("--- FAIL: %s (%s)", test.Name, dstr)
-		default:
-			if verbose {
-				io.ErrPrintfln("--- PASS: %s (%s)", test.Name, dstr)
-			}
-		}
-
-		if rep.Output != "" && (verbose || rep.Failed) {
-			io.ErrPrintfln("output: %s", rep.Output)
 		}
 
 		if printRuntimeMetrics {
@@ -574,12 +550,8 @@ func runTestFiles(
 
 // mirror of stdlibs/testing.Report
 type report struct {
-	Name     string
-	Verbose  bool
-	Failed   bool
-	Skipped  bool
-	Filtered bool
-	Output   string
+	Failed  bool
+	Skipped bool
 }
 
 var testmainTmpl = template.Must(template.New("testmain").Parse(`

gnovm/cmd/gno/testdata/gno_test/flag_run.txtar

@@ -6,39 +6,42 @@ gno test ./run_test.gno
 
 gno test -verbose .
 
-stdout '=== RUN   TestRun/hello'
-stdout '=== RUN   TestRun/hi_you'
-stdout '=== RUN   TestRun/hi_me'
+! stdout .+
+stderr '=== RUN   TestRun/hello'
+stderr '=== RUN   TestRun/hi_you'
+stderr '=== RUN   TestRun/hi_me'
 stderr '=== RUN   TestRun'
 stderr '--- PASS: TestRun'
 
 gno test -verbose -run .* .
 
-stdout '=== RUN   TestRun/hello'
-stdout '=== RUN   TestRun/hi_you'
-stdout '=== RUN   TestRun/hi_me'
+! stdout .+
+stderr '=== RUN   TestRun/hello'
+stderr '=== RUN   TestRun/hi_you'
+stderr '=== RUN   TestRun/hi_me'
 stderr '=== RUN   TestRun'
 stderr '--- PASS: TestRun'
 
 gno test -verbose -run NotExists .
 
 ! stdout .+
-stderr '=== RUN   TestRun'
-stderr '--- FILT: TestRun'
+! stderr '=== RUN   TestRun'
 
 gno test -verbose -run .*/hello .
 
-stdout '=== RUN   TestRun/hello'
-! stdout '=== RUN   TestRun/hi_you'
-! stdout '=== RUN   TestRun/hi_me'
+! stdout .+
+stderr '=== RUN   TestRun/hello'
+! stderr '=== RUN   TestRun/hi_you'
+! stderr '=== RUN   TestRun/hi_me'
 stderr '=== RUN   TestRun'
 stderr '--- PASS: TestRun'
 
 gno test -verbose -run .*/hi .
 
-! stdout '=== RUN   TestRun/hello'
-stdout '=== RUN   TestRun/hi_you'
-stdout '=== RUN   TestRun/hi_me'
+! stdout .+
+! stderr '=== RUN   TestRun/hello'
+stderr '=== RUN   TestRun/hi_you'
+stderr '=== RUN   TestRun/hi_me'
 stderr '=== RUN   TestRun'
 stderr '--- PASS: TestRun'
 
@@ -50,25 +53,28 @@ stderr '--- PASS: TestRun'
 
 gno test -verbose -run Run/.* .
 
-stdout '=== RUN   TestRun/hello'
-stdout '=== RUN   TestRun/hi_you'
-stdout '=== RUN   TestRun/hi_me'
+! stdout .+
+stderr '=== RUN   TestRun/hello'
+stderr '=== RUN   TestRun/hi_you'
+stderr '=== RUN   TestRun/hi_me'
 stderr '=== RUN   TestRun'
 stderr '--- PASS: TestRun'
 
 gno test -verbose -run Run/ .
 
-stdout '=== RUN   TestRun/hello'
-stdout '=== RUN   TestRun/hi_you'
-stdout '=== RUN   TestRun/hi_me'
+! stdout .+
+stderr '=== RUN   TestRun/hello'
+stderr '=== RUN   TestRun/hi_you'
+stderr '=== RUN   TestRun/hi_me'
 stderr '=== RUN   TestRun'
 stderr '--- PASS: TestRun'
 
 gno test -verbose -run Run/hello .
 
-stdout '=== RUN   TestRun/hello'
-! stdout '=== RUN   TestRun/hi_you'
-! stdout '=== RUN   TestRun/hi_me'
+! stdout .+
+stderr '=== RUN   TestRun/hello'
+! stderr '=== RUN   TestRun/hi_you'
+! stderr '=== RUN   TestRun/hi_me'
 stderr '=== RUN   TestRun'
 stderr '--- PASS: TestRun'
 

gnovm/cmd/gno/testdata/gno_test/panic.txtar

@@ -0,0 +1,20 @@
+# Test panic output in a test
+
+! gno test .
+
+! stdout .+
+stderr '--- FAIL: TestPanic'
+stderr 'panic: hello world'
+stderr 'FAIL'
+
+-- panic.gno --
+package valid
+
+-- panic_test.gno --
+package valid
+
+import "testing"
+
+func TestPanic(t *testing.T) {
+	panic("hello world")
+}

gnovm/cmd/gno/testdata/gno_test/recover.txtar

@@ -0,0 +1,62 @@
+# Test recovering
+
+gno test -verbose -run 'TestRecover$' .
+
+! stdout .+
+stderr 'recovered bad panic!'
+stderr '--- PASS'
+stderr 'ok  '
+
+gno test -verbose -run 'TestRecoverSkip$' .
+
+! stdout .+
+stderr 'skipped'
+! stderr 'recovered.*testing.Recover'
+stderr '--- SKIP'
+stderr 'ok  '
+
+gno test -verbose -run 'TestBadRecoverSkip$' .
+
+! stdout .+
+# should contain warning about using testing.Recover
+stderr 'recovered.*testing.Recover'
+# the test will still be marked as skipped
+stderr '--- SKIP'
+stderr 'ok  '
+
+-- recov.gno --
+package recov
+
+-- recov_test.gno --
+package recov
+
+import "testing"
+
+func TestRecover(t *testing.T) {
+	defer func() {
+		err := testing.Recover()
+		t.Log("recovered", err)
+	}()
+
+	panic("bad panic!")
+}
+
+func TestRecoverSkip(t *testing.T) {
+	defer func() {
+		err := testing.Recover()
+		t.Log("recovered", err)
+	}()
+
+	t.Skip("skipped")
+	panic("bad panic!")
+}
+
+func TestBadRecoverSkip(t *testing.T) {
+	defer func() {
+		err := recover()
+		t.Log("recovered", err)
+	}()
+
+	t.Skip("skipped")
+	panic("bad panic!")
+}

gnovm/cmd/gno/testdata/gno_test/skip.txtar

@@ -0,0 +1,24 @@
+# Test skipping a test
+
+gno test -verbose .
+
+! stdout .+
+stderr 'Hey'
+stderr 'I.m on strike!'
+! stderr 'this shouldn.t print'
+stderr '--- SKIP: TestSkip'
+stderr 'ok  '
+
+-- skip.gno --
+package skip
+
+-- skip_test.gno --
+package skip
+
+import "testing"
+
+func TestSkip(t *testing.T) {
+	t.Log("Hey")
+	t.Skip("I'm on strike!")
+	t.Log("so this shouldn't print")
+}

gnovm/pkg/gnolang/machine.go

@@ -391,12 +391,8 @@ func (m *Machine) TestFunc(t *testing.T, tv TypedValue) {
 
 		// mirror of stdlibs/testing.Report
 		var report struct {
-			Name     string
-			Verbose  bool
-			Failed   bool
-			Skipped  bool
-			Filtered bool
-			Output   string
+			Skipped bool
+			Failed  bool
 		}
 		err := json.Unmarshal([]byte(ret), &report)
 		if err != nil {
@@ -405,17 +401,11 @@ func (m *Machine) TestFunc(t *testing.T, tv TypedValue) {
 		}
 
 		switch {
-		case report.Filtered:
-			// noop
 		case report.Skipped:
 			t.SkipNow()
 		case report.Failed:
 			t.Fail()
 		}
-
-		if report.Output != "" && (report.Verbose || report.Failed) {
-			t.Log(report.Output)
-		}
 	})
 }