internal/trace: be stricter about allowed events in v2 trace versions

Currently all v2 trace versions, Go 1.22 and Go 1.23, share a full set
of specs. This is mostly OK, but it means quite a few events will be
accepted for 1.22 traces that should be rejected. This change fixes that
by limiting which event specs are returned by version.Version.Specs for
Go 1.22.

While we're here, let's be stricter about event names too, and move
tracev2.EventString to be a method on the version, so we can be more
precise. An intended consequence of this move is that tracev2 no longer
depends on fmt, since we will want the runtime to depend on tracev2 in
the near future.

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

diff --git a/src/go/build/deps_test.go b/src/go/build/deps_test.go
index 5212db740ee6fa32fdf2651f619bfb5afb3297bd..f2de39a0825f609195538fa282741529348ea29f 100644 (file)
--- a/src/go/build/deps_test.go
+++ b/src/go/build/deps_test.go
@@ -58,6 +58,7 @@ var depsRules = `
          internal/platform,
          internal/profilerecord,
          internal/syslist,
+         internal/trace/tracev2/event,
          internal/trace/traceviewer/format,
          log/internal,
          math/bits,
@@ -698,9 +699,6 @@ var depsRules = `
        < crypto/internal/fips140/check/checktest;
 
        # v2 execution trace parser.
-       FMT
-       < internal/trace/tracev2/event;
-
        internal/trace/tracev2/event
        < internal/trace/tracev2;
 

diff --git a/src/internal/trace/batch.go b/src/internal/trace/batch.go
index ba22bfde38dc27153d3ea85a7f4b5623dcfd25ce..0dc87321a6936422984d8660aa5cc302568da888 100644 (file)
--- a/src/internal/trace/batch.go
+++ b/src/internal/trace/batch.go
@@ -53,7 +53,7 @@ func readBatch(r interface {
                return batch{}, 0, err
        }
        if typ := event.Type(b); typ != tracev2.EvEventBatch && typ != tracev2.EvExperimentalBatch {
-               return batch{}, 0, fmt.Errorf("expected batch event, got %s", tracev2.EventString(typ))
+               return batch{}, 0, fmt.Errorf("expected batch event, got event %d", typ)
        }
 
        // Read the experiment of we have one.

diff --git a/src/internal/trace/event.go b/src/internal/trace/event.go
index 67f1e382306d2754617962e8b13da951aa2bc565..fa1daf3698004d8032f7e886f2b741bff6155600 100644 (file)
--- a/src/internal/trace/event.go
+++ b/src/internal/trace/event.go
@@ -430,7 +430,7 @@ func (e Event) Metric() Metric {
                m.Name = "/gc/heap/goal:bytes"
                m.Value = Value{kind: ValueUint64, scalar: e.base.args[0]}
        default:
-               panic(fmt.Sprintf("internal error: unexpected event type for Metric kind: %s", tracev2.EventString(e.base.typ)))
+               panic(fmt.Sprintf("internal error: unexpected wire-format event type for Metric kind: %d", e.base.typ))
        }
        return m
 }
@@ -443,7 +443,7 @@ func (e Event) Label() Label {
                panic("Label called on non-Label event")
        }
        if e.base.typ != tracev2.EvGoLabel {
-               panic(fmt.Sprintf("internal error: unexpected event type for Label kind: %s", tracev2.EventString(e.base.typ)))
+               panic(fmt.Sprintf("internal error: unexpected wire-format event type for Label kind: %d", e.base.typ))
        }
        return Label{
                Label:    e.table.strings.mustGet(stringID(e.base.args[0])),
@@ -486,7 +486,7 @@ func (e Event) Range() Range {
                        r.Scope.id = int64(e.Goroutine())
                }
        default:
-               panic(fmt.Sprintf("internal error: unexpected event type for Range kind: %s", tracev2.EventString(e.base.typ)))
+               panic(fmt.Sprintf("internal error: unexpected wire-event type for Range kind: %d", e.base.typ))
        }
        return r
 }
