From: Michael Anthony Knyszek Date: Thu, 9 Oct 2025 20:30:18 +0000 (+0000) Subject: runtime/trace: dump test traces on validation failure X-Git-Tag: go1.26rc1~561 X-Git-Url: http://www.git.cypherpunks.su/?a=commitdiff_plain;h=ee4d2c312d;p=gostls13.git runtime/trace: dump test traces on validation failure We currently dump traces for internal/trace tests on validation failure, but not for the runtime/trace package. This change moves some of the machinery to do this into the testtrace package and then uses it from the runtime/trace package. For #75665. Change-Id: Ibe2d4f3945c1fd21dcbccf56820865f8d2ea41f9 Reviewed-on: https://go-review.googlesource.com/c/go/+/710755 Reviewed-by: Michael Pratt Auto-Submit: Michael Knyszek LUCI-TryBot-Result: Go LUCI --- diff --git a/src/go/build/deps_test.go b/src/go/build/deps_test.go index 8966254d0d..8b14e6cb05 100644 --- a/src/go/build/deps_test.go +++ b/src/go/build/deps_test.go @@ -803,7 +803,7 @@ var depsRules = ` FMT, testing < internal/cgrouptest; - regexp, internal/trace, internal/trace/raw, internal/txtar, testing + regexp, internal/testenv, internal/trace, internal/trace/raw, internal/txtar, testing < internal/trace/testtrace; C, CGO diff --git a/src/internal/trace/reader_test.go b/src/internal/trace/reader_test.go index e0733b827d..c03d0676a0 100644 --- a/src/internal/trace/reader_test.go +++ b/src/internal/trace/reader_test.go @@ -7,19 +7,14 @@ package trace_test import ( "bytes" "flag" - "fmt" "io" - "os" "path/filepath" "runtime" - "strings" "testing" "time" "internal/trace" - "internal/trace/raw" "internal/trace/testtrace" - "internal/trace/version" ) var ( @@ -131,52 +126,6 @@ func testReader(t *testing.T, tr io.Reader, v *testtrace.Validator, exp *testtra } } -func dumpTraceToText(t *testing.T, b []byte) string { - t.Helper() - - br, err := raw.NewReader(bytes.NewReader(b)) - if err != nil { - t.Fatalf("dumping trace: %v", err) - } - var sb strings.Builder - tw, err := raw.NewTextWriter(&sb, version.Current) - if err != nil { - t.Fatalf("dumping trace: %v", err) - } - for { - ev, err := br.ReadEvent() - if err == io.EOF { - break - } - if err != nil { - t.Fatalf("dumping trace: %v", err) - } - if err := tw.WriteEvent(ev); err != nil { - t.Fatalf("dumping trace: %v", err) - } - } - return sb.String() -} - -func dumpTraceToFile(t *testing.T, testName string, stress bool, b []byte) string { - t.Helper() - - desc := "default" - if stress { - desc = "stress" - } - name := fmt.Sprintf("%s.%s.trace.", testName, desc) - f, err := os.CreateTemp("", name) - if err != nil { - t.Fatalf("creating temp file: %v", err) - } - defer f.Close() - if _, err := io.Copy(f, bytes.NewReader(b)); err != nil { - t.Fatalf("writing trace dump to %q: %v", f.Name(), err) - } - return f.Name() -} - func TestTraceGenSync(t *testing.T) { type sync struct { Time trace.Time diff --git a/src/internal/trace/testtrace/helpers.go b/src/internal/trace/testtrace/helpers.go new file mode 100644 index 0000000000..50f6825bab --- /dev/null +++ b/src/internal/trace/testtrace/helpers.go @@ -0,0 +1,87 @@ +// Copyright 2025 The Go Authors. All rights reserved. +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +package testtrace + +import ( + "bytes" + "fmt" + "internal/testenv" + "internal/trace/raw" + "internal/trace/version" + "io" + "os" + "strings" + "testing" +) + +// MustHaveSyscallEvents skips the current test if the current +// platform does not support true system call events. +func Dump(t *testing.T, testName string, traceBytes []byte, forceToFile bool) { + onBuilder := testenv.Builder() != "" + onOldBuilder := !strings.Contains(testenv.Builder(), "gotip") && !strings.Contains(testenv.Builder(), "go1") + + if onBuilder && !forceToFile { + // Dump directly to the test log on the builder, since this + // data is critical for debugging and this is the only way + // we can currently make sure it's retained. + s := dumpTraceToText(t, traceBytes) + if onOldBuilder && len(s) > 1<<20+512<<10 { + // The old build infrastructure truncates logs at ~2 MiB. + // Let's assume we're the only failure and give ourselves + // up to 1.5 MiB to dump the trace. + // + // TODO(mknyszek): Remove this when we've migrated off of + // the old infrastructure. + t.Logf("text trace too large to dump (%d bytes)", len(s)) + } else { + t.Log(s) + } + } else { + // We asked to dump the trace or failed. Write the trace to a file. + t.Logf("wrote trace to file: %s", dumpTraceToFile(t, testName, traceBytes)) + } +} + +func dumpTraceToText(t *testing.T, b []byte) string { + t.Helper() + + br, err := raw.NewReader(bytes.NewReader(b)) + if err != nil { + t.Fatalf("dumping trace: %v", err) + } + var sb strings.Builder + tw, err := raw.NewTextWriter(&sb, version.Current) + if err != nil { + t.Fatalf("dumping trace: %v", err) + } + for { + ev, err := br.ReadEvent() + if err == io.EOF { + break + } + if err != nil { + t.Fatalf("dumping trace: %v", err) + } + if err := tw.WriteEvent(ev); err != nil { + t.Fatalf("dumping trace: %v", err) + } + } + return sb.String() +} + +func dumpTraceToFile(t *testing.T, testName string, b []byte) string { + t.Helper() + + name := fmt.Sprintf("%s.trace.", testName) + f, err := os.CreateTemp(t.ArtifactDir(), name) + if err != nil { + t.Fatalf("creating temp file: %v", err) + } + defer f.Close() + if _, err := io.Copy(f, bytes.NewReader(b)); err != nil { + t.Fatalf("writing trace dump to %q: %v", f.Name(), err) + } + return f.Name() +} diff --git a/src/internal/trace/trace_test.go b/src/internal/trace/trace_test.go index 4824937b70..25f671d440 100644 --- a/src/internal/trace/trace_test.go +++ b/src/internal/trace/trace_test.go @@ -668,26 +668,14 @@ func testTraceProg(t *testing.T, progName string, extra func(t *testing.T, trace } // Dump some more information on failure. - if t.Failed() && onBuilder { - // Dump directly to the test log on the builder, since this - // data is critical for debugging and this is the only way - // we can currently make sure it's retained. - t.Log("found bad trace; dumping to test log...") - s := dumpTraceToText(t, tb) - if onOldBuilder && len(s) > 1<<20+512<<10 { - // The old build infrastructure truncates logs at ~2 MiB. - // Let's assume we're the only failure and give ourselves - // up to 1.5 MiB to dump the trace. - // - // TODO(mknyszek): Remove this when we've migrated off of - // the old infrastructure. - t.Logf("text trace too large to dump (%d bytes)", len(s)) - } else { - t.Log(s) + if t.Failed() || *dumpTraces { + suffix := func(stress bool) string { + if stress { + return "stress" + } + return "default" } - } else if t.Failed() || *dumpTraces { - // We asked to dump the trace or failed. Write the trace to a file. - t.Logf("wrote trace to file: %s", dumpTraceToFile(t, testName, stress, tb)) + testtrace.Dump(t, fmt.Sprintf("%s.%s", testName, suffix(stress)), tb, *dumpTraces) } } t.Run("Default", func(t *testing.T) { diff --git a/src/runtime/trace/flightrecorder_test.go b/src/runtime/trace/flightrecorder_test.go index 61cb03dcf6..221f9c6b67 100644 --- a/src/runtime/trace/flightrecorder_test.go +++ b/src/runtime/trace/flightrecorder_test.go @@ -119,7 +119,7 @@ func TestFlightRecorderConcurrentWriteTo(t *testing.T) { if buf.Len() == 0 { continue } - testReader(t, buf, testtrace.ExpectSuccess()) + testReader(t, buf.Bytes(), testtrace.ExpectSuccess()) } } @@ -260,12 +260,12 @@ func testFlightRecorder(t *testing.T, fr *trace.FlightRecorder, f flightRecorder traceBytes := buf.Bytes() // Parse the trace to make sure it's not broken. - testReader(t, bytes.NewReader(traceBytes), testtrace.ExpectSuccess()) + testReader(t, traceBytes, testtrace.ExpectSuccess()) return traceBytes } -func testReader(t *testing.T, tr io.Reader, exp *testtrace.Expectation) { - r, err := inttrace.NewReader(tr) +func testReader(t *testing.T, tb []byte, exp *testtrace.Expectation) { + r, err := inttrace.NewReader(bytes.NewReader(tb)) if err != nil { if err := exp.Check(err); err != nil { t.Error(err) @@ -292,6 +292,9 @@ func testReader(t *testing.T, tr io.Reader, exp *testtrace.Expectation) { if err := exp.Check(nil); err != nil { t.Error(err) } + if t.Failed() || *dumpTraces { + testtrace.Dump(t, "trace", tb, *dumpTraces) + } } func TestTraceAndFlightRecorder(t *testing.T) { diff --git a/src/runtime/trace/trace_test.go b/src/runtime/trace/trace_test.go index b891c8c8f9..2174be061d 100644 --- a/src/runtime/trace/trace_test.go +++ b/src/runtime/trace/trace_test.go @@ -7,13 +7,16 @@ package trace_test import ( "bytes" "flag" - "os" . "runtime/trace" "testing" "time" ) -var saveTraces = flag.Bool("savetraces", false, "save traces collected by tests") +var dumpTraces = flag.Bool("dump-traces", false, "dump traces to a file, even on success") + +// This file just contains smoke tests and tests of runtime/trace logic only. +// It doesn't validate the resulting traces. See the internal/trace package for +// more comprehensive end-to-end tests. func TestTraceStartStop(t *testing.T) { if IsEnabled() { @@ -32,7 +35,6 @@ func TestTraceStartStop(t *testing.T) { if size != buf.Len() { t.Fatalf("trace writes after stop: %v -> %v", size, buf.Len()) } - saveTrace(t, buf, "TestTraceStartStop") } func TestTraceDoubleStart(t *testing.T) { @@ -50,12 +52,3 @@ func TestTraceDoubleStart(t *testing.T) { Stop() Stop() } - -func saveTrace(t *testing.T, buf *bytes.Buffer, name string) { - if !*saveTraces { - return - } - if err := os.WriteFile(name+".trace", buf.Bytes(), 0600); err != nil { - t.Errorf("failed to write trace file: %s", err) - } -}