metatesting: forward stderr logs for races

Make sure stderr logs show up to help debug races (or other
problems that are printed to stderr.)

Prefix all log lines to distinguish logs from the metatesting
binary.

Test that logs show up when there is a problem and otherwise
are quiet.

Author: jellevandenhooff

gosimruntime/testmain.go

@@ -3,6 +3,7 @@ package gosimruntime
 import (
 	"encoding/json"
 	"flag"
+	"io"
 	"log"
 	"maps"
 	"os"
@@ -167,7 +168,7 @@ func TestMain(rt Runtime) {
 			if !ok {
 				SetAbortError(ErrTestFailed)
 			}
-		}, seed, enableTracer, captureLog, logLevelOverride, makeConsoleLogger(os.Stderr), req.ExtraEnv)
+		}, seed, enableTracer, captureLog, logLevelOverride, io.Discard, req.ExtraEnv)
 
 		metaResult := runResult{
 			Seed:      result.Seed,

internal/tests/script/testdata/metatestlogs.txtar

@@ -0,0 +1,70 @@
+# metatest forwards logs
+
+# normally we do not see prefixed forwarded logs
+exec go test -run=Ok -race -count=1 -v .
+stdout hello
+! stdout 'metatest binary'
+
+# races do show up
+! exec go test -run=Bad -race -count=1 -v .
+stdout 'metatest binary: WARNING: DATA RACE'
+
+-- race_meta_test.go --
+//go:build !sim
+package behavior_test
+
+import (
+	"testing"
+
+    "github.com/jellevandenhooff/gosim/metatesting"
+)
+
+func TestOk(t *testing.T) {
+    mt := metatesting.ForCurrentPackage(t)
+	_, err := mt.Run(t, &metatesting.RunConfig{
+		Test:     "TestOk",
+		Seed:     1,
+	})
+	if err != nil {
+		t.Fatal(err)
+	}
+}
+
+func TestBad(t *testing.T) {
+    mt := metatesting.ForCurrentPackage(t)
+	res, err := mt.Run(t, &metatesting.RunConfig{
+		Test:     "TestBad",
+		Seed:     1,
+	})
+	if err != nil {
+		t.Fatal(err)
+	}
+    if res.Failed {
+		t.Fatal(res.Err)
+    }
+}
+
+-- race_test.go --
+//go:build sim
+package behavior_test
+
+import (
+	"testing"
+)
+
+func TestOk(t *testing.T) {
+    t.Log("hello")
+}
+
+func TestBad(t *testing.T) {
+    // simple data race
+    var x int
+    done := make(chan struct{})
+    go func() {
+        x = 1
+        close(done)
+    }()
+    x = 2
+    <-done
+    _ = x
+}

metatesting/metatest.go

@@ -4,7 +4,6 @@ import (
 	"bytes"
 	"encoding/json"
 	"fmt"
-	"io"
 	"log"
 	"log/slog"
 	"os"
@@ -54,10 +53,12 @@ type MetaT struct {
 	r *json.Decoder
 }
 
-/*
-type indenter struct{}
+type prefixer struct {
+	out    *os.File
+	prefix string
+}
 
-func (w indenter) Write(b []byte) (n int, err error) {
+func (w prefixer) Write(b []byte) (n int, err error) {
 	n = len(b)
 	for len(b) > 0 {
 		end := bytes.IndexByte(b, '\n')
@@ -66,22 +67,16 @@ func (w indenter) Write(b []byte) (n int, err error) {
 		} else {
 			end++
 		}
-		// An indent of 4 spaces will neatly align the dashes with the status
-		// indicator of the parent.
 		line := b[:end]
-		// if line[0] == marker {
-		// w.c.output = append(w.c.output, marker)
-		// line = line[1:]
-		// }
-		const indent = "    "
-		fmt.Fprintf(os.Stderr, "%s%s", indent, line)
-		// w.c.output = append(w.c.output, indent...)
-		// w.c.output = append(w.c.output, line...)
+		w.out.WriteString(w.prefix)
+		w.out.Write(line)
+		if line[len(line)-1] != '\n' {
+			w.out.WriteString("\n")
+		}
 		b = b[end:]
 	}
 	return
 }
-*/
 
 func newRunner(path string) (*MetaT, error) {
 	cmd := exec.Command(path, "-metatest")
@@ -96,7 +91,7 @@ func newRunner(path string) (*MetaT, error) {
 
 	// TODO: Do not discard, and disable the formatted output print in gosimruntime instead
 	// TODO: Prefix output to help identify stray logging?
-	cmd.Stderr = io.Discard // os.Stderr
+	cmd.Stderr = &prefixer{out: os.Stderr, prefix: "metatest binary: "}
 
 	if err := cmd.Start(); err != nil {
 		return nil, err