proposal: x/debug/trace: add package for parsing execution traces

@rhysh

As part of #60773 (tracking issue #57175) I've been working on a new parser for the execution tracer, and to save work down the line I've also been trying to come up with a nice API that would work well.

The goals of such an API would be to:

Enable custom analyses of traces.
Allow for streaming traces and performing on-line analyses.
Be both backward- and forward- compatible with new Go versions and trace wire formats.

Here are the requirements I have for such an API:

The API should be stream-based, regardless of whether the underlying trace format supports it.
Parsing a single trace in parallel is unsupported (part of the point of parsing is to serialize the stream anyway).
The API should expose some model of the Go scheduler explicitly. (This comes from an insight from @rhysh about the internal/trace API that doesn't actually expose e.g. the state machine goroutines go through (even though it already has to know about it), leaving users to figure it out again.)
The API should at least allow for an extension for efficient random access from local storage (e.g. loading from an mmap'd trace file).

Any such API is likely to have a fairly large surface. Rather than try to list the full API and debate its merits, we should experiment.

https://go.dev/cl/527875 is my first attempt at such an experiment to support the work done for #60773. The implementation is not quite fully baked (there may be bugs, and there's still some validation missing) but it already seems to work for non-trivial traces produced by https://go.dev/cl/494187 (with GOEXPERIMENT=exectracer2). (I'll update this section when it's ready, including with instructions on how to try it out.)

I plan to take this API and vendor it and/or copy it into the standard library to work as the implementation for supporting new traces in internal/trace. That'll help move #60773 along but it'll also give us some experience with using the API.

Once I get this API landed in x/exp, and the first cut of the new tracer for #60773, I'd like to invite people to experiment to both shake out bugs but also to identify deficiencies in the API.

For the proposal committee: there's nothing actionable here yet, but I figured I'd create an issue to track work and start a discussion.

Related to #62461.

CC @prattmic @aclements @dominikh @felixge @nsrip-dd @bboreham @rhysh

Change https://go.dev/cl/544655 mentions this issue: trace: export trace parsing API from std

@felixge

I uploaded CL of a decent first cut to golang.org/x/exp: https://go.dev/cl/544655.

@felixge and I got some experience using this to port cmd/trace over to the new trace parser, and here are some of my notes so far:

Syscalls should probably not be a state of a goroutine, but rather an EventRange set of events. Correct emission of syscall ranges really depended on treating them identically to EventRange ranges.
Detecting blocking syscalls is annoying if you don't know what to look for (proc goes idle while its goroutine is in a syscall). I think if we make syscalls EventRange events, then we can emit an EventStateTransition of GoRunning->GoWaiting when the goroutine blocks in a syscall. Of course, we'd still have the proc going idle, but the explicit signal would simplify a bunch of analysis.
EventRangeActive events are necessary to avoid loss of information, but using them correctly is a little hard. Arguably though, it's not any harder than dealing with GoUndetermined->GoWhatever transitions since the analysis needs to do the same kind of "this was true since the last sync" accounting. Perhaps just examples and documentation will suffice.
The new tracer plays it a little loose with GOMAXPROCS. It treats it like a sampled metric rather than something with any semantic meaning. Maybe that's OK if we guarantee it shows up in each generation (like it does now), but it would probably be better if we had an explicit signal.
The range event names and state transition reasons are strings, so any analysis that is looking for something very particular will quickly end up depending on the strings. At the same time, the strings were chosen so that backwards compatibility is easier to maintain and we don't have to deprecate stale enum values or something in the future. Maybe it's fine, but I think the decision is worth revisiting.

Change https://go.dev/cl/546026 mentions this issue: doc: add release notes for the new execution tracer

doc: add release notes for the new execution tracer

Change https://go.dev/cl/546737 mentions this issue: trace: add script to generate experimental API from a Go checkout

trace: add script to generate experimental API from a Go checkout

trace: regenerate experimental API from go@6d7b3c8

The parsing API has now landed and will work with Go at tip. I'll update it when changes are made at tip.

Overall I really like the API. Here are the things I've noticed are missing or confusing (in addition to the things we've discussed before):

No way to get the version of the trace. Since it's possible for trace versions to change semantics without adding new event types, it's useful for tools to know which version they're dealing with, even if most things are self-describing.
No way to get the start time of the trace. With the monotonic clock, it's useful to have a base timestamp. Right now, the only option is to get the timestamp of the first event, but that can be later than the trace start, and this might matter to users. Getting the timestamps of the EvBatch events is probably sufficient.
When/if you implement seeking or mmap, it'd be useful to be able to get an approximation of the number of events in the trace before reading all events with ReadEvent. I'd need that for progress bars in Gotraceui.
It's hard to tell which Ranges are actually local to their resource. I've seen STW starts being attributed to goroutines, but STW is of course process-wide. We can map from their names, but that's not very self-describing.

Stack.Frames doesn't follow the latest state of the rangefunc proposal. At a minimum, it should lose the bool return value so that it's actually a valid iterator. Also, the proposal seems to suggest that methods shouldn't themselves be iterators, but return iterators. That is, func (Stack) Frames() func(yield func(StackFrame) bool). (i.e. func (Stack) Frames() iter.Seq[StackFrame], but without depending on the iter package.)

I also don't think that having an iterator is sufficient API. In Gotraceui, we want to index into stacks, preferably without being O(n). Judging from the current data structures involved, it should be possible to add Stack.At and Stack.Len methods.

I'm somewhat worried about Label, its current implementation, and its semantics.

It seems that in the general sense, labels are able to associate a string with a resource, which is valid from the point of the Label event until the next Label event.

However, its only current use is to replicate the old GoStartLabel event, which had much tighter semantics than GoStart + Label, and was easier to use, for the two following reasons:

With GoStartLabel it was clear that the label described the kind of work being done by the goroutine for the duration of that running state, until the next state transition. With GoStart + Label, it is not obvious whether the label is only valid until the next state transition or not. Furthermore, the GoStart and Label events will have different timestamps. Does the goroutine have no label for that short duration? Or, if Label is valid until the next Label, does the goroutine still have the old label for that short duration?

In Gotraceui, we use labels as part of span labels, where each state transition, and some regions, create spans. Do I need a tiny span between GoStart and GoStartLabel? I don't for the current use of Label, which is to describe the kind of GC work being done by background workers. But what about future uses of labels?
It's useful to be able to refer to a single Event to describe a region, range, or state transition. In Gotraceui, the Span type refers to a single event and with the old parser, this provided all the information that one needed to know. Now I'd also have to carry around the label somehow. It'd be much nicer to have the information that Label provides be directly on the state transition instead, either as the reason (in the sense that a goroutine is transitioning to Running because it has to do GC (dedicated) work), or as the Label method working on state transition events.

An update on stack caching:

The Stack API is also designed to allow for efficient caching of this copying. You can create something like map[trace.Stack][]trace.StackFrame as the cache (in fact, the new cmd/trace does exactly this for profile creation).

I can see how that would be simple in the "load all events into memory" use case, but once we support seeking and incremental (re)parsing, the lack of weak maps will make it hard to drop stacks and the evTables they refer to.

Yep, that is a really good point and does make this format less useful. Long-term I don't think weak-keyed maps are off the table, and they would be a great for this, but it's not going to happen overnight. I dunno.

Go 1.24 will likely have weak pointers and an alternative to finalizers that would allow implementing such a map.

Change https://go.dev/cl/644215 mentions this issue: internal/trace: refactor how experimental batches are exposed

@mknyszek

During the last runtime diagnostics meeting I mentioned a challenge when it comes to writing test cases for code that targets the trace.Reader API

The issue is that there is no good way to create custom trace.Event values for testing purposes.

One option is to write programs that generate traces with the desired properties, but this can be hard since scheduling is not deterministic.

A second option is using the testgen package to build traces from low level events (example), but the problem is that the testgen package is currently marked as internal. Additionally the low level events feel like the wrong level of abstraction for writing test cases.

A third option is to build an interface around the trace.Event API. But this is hard because the API surface is fairly big, and Event.StateTransition returning a struct with private fields further complicates the matter. Here is a gist of a vtrace package where I tried this approach.

So from my point of view, it'd be great to have a good API for creating trace.Event values for testing purposes. I don't feel too strongly about the specifics, but below is an example from my vtrace package for inspiration:

// Construct an event where G5 wakes up G7 at timestamp 123.
var event vtrace.Event = vtrace.GoroutineTransition{
  T: 123,
  G: 5,
  StG: 7,
  From: trace.GoWaiting,
  To: trace.GoRunnable
}

cc @mknyszek @prattmic @nsrip-dd

@felixge

@felixge I agree this is important if the idea is to encourage people to build their own analyses on top of this package. I'm not sure it should block this proposal, but I do think it's something to at least do very soon after.

As for what this should look like, I think just providing constructors (via functions that either use the options pattern or just take a configuration struct) for the different events would go pretty far. I do think they need to be functions though, since the internal representation of each event is pretty weird and opaque. I think normalizing that a little and moving away from 'it's just a raw event under the hood' would help.

That would also be a step toward a world where trace analyses can add their own instrumentation into the trace, if we ever have a way to re-serialize the trace events, which I know is something @rhysh has brought up before.

I'm not sure it should block this proposal, but I do think it's something to at least do very soon after.

Agreed.

As for what this should look like, I think just providing constructors (via functions that either use the options pattern or just take a configuration struct) for the different events would go pretty far.

Sounds good! Having constructors, even with a less convenient API, would sufficiently solve my problem. It would make it very easy to build a struct based API (e.g. vtrace.GoroutineTransition) on top of it. And it would avoid the need to propagate a wrapper interface into the actual implementation code.

internal/trace: refactor how experimental batches are exposed

(Summarizing a discussion from Slack. This expands on previous discussion regarding STW ranges being scoped to goroutines instead of being global)

It continues being useful to display STW as a goroutine-specific range, for example to tell apart goroutines that are ignoring the STW (which will be in the "running" state) from goroutines that control the STW (which will also be in the "running" state)
However, STW is still very much global. There can only be one STW range active at a time, and it affects all goroutines.
There is currently no way to know which ranges are "global but not global" without hard-coding (prefixes) of strings.
Possible solutions are
1. Emitting two ranges per STW: one scoped to a goroutine, and one scoped globally. This doesn't help much, because now users need to know which ranges to deduplicate in a list of all ranges, say.
2. In addition to ResourceNone and ResourceGoroutine add a resource for "goroutine+global". Runs the risk of a small combinatorial explosion.
3. Encode additional information, either in a structured string, or by switching to an opaque string + bits representation. To keep things general and expandable, the new bit should probably represent the globalness of the range (as opposed to having a bit specific to STW). One problem here would be nomenclature. ResourceNone is currently documented as "indicates the range is globally scoped", which refers to a different kind of "global" than this bit would.
4. Do nothing. Currently, STW is the only kind of range that is affected by this, and tools can handle all STW ranges with a single call to strings.HasPrefix. This isn't more effort than adding support for the new bit. In that case, we should revisit this when/if more global-but-not-global ranges are added.

The semantics of Sync events have changed, are no longer true to the documentation, and have lost a useful property.

In the past, Sync events were emitted at the end of generations, and it was guaranteed that

At the point of a sync event, the trace reader can be certain that all resources (e.g. threads, goroutines) that have existed until that point have been enumerated.

Importantly, this meant that after having seen the first Sync event, all existing resources were known.

However, traces now start with a Sync event, as it now helps establish a mapping between monotonic and wall time. This means that all existing resources have definitely not been enumerated by the time we see the event.

The documented guarantee isn't necessary--code can be written differently to skip over duplicate information (such as RangeActive ranges) in future generations--but being able to special case the first Sync event was convenient. The change also broke existing code, though admittedly there wasn't a lot of it.

Can we just document that there's an additional Sync at the beginning of the trace, and to special-case the second Sync instead of the first? x/exp/trace would have to guarantee that both old and new traces always start with the extra event, though.

The documented guarantee isn't necessary--code can be written differently to skip over duplicate information (such as RangeActive ranges) in future generations--but being able to special case the first Sync event was convenient.

FTR, a lot of the code in cmd/trace and elsewhere still makes this assumption, it just counts whether it's seen 1 sync event instead of 0. I do want code to be able to make this assumption, and not have to merge in RangeActive events with more complicated code.

The change also broke existing code, though admittedly there wasn't a lot of it.

While that's somewhat expected in this experimental stage, I did also trip over this a bunch. I don't think I realized how much stuff cared about it.

Can we just document that there's an additional Sync at the beginning of the trace, and to special-case the second Sync instead of the first? x/exp/trace would have to guarantee that both old and new traces always start with the extra event, though.

Yes, though, at the risk of introducing even more breakage, perhaps we should let the Sync events go back to their old purpose. Merging the two makes sense from the wire format's perspective, but perhaps it was more generally a mistake.

We should be aiming for clarity here; documenting the extra first Sync event is fine (and I think I also suggested that at some point) but probably not doing that would be much less surprising.

For ClockSnapshot, perhaps we should instead make that a method on the Reader, because there's always a valid snapshot. We can just say it updates just after a Sync event. Its primary purpose is to align and convert clocks; it seems more intuitive for that purpose anyway. (And perhaps we even want some helpers to do the conversion for you.)

The only thing left then is ExperimentalBatches but I'd really like to remove that in favor of a much easier to use mechanism anyway. I've got some WIP changes for that.

Change https://go.dev/cl/754300 mentions this issue: internal/trace: replace ClockSnapshot with methods on Event

Change https://go.dev/cl/754301 mentions this issue: internal/trace: don't emit a Sync event at the start

Change https://go.dev/cl/750941 mentions this issue: runtime,internal/trace: replace trace experiments with a debug event

Change https://go.dev/cl/754884 mentions this issue: internal/trace: revamp Range

Change https://go.dev/cl/754883 mentions this issue: internal/trace: bring back ClockSnapshot

Navigation Menu

proposal: x/debug/trace: add package for parsing execution traces #62627

12 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

proposal: x/debug/trace: add package for parsing execution traces #62627

Description

Activity

gopherbot commented on Nov 22, 2023

mknyszek commented on Nov 22, 2023

gopherbot commented on Nov 30, 2023

gopherbot commented on Dec 4, 2023

mknyszek commented on Dec 6, 2023

dominikh commented on Dec 22, 2023

dominikh commented on Dec 22, 2023

dominikh commented on Dec 23, 2023

12 remaining items

dominikh commented on Jan 12, 2025

gopherbot commented on Jan 25, 2025

felixge commented on Feb 5, 2025

mknyszek commented on Feb 5, 2025

felixge commented on Feb 6, 2025

dominikh commented on Dec 2, 2025

dominikh commented on Dec 2, 2025

mknyszek commented on Dec 3, 2025

gopherbot commented on Mar 11, 2026

gopherbot commented on Mar 11, 2026

gopherbot commented on Mar 11, 2026

gopherbot commented on Mar 13, 2026

gopherbot commented on Mar 13, 2026

khalidsaidi commented on Mar 14, 2026

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions