test2json: Passthrough github actions commands to stderr

Because `go test` seems to be capturing stderr and passing it to stdout
instead (and thus is getting captured by test2jsongha), check if a given event
output looks like a github actions command and pass that through.

Signed-off-by: Brian Goff <[email protected]>

Author: cpuguy83

.github/workflows/ci.yml

@@ -159,6 +159,7 @@ jobs:
         uses: crazy-max/ghaction-github-runtime@3cb05d89e1f492524af3d41a1c98c83bc3025124 # v3.1.0
       - name: Run integration tests
         run: |
+          env | grep GITHUB
           set -ex
           if [ -n "${TEST_SUITE}" ] && [ ! "${TEST_SUITE}" = "other" ]; then
             run="-run=${TEST_SUITE}"

cmd/test2json2gha/event.go

@@ -7,7 +7,9 @@ import (
 	"math"
 	"os"
 	"path"
+	"regexp"
 	"strings"
+	"sync"
 	"time"
 
 	"github.com/Azure/dalec"
@@ -47,7 +49,29 @@ type outputStreamer struct {
 
 func (h *outputStreamer) HandleEvent(te *TestEvent) error {
 	if te.Output != "" {
-		_, err := h.out.Write([]byte(te.Output))
+		if !githubActionsCommand().MatchString(te.Output) {
+			_, err := h.out.Write([]byte(te.Output))
+			return err
+		}
+	}
+	return nil
+}
+
+var githubActionsCommand = sync.OnceValue(func() *regexp.Regexp {
+	return regexp.MustCompile(`^::(error|warning|notice|add-mask)(?:\s+file=([^,:]+)(?:,line=(\d+))?)?::`)
+})
+
+type githubActionsCommandPassthrough struct {
+	out io.Writer
+}
+
+func (h *githubActionsCommandPassthrough) HandleEvent(te *TestEvent) error {
+	if te.Output != "" && githubActionsCommand().MatchString(te.Output) {
+		out := h.out
+		if out == nil {
+			out = os.Stderr
+		}
+		_, err := out.Write([]byte(te.Output))
 		return err
 	}
 	return nil
@@ -109,9 +133,11 @@ func (h *resultsHandler) HandleEvent(te *TestEvent) error {
 	tr.elapsed = te.Elapsed
 
 	if te.Output != "" {
-		_, err := tr.output.WriteString(te.Output)
-		if err != nil {
-			return errors.Wrap(err, "error collecting test event output")
+		if !githubActionsCommand().MatchString(te.Output) {
+			_, err := tr.output.WriteString(te.Output)
+			if err != nil {
+				return errors.Wrap(err, "error collecting test event output")
+			}
 		}
 	}
 

cmd/test2json2gha/event_test.go

@@ -73,6 +73,8 @@ const (
 {"Time":"2025-06-04T09:51:34.185052-07:00","Action":"output","Package":"some_package","Test":"TestGenTimeout","Output":"exit status 2\n"}
 {"Time":"2025-03-31T09:46:20.328007-07:00","Action":"output","Package":"some_package","Output":"FAIL\n"}
 {"Time":"2025-03-31T09:46:20.328475-07:00","Action":"output","Package":"some_package","Output":"FAIL\tsome_package\t0.249s\n"}
+{"Time": "2025-03-31T09:46:20.32851-07:00","Action":"output","Package":"some_package","Output":"::warning file=foo_test.go,line=38::hello warning\n"}
+{"Time": "2025-03-31T09:46:20.32851-07:00","Action":"output","Package":"some_package","Output":"::notice::hello notice\n"}
 {"Time":"2025-03-31T09:46:20.32851-07:00","Action":"fail","Package":"some_package","Elapsed":0.25}
 `
 
@@ -122,6 +124,8 @@ exit status 2
 	testLogsAnnotation = "    foo_test.go:42: some error\n    foo_test.go:43: some fatal error\n"
 
 	testPackageName = "some_package"
+
+	ghaCommandsOutput = "::warning file=foo_test.go,line=38::hello warning\n::notice::hello notice\n"
 )
 
 func mockTestResults(t *testing.T) iter.Seq[*TestResult] {
@@ -275,3 +279,15 @@ func TestWriteLogs(t *testing.T) {
 		assert.Equal(t, string(content), string(output), "log file content does not match expected output")
 	}
 }
+
+func TestGithubActionsPassthrough(t *testing.T) {
+	var output strings.Builder
+	out := &githubActionsCommandPassthrough{out: &output}
+
+	for event := range readTestEvents(t) {
+		err := out.HandleEvent(event)
+		assert.NilError(t, err)
+	}
+
+	assert.Equal(t, output.String(), ghaCommandsOutput)
+}

cmd/test2json2gha/main.go

@@ -15,11 +15,12 @@ import (
 )
 
 type config struct {
-	slowThreshold time.Duration
-	modName       string
-	verbose       bool
-	stream        bool
-	logDir        string
+	slowThreshold  time.Duration
+	modName        string
+	verbose        bool
+	stream         bool
+	logDir         string
+	ghaCommandsOut io.Writer
 }
 
 func main() {
@@ -107,6 +108,7 @@ func do(in io.Reader, out io.Writer, cfg config) (bool, error) {
 	handlers := []EventHandler{
 		results,
 		&anyFailed,
+		&githubActionsCommandPassthrough{out: cfg.ghaCommandsOut},
 	}
 
 	if cfg.stream {

cmd/test2json2gha/main_test.go

@@ -9,6 +9,7 @@ import (
 	"time"
 
 	"gotest.tools/v3/assert"
+	"gotest.tools/v3/assert/cmp"
 )
 
 const (
@@ -28,11 +29,13 @@ func TestDo(t *testing.T) {
 		input := strings.NewReader(testEventJSON)
 		var output bytes.Buffer
 
+		ghaBuff := bytes.NewBuffer(nil)
 		cfg := config{
-			slowThreshold: 200 * time.Millisecond,
-			modName:       testModuleName,
-			verbose:       false,
-			stream:        false,
+			slowThreshold:  200 * time.Millisecond,
+			modName:        testModuleName,
+			verbose:        false,
+			stream:         false,
+			ghaCommandsOut: ghaBuff,
 		}
 
 		anyFail, err := do(input, &output, cfg)
@@ -41,18 +44,21 @@ func TestDo(t *testing.T) {
 
 		// Non-verbose output should only include the grouped fail events + error annotations
 		expected := failGroup + timeoutGroup + annotation
-		assert.Equal(t, expected, output.String())
+		assert.Check(t, cmp.Equal(expected, output.String()))
+		assert.Check(t, cmp.Equal(ghaCommandsOutput, ghaBuff.String()))
 	})
 
 	t.Run("verbose=true", func(t *testing.T) {
 		input := strings.NewReader(testEventJSON)
 		var output bytes.Buffer
 
+		ghaBuff := bytes.NewBuffer(nil)
 		cfg := config{
-			slowThreshold: 200 * time.Millisecond,
-			modName:       testModuleName,
-			verbose:       true,
-			stream:        false,
+			slowThreshold:  200 * time.Millisecond,
+			modName:        testModuleName,
+			verbose:        true,
+			stream:         false,
+			ghaCommandsOut: ghaBuff,
 		}
 
 		anyFail, err := do(input, &output, cfg)
@@ -62,17 +68,21 @@ func TestDo(t *testing.T) {
 		// verbose output should include grouped events for all test results + error annotations
 		expected := failGroup + passGroup + skipGroup + timeoutGroup + annotation
 		assert.Equal(t, output.String(), expected)
+		assert.Check(t, cmp.Equal(expected, output.String()))
+		assert.Check(t, cmp.Equal(ghaCommandsOutput, ghaBuff.String()))
 	})
 
 	t.Run("stream=true", func(t *testing.T) {
 		input := strings.NewReader(testEventJSON)
 		var output bytes.Buffer
 
+		ghaBuff := bytes.NewBuffer(nil)
 		cfg := config{
-			slowThreshold: 200 * time.Millisecond,
-			modName:       testModuleName,
-			verbose:       false,
-			stream:        true,
+			slowThreshold:  200 * time.Millisecond,
+			modName:        testModuleName,
+			verbose:        false,
+			stream:         true,
+			ghaCommandsOut: ghaBuff,
 		}
 
 		anyFail, err := do(input, &output, cfg)
@@ -81,7 +91,8 @@ func TestDo(t *testing.T) {
 
 		// Stream output should include all the raw events + the grouped fail events + the annotation
 		expected := testEventPassOutput + testEventFailOutput + testEventSkipOutput + testEventTimeoutOutput + testEventPackageOutput + failGroup + timeoutGroup + annotation
-		assert.Equal(t, output.String(), expected)
+		assert.Check(t, cmp.Equal(expected, output.String()))
+		assert.Check(t, cmp.Equal(ghaCommandsOutput, ghaBuff.String()))
 	})
 
 	t.Run("summary", func(t *testing.T) {
@@ -94,11 +105,13 @@ func TestDo(t *testing.T) {
 
 		input := strings.NewReader(testEventJSON)
 
+		ghaBuff := bytes.NewBuffer(nil)
 		cfg := config{
-			slowThreshold: 200 * time.Millisecond,
-			modName:       testModuleName,
-			verbose:       false,
-			stream:        false,
+			slowThreshold:  200 * time.Millisecond,
+			modName:        testModuleName,
+			verbose:        false,
+			stream:         false,
+			ghaCommandsOut: ghaBuff,
 		}
 
 		anyFail, err := do(input, io.Discard, cfg)
@@ -125,20 +138,23 @@ some_package: 0.250s
 
 `
 
-		assert.Equal(t, string(output), expect)
+		assert.Check(t, cmp.Equal(string(output), expect))
+		assert.Check(t, cmp.Equal(ghaCommandsOutput, ghaBuff.String()))
 	})
 
 	t.Run("LogDir", func(t *testing.T) {
 		input := strings.NewReader(testEventJSON)
 		var output bytes.Buffer
 
 		logDir := t.TempDir()
+		ghaBuff := bytes.NewBuffer(nil)
 		cfg := config{
-			slowThreshold: 500,
-			modName:       "github.com/Azure/dalec/cmd/test2json2gha",
-			verbose:       false,
-			stream:        false,
-			logDir:        logDir,
+			slowThreshold:  500,
+			modName:        "github.com/Azure/dalec/cmd/test2json2gha",
+			verbose:        false,
+			stream:         false,
+			logDir:         logDir,
+			ghaCommandsOut: ghaBuff,
 		}
 
 		anyFail, err := do(input, &output, cfg)
@@ -148,6 +164,7 @@ some_package: 0.250s
 		// Validate that logs are written to the specified directory
 		entries, err := os.ReadDir(logDir)
 		assert.NilError(t, err)
-		assert.Assert(t, len(entries) > 0, "expected log files to be written to the log directory")
+		assert.Check(t, len(entries) > 0, "expected log files to be written to the log directory")
+		assert.Check(t, cmp.Equal(ghaCommandsOutput, ghaBuff.String()))
 	})
 }

test/testenv/build.go

@@ -224,25 +224,48 @@ func lookupProjectRoot(cur string) (string, error) {
 	return cur, nil
 }
 
-var ciLoadCacheOptions = sync.OnceValue(func() (out []client.CacheOptionsEntry) {
+func ghaAnnotation(skipFrames int, cmd string, msg string) {
+	ghaAnnotationf(skipFrames+1, cmd, "%s", msg)
+}
+
+func ghaAnnotationf(skipFrames int, cmd string, format string, args ...any) {
+	_, f, l, _ := runtime.Caller(skipFrames + 1)
 	if os.Getenv("GITHUB_ACTIONS") != "true" {
 		// not running in a github action, nothing to do
 		return
 	}
 
+	format = "::%s file=%s,line=%d::%s\n" + format
+	args = append([]any{cmd, f, l}, args...)
+	fmt.Printf(format, args...)
+}
+
+var ciLoadCacheOptions = sync.OnceValues(func() (out []client.CacheOptionsEntry, ok bool) {
+	const (
+		ghaEnv   = "GITHUB_ACTIONS"
+		tokenEnv = "ACTIONS_RUNTIME_TOKEN"
+		urlEnv   = "ACTIONS_CACHE_URL"
+	)
+	if os.Getenv(ghaEnv) != "true" {
+		// not running in a github action, nothing to do
+		return out, false
+	}
+
+	ghaAnnotation(0, "notice", "Loading cache options for GitHub Actions")
+
 	// token and url are required for the cache to work.
 	// These need to be exposed as environment variables in the GitHub Actions workflow.
 	// See the crazy-max/ghaction-github-runtime@v3 action.
-	token := os.Getenv("ACTIONS_RUNTIME_TOKEN")
+	token := os.Getenv(tokenEnv)
 	if token == "" {
-		fmt.Fprintln(os.Stderr, "::warning::GITHUB_ACTIONS_RUNTIME_TOKEN is not set, skipping cache export")
-		return nil
+		ghaAnnotationf(0, "warning", "%s is not set, skipping cache export", tokenEnv)
+		return nil, true
 	}
 
 	url := os.Getenv("ACTIONS_CACHE_URL")
 	if url == "" {
-		fmt.Fprintln(os.Stderr, "::warning::ACTIONS_CACHE_URL is not set, skipping cache export")
-		return nil
+		ghaAnnotationf(0, "warning", "%s is not set, skipping cache export", urlEnv)
+		return nil, true
 	}
 
 	// Unfortunately we need to load all the caches because at this level we do
@@ -254,6 +277,7 @@ var ciLoadCacheOptions = sync.OnceValue(func() (out []client.CacheOptionsEntry)
 
 	for _, r := range plugins.Graph(filter) {
 		target := path.Join(r.ID, "worker")
+		ghaAnnotationf(0, "notice", "Adding cache import: type: gha target: %q", "gha", target)
 		out = append(out, client.CacheOptionsEntry{
 			Type: "gha",
 			Attrs: map[string]string{
@@ -264,18 +288,16 @@ var ciLoadCacheOptions = sync.OnceValue(func() (out []client.CacheOptionsEntry)
 		})
 	}
 
-	fmt.Fprintln(os.Stderr, "::add-mask::"+token)
-	_, f, l, _ := runtime.Caller(1)
 	if len(out) == 0 {
-		_, f, l, _ := runtime.Caller(1)
-		fmt.Fprintf(os.Stderr, "::error file=%s,line=%d::No build targets found, skipping cache export\n", f, l)
+		ghaAnnotation(0, "error", "No build targets found, skipping cache export")
 	}
-	for _, o := range out {
-		fmt.Fprintf(os.Stderr, "::notice file=%s,line=%d::Adding cache import: %s %v\n", f, l, o.Type, o.Attrs)
-	}
-	return out
+	return out, true
 })
 
-func withCICache(opts *client.SolveOpt) {
-	opts.CacheImports = append(opts.CacheImports, ciLoadCacheOptions()...)
+func withCICache(opts *client.SolveOpt) bool {
+	imports, ok := ciLoadCacheOptions()
+	if ok {
+		opts.CacheImports = append(opts.CacheImports, imports...)
+	}
+	return ok
 }

test/testenv/buildx.go

@@ -378,7 +378,10 @@ func (b *BuildxEnv) RunTest(ctx context.Context, t *testing.T, f TestFunc, opts
 		f(&so)
 	}
 
-	withCICache(&so)
+	ok := withCICache(&so)
+	if ok && len(so.CacheImports) == 0 {
+		t.Fatal("github cache is enabled but no cache imports are set")
+	}
 
 	_, err = c.Build(ctx, so, "", func(ctx context.Context, gwc gwclient.Client) (*gwclient.Result, error) {
 		gwc = &clientForceDalecWithInput{gwc}