internal/trace: add a validator test for the new clock snapshots

Check that the clock snapshots, when expected to be present, are
non-zero and monotonically increasing.

This required some refactoring to make the validator aware of the
version of the trace it is validating.

Change-Id: I04c4dd10fe6975cbac12bb0ddaebcec3a5284e7b
Reviewed-on: https://go-review.googlesource.com/c/go/+/669715
Auto-Submit: Michael Knyszek <mknyszek@google.com>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Reviewed-by: Michael Knyszek <mknyszek@google.com>
Reviewed-by: David Chase <drchase@google.com>

diff --git a/src/internal/trace/gc_test.go b/src/internal/trace/gc_test.go
index 39f28cc0f6977e96681247430c52be3593cd40b6..9c6d0fcb0e56d89dfd936abaf10cf6a1c17c35f3 100644 (file)
--- a/src/internal/trace/gc_test.go
+++ b/src/internal/trace/gc_test.go
@@ -118,7 +118,7 @@ func TestMMUTrace(t *testing.T) {
        }
        t.Run("V2", func(t *testing.T) {
                testPath := "testdata/tests/go122-gc-stress.test"
-               r, _, err := testtrace.ParseFile(testPath)
+               r, _, _, err := testtrace.ParseFile(testPath)
                if err != nil {
                        t.Fatalf("malformed test %s: bad trace file: %v", testPath, err)
                }

diff --git a/src/internal/trace/reader_test.go b/src/internal/trace/reader_test.go
index 37c21da667ef34c99f93f1d345a4ee2efdfeb544..b395183e0e91d28b203c1ab119e921d83bdf38bf 100644 (file)
--- a/src/internal/trace/reader_test.go
+++ b/src/internal/trace/reader_test.go
@@ -37,11 +37,11 @@ func TestReaderGolden(t *testing.T) {
                        t.Fatalf("failed to relativize testdata path: %v", err)
                }
                t.Run(testName, func(t *testing.T) {
-                       tr, exp, err := testtrace.ParseFile(testPath)
+                       tr, ver, exp, err := testtrace.ParseFile(testPath)
                        if err != nil {
                                t.Fatalf("failed to parse test file at %s: %v", testPath, err)
                        }
-                       testReader(t, tr, exp)
+                       testReader(t, tr, ver, exp)
                })
        }
 }
@@ -93,7 +93,7 @@ func FuzzReader(f *testing.F) {
        })
 }
 
