]> Cypherpunks repositories - gostls13.git/commitdiff
internal/trace: add generator tests for sync events
authorFelix Geisendörfer <felix.geisendoerfer@datadoghq.com>
Fri, 28 Feb 2025 16:30:54 +0000 (17:30 +0100)
committerGopher Robot <gobot@golang.org>
Wed, 21 May 2025 15:23:41 +0000 (08:23 -0700)
Add generator tests that verify the timestamps for the sync events
emitted in the go1.25 trace format and earlier versions.

Add the ability to configure the properties of the per-generation sync
batches in testgen. Also refactor testgen to produce more realistic
timestamps by keeping track of lastTs and using it for structural
batches that don't have their own timestamps. Otherwise they default to
zero which means the minTs of the generation can't be controlled.

For #69869

Change-Id: I92a49b8281bc4169b63e13c030c1de7720cd6f26
Reviewed-on: https://go-review.googlesource.com/c/go/+/653876
Auto-Submit: Michael Knyszek <mknyszek@google.com>
Reviewed-by: David Chase <drchase@google.com>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Reviewed-by: Michael Knyszek <mknyszek@google.com>
src/internal/trace/internal/testgen/trace.go
src/internal/trace/reader_test.go
src/internal/trace/testdata/generators/go123-sync.go [new file with mode: 0644]
src/internal/trace/testdata/generators/go125-sync.go [new file with mode: 0644]
src/internal/trace/testdata/tests/go123-sync.test [new file with mode: 0644]
src/internal/trace/testdata/tests/go125-sync.test [new file with mode: 0644]

