diff --git a/src/internal/trace/internal/testgen/trace.go b/src/internal/trace/internal/testgen/trace.go index af469f525c..415acaccae 100644 --- a/src/internal/trace/internal/testgen/trace.go +++ b/src/internal/trace/internal/testgen/trace.go @@ -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 diff --git a/src/internal/trace/reader_test.go b/src/internal/trace/reader_test.go index b395183e0e..222d2dfa82 100644 --- a/src/internal/trace/reader_test.go +++ b/src/internal/trace/reader_test.go @@ -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 index 0000000000..257581c7ea --- /dev/null +++ b/src/internal/trace/testdata/generators/go123-sync.go @@ -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 index 0000000000..30ebf6717a --- /dev/null +++ b/src/internal/trace/testdata/generators/go125-sync.go @@ -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 index 0000000000..44e98e6c95 --- /dev/null +++ b/src/internal/trace/testdata/tests/go123-sync.test @@ -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 index 0000000000..dac3723b62 --- /dev/null +++ b/src/internal/trace/testdata/tests/go125-sync.test @@ -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