-func testReader(t *testing.T, tr io.Reader, exp *testtrace.Expectation) {
+func testReader(t *testing.T, tr io.Reader, ver version.Version, exp *testtrace.Expectation) {
        r, err := trace.NewReader(tr)
        if err != nil {
                if err := exp.Check(err); err != nil {
@@ -102,6 +102,7 @@ func testReader(t *testing.T, tr io.Reader, exp *testtrace.Expectation) {
                return
        }
        v := testtrace.NewValidator()
+       v.GoVersion = ver
        for {
                ev, err := r.ReadEvent()
                if err == io.EOF {

diff --git a/src/internal/trace/summary_test.go b/src/internal/trace/summary_test.go
index 396bd5f0969f066d07fad76a982eabd5dd553f06..c5f1910262cb2acbc9c793c54c787d17b2bcc652 100644 (file)
--- a/src/internal/trace/summary_test.go
+++ b/src/internal/trace/summary_test.go
@@ -264,7 +264,7 @@ func basicGoroutineSummaryChecks(t *testing.T, summary *trace.GoroutineSummary)
 }
 
 func summarizeTraceTest(t *testing.T, testPath string) *trace.Summary {
-       trc, _, err := testtrace.ParseFile(testPath)
+       trc, _, _, err := testtrace.ParseFile(testPath)
        if err != nil {
                t.Fatalf("malformed test %s: bad trace file: %v", testPath, err)
        }
@@ -388,7 +388,7 @@ func basicGoroutineExecStatsChecks(t *testing.T, stats *trace.GoroutineExecStats
 
 func TestRelatedGoroutinesV2Trace(t *testing.T) {
        testPath := "testdata/tests/go122-gc-stress.test"
-       trc, _, err := testtrace.ParseFile(testPath)
+       trc, _, _, err := testtrace.ParseFile(testPath)
        if err != nil {
                t.Fatalf("malformed test %s: bad trace file: %v", testPath, err)
        }

diff --git a/src/internal/trace/testtrace/format.go b/src/internal/trace/testtrace/format.go
index 82b69340ae28e09b7855bac86b9c5d5a1d4311bb..5c3c64787d25827bd1c184e836c0106332cd40f0 100644 (file)
--- a/src/internal/trace/testtrace/format.go
+++ b/src/internal/trace/testtrace/format.go
@@ -8,33 +8,34 @@ import (
        "bytes"
        "fmt"
        "internal/trace/raw"
+       "internal/trace/version"
        "internal/txtar"
        "io"
 )
 
 // ParseFile parses a test file generated by the testgen package.
-func ParseFile(testPath string) (io.Reader, *Expectation, error) {
+func ParseFile(testPath string) (io.Reader, version.Version, *Expectation, error) {
        ar, err := txtar.ParseFile(testPath)
        if err != nil {
-               return nil, nil, fmt.Errorf("failed to read test file for %s: %v", testPath, err)
+               return nil, 0, nil, fmt.Errorf("failed to read test file for %s: %v", testPath, err)
        }
        if len(ar.Files) != 2 {
-               return nil, nil, fmt.Errorf("malformed test %s: wrong number of files", testPath)
+               return nil, 0, nil, fmt.Errorf("malformed test %s: wrong number of files", testPath)
        }
        if ar.Files[0].Name != "expect" {
-               return nil, nil, fmt.Errorf("malformed test %s: bad filename %s", testPath, ar.Files[0].Name)
+               return nil, 0, nil, fmt.Errorf("malformed test %s: bad filename %s", testPath, ar.Files[0].Name)
        }
        if ar.Files[1].Name != "trace" {
-               return nil, nil, fmt.Errorf("malformed test %s: bad filename %s", testPath, ar.Files[1].Name)
+               return nil, 0, nil, fmt.Errorf("malformed test %s: bad filename %s", testPath, ar.Files[1].Name)
        }
        tr, err := raw.NewTextReader(bytes.NewReader(ar.Files[1].Data))
        if err != nil {
-               return nil, nil, fmt.Errorf("malformed test %s: bad trace file: %v", testPath, err)
+               return nil, 0, nil, fmt.Errorf("malformed test %s: bad trace file: %v", testPath, err)
        }
        var buf bytes.Buffer
        tw, err := raw.NewWriter(&buf, tr.Version())
        if err != nil {
-               return nil, nil, fmt.Errorf("failed to create trace byte writer: %v", err)
+               return nil, 0, nil, fmt.Errorf("failed to create trace byte writer: %v", err)
        }
        for {
                ev, err := tr.ReadEvent()
@@ -42,15 +43,15 @@ func ParseFile(testPath string) (io.Reader, *Expectation, error) {
                        break
                }
                if err != nil {
-                       return nil, nil, fmt.Errorf("malformed test %s: bad trace file: %v", testPath, err)
+                       return nil, 0, nil, fmt.Errorf("malformed test %s: bad trace file: %v", testPath, err)
                }
                if err := tw.WriteEvent(ev); err != nil {
-                       return nil, nil, fmt.Errorf("internal error during %s: failed to write trace bytes: %v", testPath, err)
+                       return nil, 0, nil, fmt.Errorf("internal error during %s: failed to write trace bytes: %v", testPath, err)
                }
        }
        exp, err := ParseExpectation(ar.Files[0].Data)
        if err != nil {
-               return nil, nil, fmt.Errorf("internal error during %s: failed to parse expectation %q: %v", testPath, string(ar.Files[0].Data), err)
+               return nil, 0, nil, fmt.Errorf("internal error during %s: failed to parse expectation %q: %v", testPath, string(ar.Files[0].Data), err)
        }
-       return &buf, exp, nil
+       return &buf, tr.Version(), exp, nil
 }

diff --git a/src/internal/trace/testtrace/validation.go b/src/internal/trace/testtrace/validation.go
index f61f7a3ffa603161b682922829c2c873d0b07436..da0e871287c235c63ac75fc3a67b0ed867a461c7 100644 (file)
--- a/src/internal/trace/testtrace/validation.go
+++ b/src/internal/trace/testtrace/validation.go
@@ -8,20 +8,21 @@ import (
        "errors"
        "fmt"
        "internal/trace"
+       "internal/trace/version"
        "slices"
        "strings"
 )
 
 // Validator is a type used for validating a stream of trace.Events.
 type Validator struct {
-       lastTs trace.Time
-       gs     map[trace.GoID]*goState
-       ps     map[trace.ProcID]*procState
-       ms     map[trace.ThreadID]*schedContext
-       ranges map[trace.ResourceID][]string
-       tasks  map[trace.TaskID]string
-       nSync  int
-       Go121  bool
+       lastTs    trace.Time
+       gs        map[trace.GoID]*goState
+       ps        map[trace.ProcID]*procState
+       ms        map[trace.ThreadID]*schedContext
+       ranges    map[trace.ResourceID][]string
+       tasks     map[trace.TaskID]string
+       lastSync  trace.Sync
+       GoVersion version.Version
 }
 
 type schedContext struct {
@@ -43,11 +44,12 @@ type procState struct {
 // NewValidator creates a new Validator.
 func NewValidator() *Validator {
        return &Validator{
-               gs:     make(map[trace.GoID]*goState),
-               ps:     make(map[trace.ProcID]*procState),
-               ms:     make(map[trace.ThreadID]*schedContext),
-               ranges: make(map[trace.ResourceID][]string),
-               tasks:  make(map[trace.TaskID]string),
+               gs:        make(map[trace.GoID]*goState),
+               ps:        make(map[trace.ProcID]*procState),
+               ms:        make(map[trace.ThreadID]*schedContext),
+               ranges:    make(map[trace.ResourceID][]string),
+               tasks:     make(map[trace.TaskID]string),
+               GoVersion: version.Current,
        }
 }
 
@@ -74,10 +76,38 @@ func (v *Validator) Event(ev trace.Event) error {
        switch ev.Kind() {
        case trace.EventSync:
                s := ev.Sync()
-               if s.N != v.nSync+1 {
-                       e.Errorf("sync count is not sequential: expected %d, got %d", v.nSync+1, s.N)
+               if s.N != v.lastSync.N+1 {
+                       e.Errorf("sync count is not sequential: expected %d, got %d", v.lastSync.N+1, s.N)
                }
-               v.nSync = s.N
+               // The trace reader currently emits synthetic sync events at the end of
+               // a trace. Those don't contain clock snapshots data, so we don't try
+               // to validate them.
+               //
+               // TODO(felixge): Drop the synthetic syncs as discussed in CL 653576.
+               if v.GoVersion >= version.Go125 && !(s.N > 1 && s.ClockSnapshot == nil) {
+                       if s.ClockSnapshot == nil {
+                               e.Errorf("sync %d has no clock snapshot", s.N)
+                       }
+                       if s.ClockSnapshot.Wall.IsZero() {
+                               e.Errorf("sync %d has zero wall time", s.N)
+                       }
+                       if s.ClockSnapshot.Mono == 0 {
+                               e.Errorf("sync %d has zero mono time", s.N)
+                       }
+                       if s.ClockSnapshot.Trace == 0 {
+                               e.Errorf("sync %d has zero trace time", s.N)
+                       }
+                       if s.N >= 2 && !s.ClockSnapshot.Wall.After(v.lastSync.ClockSnapshot.Wall) {
+                               e.Errorf("sync %d has non-increasing wall time: %v vs %v", s.N, s.ClockSnapshot.Wall, v.lastSync.ClockSnapshot.Wall)
+                       }
+                       if s.N >= 2 && !(s.ClockSnapshot.Mono > v.lastSync.ClockSnapshot.Mono) {
+                               e.Errorf("sync %d has non-increasing mono time: %v vs %v", s.N, s.ClockSnapshot.Mono, v.lastSync.ClockSnapshot.Mono)
+                       }
+                       if s.N >= 2 && !(s.ClockSnapshot.Trace > v.lastSync.ClockSnapshot.Trace) {
+                               e.Errorf("sync %d has non-increasing trace time: %v vs %v", s.N, s.ClockSnapshot.Trace, v.lastSync.ClockSnapshot.Trace)
+                       }
+               }
+               v.lastSync = s
        case trace.EventMetric:
                m := ev.Metric()
                if !strings.Contains(m.Name, ":") {
@@ -143,7 +173,7 @@ func (v *Validator) Event(ev trace.Event) error {
                        if new == trace.GoUndetermined {
                                e.Errorf("transition to undetermined state for goroutine %d", id)
                        }
-                       if v.nSync > 1 && old == trace.GoUndetermined {
+                       if v.lastSync.N > 1 && old == trace.GoUndetermined {
                                e.Errorf("undetermined goroutine %d after first global sync", id)
                        }
                        if new == trace.GoNotExist && v.hasAnyRange(trace.MakeResourceID(id)) {
@@ -196,7 +226,7 @@ func (v *Validator) Event(ev trace.Event) error {
                        if new == trace.ProcUndetermined {
                                e.Errorf("transition to undetermined state for proc %d", id)
                        }
-                       if v.nSync > 1 && old == trace.ProcUndetermined {
+                       if v.lastSync.N > 1 && old == trace.ProcUndetermined {
                                e.Errorf("undetermined proc %d after first global sync", id)
                        }
                        if new == trace.ProcNotExist && v.hasAnyRange(trace.MakeResourceID(id)) {
@@ -325,7 +355,7 @@ func (v *Validator) getOrCreateThread(e *errAccumulator, ev trace.Event, m trace
                // Be lenient about GoUndetermined -> GoSyscall transitions if they
                // originate from an old trace. These transitions lack thread
                // information in trace formats older than 1.22.
-               if !v.Go121 {
+               if v.GoVersion >= version.Go122 {
                        return false
                }
                if ev.Kind() != trace.EventStateTransition {

diff --git a/src/internal/trace/trace_test.go b/src/internal/trace/trace_test.go
index 4ff87c1ede6ac680d16fa3fec255dc307be15cfd..8c40e84a816d4f0a5d6d177683c5a850f25f9cc2 100644 (file)
--- a/src/internal/trace/trace_test.go
+++ b/src/internal/trace/trace_test.go
@@ -12,6 +12,7 @@ import (
        "internal/testenv"
        "internal/trace"
        "internal/trace/testtrace"
+       "internal/trace/version"
        "io"
        "os"
        "path/filepath"
@@ -617,7 +618,7 @@ func testTraceProg(t *testing.T, progName string, extra func(t *testing.T, trace
                tb := traceBuf.Bytes()
 
                // Test the trace and the parser.
-               testReader(t, bytes.NewReader(tb), testtrace.ExpectSuccess())
+               testReader(t, bytes.NewReader(tb), version.Current, testtrace.ExpectSuccess())
 
                // Run some extra validation.
                if !t.Failed() && extra != nil {

diff --git a/src/internal/trace/tracev1_test.go b/src/internal/trace/tracev1_test.go
index 008c7535c9f35f56271ed11ba536b8163d10a328..42a83718877e1f00e8d3354c14f6f316a58a70d8 100644 (file)
--- a/src/internal/trace/tracev1_test.go
+++ b/src/internal/trace/tracev1_test.go
@@ -7,6 +7,7 @@ package trace_test
 import (
        "internal/trace"
        "internal/trace/testtrace"
+       "internal/trace/version"
        "io"
        "os"
        "path/filepath"
@@ -38,7 +39,7 @@ func TestTraceV1(t *testing.T) {
                        }
 
                        v := testtrace.NewValidator()
-                       v.Go121 = true
+                       v.GoVersion = version.Go121
                        for {
                                ev, err := tr.ReadEvent()
                                if err != nil {