Related Issues

• runtime, cmd/trace: recent regression: "failed to parse trace: no consistent ordering of events possible #36186 (closed)
• x/net/trace: race when rendering active requests #24231 (closed)
• cmd/trace: give more context to "Scheduler wait" table column on /goroutine page #63430
• cmd/trace: "failed to parse trace: no consistent ordering of events possible" #29707 (closed)
• runtime/trace: fails to parse trace with "time stamps out of order" #52776 (closed)
• runtime/trace: "preempted" StateTransition sometimes has Stack of single zeroed StackFrame #68090
• cmd/trace: go tool trace trace time stamps out of order #24663 (closed)
• testing: "panic: Log in goroutine after Test..." is unreliable due to lack of synchronization on t.done #67701
• runtime/trace: generated timestamps have a jump in them #15102 (closed)
• runtime/race: bogus race reports #15739 (closed)

_{(Emoji vote if this was helpful or unhelpful; more detailed feedback welcome in this discussion.)}

Yes, this appears due to map iteration in https://github.com/golang/go/blob/go1.23rc1/src/internal/trace/reader.go#L145

Forcing a sort (such as with slices.Sorted(maps.Keys(r.gen.batches)), for newer toolchains) resolves it. I can prepare a patch.

$ git -C /usr/local/go diff --stat
 src/internal/trace/reader.go | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

$ (go run cmd/trace -d=1 /tmp/trace123_h2 ; go run cmd/trace -d=1 /tmp/trace123_h2) | grep '^M=' | sort | uniq -c | awk '{print $1}' | sort | uniq -c
930838 2

Change https://go.dev/cl/596355 mentions this issue: internal/trace: make Reader output deterministic

Moving this to the 1.23 milestone, please comment if any issues with that.

Thanks. Yes, the problem starts in std's internal/trace (not the generated copy in x/exp/trace) so a release milestone is right. Go 1.23 would be great if the door is still open for small fixes like this. Otherwise 1.24.

I plan to send a CL for x/exp/trace (with a "Fixes" line) once internal/trace has https://go.dev/cl/596355, independent of the main Go release cycle.

Thanks for sending a fix!

I think whether this fix should go into Go 1.23 depends on whether we would backport it anyway in the Go 1.24 dev cycle. I'm not totally sure that we would, because the issue doesn't actually impact most cmd/trace functionality (?) except for the debug output, so the severity isn't very high.

That being said, I do think this is an important property of the trace parser to maintain, and I don't want any blockers for the public parser API sitting around too long. FWIW, I think golang.org/x/exp/trace could definitely get updated with this patch before it lands on tip.

Here's what I propose:

• Set https://go.dev/cl/596355 for wait-release, give it Auto-Submit+1 and Code-Review+2 (it LGTM), so it lands in the Go 1.24 dev cycle.
• Apply the patch locally and point the script in golang.org/x/exp/trace at a GOROOT with the patch applied. Send the CL and submit it.

Thoughts?

Change https://go.dev/cl/597177 mentions this issue: trace: regenerate to include CL 596355

That sounds like a fine plan, yes. My own usage depends on x/exp getting the fix, and not at all on it landing in the core repo before the tree opens for Go 1.24.

The severity in cmd/trace is pretty low. Some day I'd like to be able to deep-link into the go tool trace UI, with the ability to target as closely as individual events .. but I'm not doing that yet, so I'm not affected.

I wonder though if all trace parsers should be able to agree on the full details of all events (including timestamp), and thus if there should be a more principled tie-breaker, rather than forcing the other maintainers ( @dominikh , @felixge , maybe others?) to be bug-compatible with this one.

and thus if there should be a more principled tie-breaker

I agree, I think that's something that should be documented in a wire format doc (once that exists).

Fixed in x/exp, fixed in internal/trace.