@@ -530,7 +530,7 @@ func (e Event) Task() Task {
                parentID = TaskID(e.base.extra(version.Go122)[0])
                typ = e.table.getExtraString(extraStringID(e.base.extra(version.Go122)[1]))
        default:
-               panic(fmt.Sprintf("internal error: unexpected event type for Task kind: %s", tracev2.EventString(e.base.typ)))
+               panic(fmt.Sprintf("internal error: unexpected wire-format event type for Task kind: %d", e.base.typ))
        }
        return Task{
                ID:     TaskID(e.base.args[0]),
@@ -547,7 +547,7 @@ func (e Event) Region() Region {
                panic("Region called on non-Region event")
        }
        if e.base.typ != tracev2.EvUserRegionBegin && e.base.typ != tracev2.EvUserRegionEnd {
-               panic(fmt.Sprintf("internal error: unexpected event type for Region kind: %s", tracev2.EventString(e.base.typ)))
+               panic(fmt.Sprintf("internal error: unexpected wire-format event type for Region kind: %d", e.base.typ))
        }
        return Region{
                Task: TaskID(e.base.args[0]),
@@ -563,7 +563,7 @@ func (e Event) Log() Log {
                panic("Log called on non-Log event")
        }
        if e.base.typ != tracev2.EvUserLog {
-               panic(fmt.Sprintf("internal error: unexpected event type for Log kind: %s", tracev2.EventString(e.base.typ)))
+               panic(fmt.Sprintf("internal error: unexpected wire-format event type for Log kind: %d", e.base.typ))
        }
        return Log{
                Task:     TaskID(e.base.args[0]),
@@ -642,7 +642,7 @@ func (e Event) StateTransition() StateTransition {
                from, to := packedStatus>>32, packedStatus&((1<<32)-1)
                s = goStateTransition(GoID(e.base.args[0]), GoState(from), tracev2GoStatus2GoState[to])
        default:
-               panic(fmt.Sprintf("internal error: unexpected event type for StateTransition kind: %s", tracev2.EventString(e.base.typ)))
+               panic(fmt.Sprintf("internal error: unexpected wire-format event type for StateTransition kind: %d", e.base.typ))
        }
        return s
 }

diff --git a/src/internal/trace/order.go b/src/internal/trace/order.go
index 8028f61a83e57af0ad587eec2f60a79c416aa631..3e7ed8941b55e1c6a5a4bf4c8a874de0022a05ba 100644 (file)
--- a/src/internal/trace/order.go
+++ b/src/internal/trace/order.go
@@ -22,6 +22,7 @@ import (
 // add completed events to the ordering. Next is used to pick
 // off events in the ordering.
 type ordering struct {
+       traceVer    version.Version
        gStates     map[GoID]*gState
        pStates     map[ProcID]*pState // TODO: The keys are dense, so this can be a slice.
        mStates     map[ThreadID]*mState
@@ -88,6 +89,10 @@ func (o *ordering) Advance(ev *baseEvent, evt *evTable, m ThreadID, gen uint64)
        return ok, err
 }
 
+func (o *ordering) evName(typ event.Type) string {
+       return o.traceVer.EventName(typ)
+}
+
 type orderingHandleFunc func(o *ordering, ev *baseEvent, evt *evTable, m ThreadID, gen uint64, curCtx schedCtx) (schedCtx, bool, error)
 
 var orderingDispatch = [256]orderingHandleFunc{
@@ -270,10 +275,10 @@ func (o *ordering) advanceProcStop(ev *baseEvent, evt *evTable, m ThreadID, gen
        // ProcStop doesn't need a sequence number.
        state, ok := o.pStates[curCtx.P]
        if !ok {
-               return curCtx, false, fmt.Errorf("event %s for proc (%v) that doesn't exist", tracev2.EventString(ev.typ), curCtx.P)
+               return curCtx, false, fmt.Errorf("event %s for proc (%v) that doesn't exist", o.evName(ev.typ), curCtx.P)
        }
        if state.status != tracev2.ProcRunning && state.status != tracev2.ProcSyscall {
-               return curCtx, false, fmt.Errorf("%s event for proc that's not %s or %s", tracev2.EventString(ev.typ), tracev2.ProcRunning, tracev2.ProcSyscall)
+               return curCtx, false, fmt.Errorf("%s event for proc that's not %s or %s", o.evName(ev.typ), tracev2.ProcRunning, tracev2.ProcSyscall)
        }
        reqs := schedReqs{M: mustHave, P: mustHave, G: mayHave}
        if err := validateCtx(curCtx, reqs); err != nil {
@@ -443,7 +448,7 @@ func (o *ordering) advanceGoCreate(ev *baseEvent, evt *evTable, m ThreadID, gen
        }
        // If we have a goroutine, it must be running.
        if state, ok := o.gStates[curCtx.G]; ok && state.status != tracev2.GoRunning {
-               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", tracev2.EventString(ev.typ), GoRunning)
+               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", o.evName(ev.typ), GoRunning)
        }
        // This goroutine created another. Add a state for it.
        newgid := GoID(ev.args[0])
@@ -468,10 +473,10 @@ func (o *ordering) advanceGoStopExec(ev *baseEvent, evt *evTable, m ThreadID, ge
        }
        state, ok := o.gStates[curCtx.G]
        if !ok {
-               return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", tracev2.EventString(ev.typ), curCtx.G)
+               return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", o.evName(ev.typ), curCtx.G)
        }
        if state.status != tracev2.GoRunning {
-               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", tracev2.EventString(ev.typ), GoRunning)
+               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", o.evName(ev.typ), GoRunning)
        }
        // Handle each case slightly differently; we just group them together
        // because they have shared preconditions.
@@ -551,10 +556,10 @@ func (o *ordering) advanceGoSwitch(ev *baseEvent, evt *evTable, m ThreadID, gen
        }
        curGState, ok := o.gStates[curCtx.G]
        if !ok {
-               return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", tracev2.EventString(ev.typ), curCtx.G)
+               return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", o.evName(ev.typ), curCtx.G)
        }
        if curGState.status != tracev2.GoRunning {
-               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", tracev2.EventString(ev.typ), GoRunning)
+               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", o.evName(ev.typ), GoRunning)
        }
        nextg := GoID(ev.args[0])
        seq := makeSeq(gen, ev.args[1]) // seq is for nextg, not curCtx.G.
@@ -606,16 +611,16 @@ func (o *ordering) advanceGoSyscallBegin(ev *baseEvent, evt *evTable, m ThreadID
        }
        state, ok := o.gStates[curCtx.G]
        if !ok {
-               return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", tracev2.EventString(ev.typ), curCtx.G)
+               return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", o.evName(ev.typ), curCtx.G)
        }
        if state.status != tracev2.GoRunning {
-               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", tracev2.EventString(ev.typ), GoRunning)
+               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", o.evName(ev.typ), GoRunning)
        }
        // Goroutine entered a syscall. It's still running on this P and M.
        state.status = tracev2.GoSyscall
        pState, ok := o.pStates[curCtx.P]
        if !ok {
-               return curCtx, false, fmt.Errorf("uninitialized proc %d found during %s", curCtx.P, tracev2.EventString(ev.typ))
+               return curCtx, false, fmt.Errorf("uninitialized proc %d found during %s", curCtx.P, o.evName(ev.typ))
        }
        pState.status = tracev2.ProcSyscall
        // Validate the P sequence number on the event and advance it.
@@ -631,7 +636,7 @@ func (o *ordering) advanceGoSyscallBegin(ev *baseEvent, evt *evTable, m ThreadID
        // to back off and see if any other events will advance. This is a running P.
        pSeq := makeSeq(gen, ev.args[0])
        if !pSeq.succeeds(pState.seq) {
-               return curCtx, false, fmt.Errorf("failed to advance %s: can't make sequence: %s -> %s", tracev2.EventString(ev.typ), pState.seq, pSeq)
+               return curCtx, false, fmt.Errorf("failed to advance %s: can't make sequence: %s -> %s", o.evName(ev.typ), pState.seq, pSeq)
        }
        pState.seq = pSeq
        o.queue.push(Event{table: evt, ctx: curCtx, base: *ev})
@@ -647,17 +652,17 @@ func (o *ordering) advanceGoSyscallEnd(ev *baseEvent, evt *evTable, m ThreadID,
        }
        state, ok := o.gStates[curCtx.G]
        if !ok {
-               return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", tracev2.EventString(ev.typ), curCtx.G)
+               return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", o.evName(ev.typ), curCtx.G)
        }
        if state.status != tracev2.GoSyscall {
-               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", tracev2.EventString(ev.typ), GoRunning)
+               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", o.evName(ev.typ), GoRunning)
        }
        state.status = tracev2.GoRunning
 
        // Transfer the P back to running from syscall.
        pState, ok := o.pStates[curCtx.P]
        if !ok {
-               return curCtx, false, fmt.Errorf("uninitialized proc %d found during %s", curCtx.P, tracev2.EventString(ev.typ))
+               return curCtx, false, fmt.Errorf("uninitialized proc %d found during %s", curCtx.P, o.evName(ev.typ))
        }
        if pState.status != tracev2.ProcSyscall {
                return curCtx, false, fmt.Errorf("expected proc %d in state %v, but got %v instead", curCtx.P, tracev2.ProcSyscall, pState.status)
@@ -681,7 +686,7 @@ func (o *ordering) advanceGoSyscallEndBlocked(ev *baseEvent, evt *evTable, m Thr
        if curCtx.P != NoProc {
                pState, ok := o.pStates[curCtx.P]
                if !ok {
-                       return curCtx, false, fmt.Errorf("uninitialized proc %d found during %s", curCtx.P, tracev2.EventString(ev.typ))
+                       return curCtx, false, fmt.Errorf("uninitialized proc %d found during %s", curCtx.P, o.evName(ev.typ))
                }
                if pState.status == tracev2.ProcSyscall {
                        return curCtx, false, nil
@@ -694,10 +699,10 @@ func (o *ordering) advanceGoSyscallEndBlocked(ev *baseEvent, evt *evTable, m Thr
        }
        state, ok := o.gStates[curCtx.G]
        if !ok {
-               return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", tracev2.EventString(ev.typ), curCtx.G)
+               return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", o.evName(ev.typ), curCtx.G)
        }
        if state.status != tracev2.GoSyscall {
-               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", tracev2.EventString(ev.typ), GoRunning)
+               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", o.evName(ev.typ), GoRunning)
        }
        newCtx := curCtx
        newCtx.G = NoGoroutine
@@ -749,10 +754,10 @@ func (o *ordering) advanceGoDestroySyscall(ev *baseEvent, evt *evTable, m Thread
        // Check to make sure the goroutine exists in the right state.
        state, ok := o.gStates[curCtx.G]
        if !ok {
-               return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", tracev2.EventString(ev.typ), curCtx.G)
+               return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", o.evName(ev.typ), curCtx.G)
        }
        if state.status != tracev2.GoSyscall {
-               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %v", tracev2.EventString(ev.typ), GoSyscall)
+               return curCtx, false, fmt.Errorf("%s event for goroutine that's not %v", o.evName(ev.typ), GoSyscall)
        }
        // This goroutine is exiting itself.
        delete(o.gStates, curCtx.G)
@@ -763,10 +768,10 @@ func (o *ordering) advanceGoDestroySyscall(ev *baseEvent, evt *evTable, m Thread
        if curCtx.P != NoProc {
                pState, ok := o.pStates[curCtx.P]
                if !ok {
-                       return curCtx, false, fmt.Errorf("found invalid proc %d during %s", curCtx.P, tracev2.EventString(ev.typ))
+                       return curCtx, false, fmt.Errorf("found invalid proc %d during %s", curCtx.P, o.evName(ev.typ))
                }
                if pState.status != tracev2.ProcSyscall {
-                       return curCtx, false, fmt.Errorf("proc %d in unexpected state %s during %s", curCtx.P, pState.status, tracev2.EventString(ev.typ))
+                       return curCtx, false, fmt.Errorf("proc %d in unexpected state %s during %s", curCtx.P, pState.status, o.evName(ev.typ))
                }
                // See the go122-create-syscall-reuse-thread-id test case for more details.
                pState.status = tracev2.ProcSyscallAbandoned
@@ -1046,7 +1051,7 @@ func (o *ordering) advanceGoRangeActive(ev *baseEvent, evt *evTable, m ThreadID,
        // current scheduler context.
        gState, ok := o.gStates[gid]
        if !ok {
-               return curCtx, false, fmt.Errorf("uninitialized goroutine %d found during %s", gid, tracev2.EventString(ev.typ))
+               return curCtx, false, fmt.Errorf("uninitialized goroutine %d found during %s", gid, o.evName(ev.typ))
        }
        if err := gState.activeRange(makeRangeType(ev.typ, 0), gen == o.initialGen); err != nil {
                return curCtx, false, err

diff --git a/src/internal/trace/reader.go b/src/internal/trace/reader.go
index 699febeed4b32773003a70053aa5b96442262e5f..81710c0125eda595770da019ad1d30764f72e1ed 100644 (file)
--- a/src/internal/trace/reader.go
+++ b/src/internal/trace/reader.go
@@ -22,6 +22,7 @@ import (
 // event as the first event, and a Sync event as the last event.
 // (There may also be any number of Sync events in the middle, too.)
 type Reader struct {
+       version    version.Version
        r          *bufio.Reader
        lastTs     Time
        gen        *generation
@@ -54,8 +55,10 @@ func NewReader(r io.Reader) (*Reader, error) {
                }, nil
        case version.Go122, version.Go123:
                return &Reader{
-                       r: br,
+                       version: v,
+                       r:       br,
                        order: ordering{
+                               traceVer:    v,
                                mStates:     make(map[ThreadID]*mState),
                                pStates:     make(map[ProcID]*pState),
                                gStates:     make(map[GoID]*gState),

diff --git a/src/internal/trace/tracev2/event.go b/src/internal/trace/tracev2/event.go
index 48ed0eba1bc41543adf01351f46cd4317d8b24ca..308ae679e977a018fac8918cc91710553c558cb1 100644 (file)
--- a/src/internal/trace/tracev2/event.go
+++ b/src/internal/trace/tracev2/event.go
@@ -5,7 +5,6 @@
 package tracev2
 
 import (
-       "fmt"
        "internal/trace/tracev2/event"
 )
 
@@ -116,14 +115,6 @@ const (
        EvGoroutineStackFree  // stack free [timestamp, id]
 )
 
-// EventString returns the name of a Go 1.22 event.
-func EventString(typ event.Type) string {
-       if int(typ) < len(specs) {
-               return specs[typ].Name
-       }
-       return fmt.Sprintf("Invalid(%d)", typ)
-}
-
 func Specs() []event.Spec {
        return specs[:]
 }

diff --git a/src/internal/trace/version/version.go b/src/internal/trace/version/version.go
index a42cc708d241a00934d9fd7dffbd87e2ef65a74c..50a674bd234cdb3d26c6a3f41f1e2049887d73e1 100644 (file)
--- a/src/internal/trace/version/version.go
+++ b/src/internal/trace/version/version.go
@@ -16,11 +16,11 @@ import (
 type Version uint32
 
 const (
-       Go111   Version = 11
-       Go119   Version = 19
-       Go121   Version = 21
-       Go122   Version = 22
-       Go123   Version = 23
+       Go111   Version = 11 // v1
+       Go119   Version = 19 // v1
+       Go121   Version = 21 // v1
+       Go122   Version = 22 // v2
+       Go123   Version = 23 // v2
        Current         = Go123
 )
 
@@ -31,10 +31,7 @@ var versions = map[Version][]event.Spec{
        Go119: nil,
        Go121: nil,
 
-       Go122: tracev2.Specs(),
-       // Go 1.23 adds backwards-incompatible events, but
-       // traces produced by Go 1.22 are also always valid
-       // Go 1.23 traces.
+       Go122: tracev2.Specs()[:tracev2.EvUserLog+1], // All events after are Go 1.23+.
        Go123: tracev2.Specs(),
 }
 
@@ -43,6 +40,22 @@ func (v Version) Specs() []event.Spec {
        return versions[v]
 }
 
+// EventName returns a string name of a wire format event
+// for a particular trace version.
+func (v Version) EventName(typ event.Type) string {
+       if !v.Valid() {
+               return "<invalid trace version>"
+       }
+       s := v.Specs()
+       if len(s) == 0 {
+               return "<v1 trace event type>"
+       }
+       if int(typ) < len(s) && s[typ].Name != "" {
+               return s[typ].Name
+       }
+       return fmt.Sprintf("Invalid(%d)", typ)
+}
+
 func (v Version) Valid() bool {
        _, ok := versions[v]
        return ok