index af469f525c67ec7de3ac4d58a355188bc56a8a54..415acaccae33bdb080617a028a143f7186cd93e3 100644 (file)
@@ -11,6 +11,7 @@ import (
        "os"
        "regexp"
        "strings"
+       "time"
 
        "internal/trace"
        "internal/trace/raw"
@@ -55,6 +56,7 @@ type Trace struct {
        events          []raw.Event
        gens            []*Generation
        validTimestamps bool
+       lastTs          Time
 
        // Expectation state.
        bad      bool
@@ -107,6 +109,7 @@ func (t *Trace) Generation(gen uint64) *Generation {
                gen:     gen,
                strings: make(map[string]uint64),
                stacks:  make(map[stack]uint64),
+               sync:    sync{freq: 15625000},
        }
        t.gens = append(t.gens, g)
        return g
@@ -178,6 +181,7 @@ type Generation struct {
        batches []*Batch
        strings map[string]uint64
        stacks  map[stack]uint64
+       sync    sync
 
        // Options applied when Trace.Generate is called.
        ignoreStringBatchSizeLimit bool
@@ -188,14 +192,11 @@ type Generation struct {
 //
 // This is convenience function for generating correct batches.
 func (g *Generation) Batch(thread trace.ThreadID, time Time) *Batch {
-       if !g.trace.validTimestamps {
-               time = 0
-       }
        b := &Batch{
-               gen:       g,
-               thread:    thread,
-               timestamp: time,
+               gen:    g,
+               thread: thread,
        }
+       b.setTimestamp(time)
        g.batches = append(g.batches, b)
        return b
 }
@@ -238,20 +239,59 @@ func (g *Generation) Stack(stk []trace.StackFrame) uint64 {
        return id
 }
 
+// Sync configures the sync batch for the generation. For go1.25 and later,
+// the time value is the timestamp of the EvClockSnapshot event. For earlier
+// version, the time value is the timestamp of the batch containing a lone
+// EvFrequency event.
+func (g *Generation) Sync(freq uint64, time Time, mono uint64, wall time.Time) {
+       if g.trace.ver < version.Go125 && (mono != 0 || !wall.IsZero()) {
+               panic(fmt.Sprintf("mono and wall args are not supported in go1.%d traces", g.trace.ver))
+       }
+       g.sync = sync{
+               freq:     freq,
+               time:     time,
+               mono:     mono,
+               walltime: wall,
+       }
+}
+
+type sync struct {
+       freq     uint64
+       time     Time
+       mono     uint64
+       walltime time.Time
+}
+
 // writeEventsTo emits event batches in the generation to tw.
 func (g *Generation) writeEventsTo(tw *raw.TextWriter) {
+       // go1.25+ sync batches are emitted at the start of the generation.
+       if g.trace.ver >= version.Go125 {
+               b := g.newStructuralBatch()
+               // Arrange for EvClockSnapshot's ts to be exactly g.sync.time.
+               b.setTimestamp(g.sync.time - 1)
+               b.RawEvent(tracev2.EvSync, nil)
+               b.RawEvent(tracev2.EvFrequency, nil, g.sync.freq)
+               sec := uint64(g.sync.walltime.Unix())
+               nsec := uint64(g.sync.walltime.Nanosecond())
+               b.Event("ClockSnapshot", g.sync.mono, sec, nsec)
+               b.writeEventsTo(tw)
+       }
+
        // Write event batches for the generation.
        for _, b := range g.batches {
                b.writeEventsTo(tw)
        }
 
-       // Write frequency.
-       b := g.newStructuralBatch()
-       b.RawEvent(tracev2.EvFrequency, nil, 15625000)
-       b.writeEventsTo(tw)
+       // Write lone EvFrequency sync batch for older traces.
+       if g.trace.ver < version.Go125 {
+               b := g.newStructuralBatch()
+               b.setTimestamp(g.sync.time)
+               b.RawEvent(tracev2.EvFrequency, nil, g.sync.freq)
+               b.writeEventsTo(tw)
+       }
 
        // Write stacks.
-       b = g.newStructuralBatch()
+       b := g.newStructuralBatch()
        b.RawEvent(tracev2.EvStacks, nil)
        for stk, id := range g.stacks {
                stk := stk.stk[:stk.len]
@@ -285,7 +325,9 @@ func (g *Generation) writeEventsTo(tw *raw.TextWriter) {
 }
 
 func (g *Generation) newStructuralBatch() *Batch {
-       return &Batch{gen: g, thread: trace.NoThread}
+       b := &Batch{gen: g, thread: trace.NoThread}
+       b.setTimestamp(g.trace.lastTs + 1)
+       return b
 }
 
 // Batch represents an event batch.
@@ -310,6 +352,7 @@ func (b *Batch) Event(name string, args ...any) {
        if b.gen.trace.specs[ev].IsTimedEvent {
                if b.gen.trace.validTimestamps {
                        uintArgs = []uint64{1}
+                       b.gen.trace.lastTs += 1
                } else {
                        uintArgs = []uint64{0}
                }
@@ -333,7 +376,7 @@ func (b *Batch) uintArgFor(arg any, argSpec string) uint64 {
        }
        var u uint64
        switch typStr {
-       case "value":
+       case "value", "mono", "sec", "nsec":
                u = arg.(uint64)
        case "stack":
                u = b.gen.Stack(arg.([]trace.StackFrame))
@@ -392,6 +435,14 @@ func (b *Batch) writeEventsTo(tw *raw.TextWriter) {
        }
 }
 
+// setTimestamp sets the timestamp for the batch.
+func (b *Batch) setTimestamp(t Time) {
+       if b.gen.trace.validTimestamps {
+               b.timestamp = t
+               b.gen.trace.lastTs = t
+       }
+}
+
 // Seq represents a sequence counter.
 type Seq uint64
 
index b395183e0e91d28b203c1ab119e921d83bdf38bf..222d2dfa820d06d9d698860e6b514e49bd713c11 100644 (file)
@@ -13,6 +13,7 @@ import (
        "path/filepath"
        "strings"
        "testing"
+       "time"
 
        "internal/trace"
        "internal/trace/raw"
@@ -171,3 +172,76 @@ func dumpTraceToFile(t *testing.T, testName string, stress bool, b []byte) strin
        }
        return f.Name()
 }
+
+func TestTraceGenSync(t *testing.T) {
+       type sync struct {
+               Time          trace.Time
+               ClockSnapshot *trace.ClockSnapshot
+       }
+       runTest := func(testName string, wantSyncs []sync) {
+               t.Run(testName, func(t *testing.T) {
+                       testPath := "testdata/tests/" + testName
+                       r, _, _, err := testtrace.ParseFile(testPath)
+                       if err != nil {
+                               t.Fatalf("malformed test %s: bad trace file: %v", testPath, err)
+                       }
+                       tr, err := trace.NewReader(r)
+                       if err != nil {
+                               t.Fatalf("malformed test %s: bad trace file: %v", testPath, err)
+                       }
+                       var syncEvents []trace.Event
+                       for {
+                               ev, err := tr.ReadEvent()
+                               if err == io.EOF {
+                                       break
+                               }
+                               if err != nil {
+                                       t.Fatalf("malformed test %s: bad trace file: %v", testPath, err)
+                               }
+                               if ev.Kind() == trace.EventSync {
+                                       syncEvents = append(syncEvents, ev)
+                               }
+                       }
+
+                       if got, want := len(syncEvents), len(wantSyncs); got != want {
+                               t.Errorf("got %d sync events, want %d", got, want)
+                       }
+
+                       for i, want := range wantSyncs {
+                               got := syncEvents[i]
+                               gotSync := syncEvents[i].Sync()
+                               if got.Time() != want.Time {
+                                       t.Errorf("sync=%d got time %d, want %d", i+1, got.Time(), want.Time)
+                               }
+                               if gotSync.ClockSnapshot == nil && want.ClockSnapshot == nil {
+                                       continue
+                               }
+                               if gotSync.ClockSnapshot.Trace != want.ClockSnapshot.Trace {
+                                       t.Errorf("sync=%d got trace time %d, want %d", i+1, gotSync.ClockSnapshot.Trace, want.ClockSnapshot.Trace)
+                               }
+                               if !gotSync.ClockSnapshot.Wall.Equal(want.ClockSnapshot.Wall) {
+                                       t.Errorf("sync=%d got wall time %s, want %s", i+1, gotSync.ClockSnapshot.Wall, want.ClockSnapshot.Wall)
+                               }
+                               if gotSync.ClockSnapshot.Mono != want.ClockSnapshot.Mono {
+                                       t.Errorf("sync=%d got mono time %d, want %d", i+1, gotSync.ClockSnapshot.Mono, want.ClockSnapshot.Mono)
+                               }
+                       }
+               })
+       }
+
+       runTest("go123-sync.test", []sync{
+               {10, nil},
+               {40, nil},
+               // The EvFrequency batch for generation 3 is emitted at trace.Time(80),
+               // but 60 is the minTs of the generation, see b30 in the go generator.
+               {60, nil},
+               {63, nil},
+       })
+
+       runTest("go125-sync.test", []sync{
+               {9, &trace.ClockSnapshot{Trace: 10, Mono: 99, Wall: time.Date(2025, 2, 28, 15, 4, 9, 123, time.UTC)}},
+               {38, &trace.ClockSnapshot{Trace: 40, Mono: 199, Wall: time.Date(2025, 2, 28, 15, 4, 10, 123, time.UTC)}},
+               {58, &trace.ClockSnapshot{Trace: 60, Mono: 299, Wall: time.Date(2025, 2, 28, 15, 4, 11, 123, time.UTC)}},
+               {83, nil},
+       })
+}
diff --git a/src/internal/trace/testdata/generators/go123-sync.go b/src/internal/trace/testdata/generators/go123-sync.go
new file mode 100644 (file)
index 0000000..257581c
--- /dev/null
@@ -0,0 +1,30 @@
+// 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 main
+
+import (
+       "internal/trace"
+       "internal/trace/internal/testgen"
+       "internal/trace/tracev2"
+       "internal/trace/version"
+       "time"
+)
+
+func main() {
+       testgen.Main(version.Go123, gen)
+}
+
+func gen(t *testgen.Trace) {
+       g1 := t.Generation(1)
+       g1.Sync(1000000000, 10, 0, time.Time{})
+       b10 := g1.Batch(1, 15)
+       b10.Event("ProcStatus", trace.ProcID(0), tracev2.ProcRunning)
+       g2 := t.Generation(2)
+       g2.Sync(500000000, 20, 0, time.Time{})
+       g3 := t.Generation(3)
+       b30 := g3.Batch(1, 30)
+       b30.Event("ProcStatus", trace.ProcID(0), tracev2.ProcRunning)
+       g3.Sync(500000000, 40, 0, time.Time{})
+}
diff --git a/src/internal/trace/testdata/generators/go125-sync.go b/src/internal/trace/testdata/generators/go125-sync.go
new file mode 100644 (file)
index 0000000..30ebf67
--- /dev/null
@@ -0,0 +1,31 @@
+// 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 main
+
+import (
+       "internal/trace"
+       "internal/trace/internal/testgen"
+       "internal/trace/tracev2"
+       "internal/trace/version"
+       "time"
+)
+
+func main() {
+       testgen.Main(version.Go125, gen)
+}
+
+func gen(t *testgen.Trace) {
+       start := time.Date(2025, 2, 28, 15, 4, 9, 123, time.UTC)
+       g1 := t.Generation(1)
+       g1.Sync(1000000000, 10, 99, start)
+       b10 := g1.Batch(1, 15)
+       b10.Event("ProcStatus", trace.ProcID(0), tracev2.ProcRunning)
+       g2 := t.Generation(2)
+       g2.Sync(500000000, 20, 199, start.Add(1*time.Second))
+       g3 := t.Generation(3)
+       g3.Sync(500000000, 30, 299, start.Add(2*time.Second))
+       b30 := g3.Batch(1, 40)
+       b30.Event("ProcStatus", trace.ProcID(0), tracev2.ProcRunning)
+}
diff --git a/src/internal/trace/testdata/tests/go123-sync.test b/src/internal/trace/testdata/tests/go123-sync.test
new file mode 100644 (file)
index 0000000..44e98e6
--- /dev/null
@@ -0,0 +1,26 @@
+-- expect --
+SUCCESS
+-- trace --
+Trace Go1.23
+EventBatch gen=1 m=1 time=15 size=4
+ProcStatus dt=1 p=0 pstatus=1
+EventBatch gen=1 m=18446744073709551615 time=10 size=6
+Frequency freq=1000000000
+EventBatch gen=1 m=18446744073709551615 time=11 size=1
+Stacks
+EventBatch gen=1 m=18446744073709551615 time=12 size=1
+Strings
+EventBatch gen=2 m=18446744073709551615 time=20 size=6
+Frequency freq=500000000
+EventBatch gen=2 m=18446744073709551615 time=21 size=1
+Stacks
+EventBatch gen=2 m=18446744073709551615 time=22 size=1
+Strings
+EventBatch gen=3 m=1 time=30 size=4
+ProcStatus dt=1 p=0 pstatus=1
+EventBatch gen=3 m=18446744073709551615 time=40 size=6
+Frequency freq=500000000
+EventBatch gen=3 m=18446744073709551615 time=41 size=1
+Stacks
+EventBatch gen=3 m=18446744073709551615 time=42 size=1
+Strings
diff --git a/src/internal/trace/testdata/tests/go125-sync.test b/src/internal/trace/testdata/tests/go125-sync.test
new file mode 100644 (file)
index 0000000..dac3723
--- /dev/null
@@ -0,0 +1,32 @@
+-- expect --
+SUCCESS
+-- trace --
+Trace Go1.25
+EventBatch gen=1 m=18446744073709551615 time=9 size=16
+Sync
+Frequency freq=1000000000
+ClockSnapshot dt=1 mono=99 sec=1740755049 nsec=123
+EventBatch gen=1 m=1 time=15 size=4
+ProcStatus dt=1 p=0 pstatus=1
+EventBatch gen=1 m=18446744073709551615 time=11 size=1
+Stacks
+EventBatch gen=1 m=18446744073709551615 time=12 size=1
+Strings
+EventBatch gen=2 m=18446744073709551615 time=19 size=17
+Sync
+Frequency freq=500000000
+ClockSnapshot dt=1 mono=199 sec=1740755050 nsec=123
+EventBatch gen=2 m=18446744073709551615 time=21 size=1
+Stacks
+EventBatch gen=2 m=18446744073709551615 time=22 size=1
+Strings
+EventBatch gen=3 m=18446744073709551615 time=29 size=17
+Sync
+Frequency freq=500000000
+ClockSnapshot dt=1 mono=299 sec=1740755051 nsec=123
+EventBatch gen=3 m=1 time=40 size=4
+ProcStatus dt=1 p=0 pstatus=1
+EventBatch gen=3 m=18446744073709551615 time=31 size=1
+Stacks
+EventBatch gen=3 m=18446744073709551615 time=32 size=1
+Strings