go/src/runtime/trace2event.go
Michael Anthony Knyszek c9c88d73f5 runtime: add tracing for iter.Pull
This change resolves a TODO in the coroutine switch implementation (used
exclusively by iter.Pull at the moment) to enable tracing. This was
blocked on eliminating the atomic load in the tracer's "off" path
(completed in the previous CL in this series) and the addition of new
tracer events to minimize the overhead of tracing in this circumstance.

This change introduces 3 new event types to support coroutine switches:
GoCreateBlocked, GoSwitch, and GoSwitchDestroy.

GoCreateBlocked needs to be introduced because the goroutine created for
the coroutine starts out in a blocked state. There's no way to represent
this in the tracer right now, so we need a new event for it.

GoSwitch represents the actual coroutine switch, which conceptually
consists of a GoUnblock, a GoBlock, and a GoStart event in series
(unblocking the next goroutine to run, blocking the current goroutine,
and then starting the next goroutine to run).

GoSwitchDestroy is closely related to GoSwitch, implementing the same
semantics except that GoBlock is replaced with GoDestroy. This is used
when exiting the coroutine.

The implementation of all this is fairly straightforward, and the trace
parser simply translates GoSwitch* into the three constituent events.

Because GoSwitch and GoSwitchDestroy imply a GoUnblock and a GoStart,
they need to synchronize with other past and future GoStart events to
create a correct partial ordering in the trace. Therefore, these events
need a sequence number for the goroutine that will be unblocked and
started.

Also, while implementing this, I noticed that the coroutine
implementation is actually buggy with respect to LockOSThread. In fact,
it blatantly disregards its invariants without an explicit panic. While
such a case is likely to be rare (and inefficient!) we should decide how
iter.Pull behaves with respect to runtime.LockOSThread.

Lastly, this change also bumps the trace version from Go 1.22 to Go
1.23. We're adding events that are incompatible with a Go 1.22 parser,
but Go 1.22 traces are all valid Go 1.23 traces, so the newer parser
supports both (and the CL otherwise updates the Go 1.22 definitions of
events and such). We may want to reconsider the structure and naming of
some of these packages though; it could quickly get confusing.

For #61897.

Change-Id: I96897a46d5852c02691cde9f957dc6c13ef4d8e7
Reviewed-on: https://go-review.googlesource.com/c/go/+/565937
Reviewed-by: Michael Pratt <mpratt@google.com>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Auto-Submit: Michael Knyszek <mknyszek@google.com>
2024-03-22 16:12:01 +00:00

200 lines
8.7 KiB
Go

// Copyright 2023 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.
//go:build goexperiment.exectracer2
// Trace event writing API for trace2runtime.go.
package runtime
import (
"runtime/internal/sys"
)
// Event types in the trace, args are given in square brackets.
//
// Naming scheme:
// - Time range event pairs have suffixes "Begin" and "End".
// - "Start", "Stop", "Create", "Destroy", "Block", "Unblock"
// are suffixes reserved for scheduling resources.
//
// NOTE: If you add an event type, make sure you also update all
// tables in this file!
type traceEv uint8
const (
traceEvNone traceEv = iota // unused
// Structural events.
traceEvEventBatch // start of per-M batch of events [generation, M ID, timestamp, batch length]
traceEvStacks // start of a section of the stack table [...traceEvStack]
traceEvStack // stack table entry [ID, ...{PC, func string ID, file string ID, line #}]
traceEvStrings // start of a section of the string dictionary [...traceEvString]
traceEvString // string dictionary entry [ID, length, string]
traceEvCPUSamples // start of a section of CPU samples [...traceEvCPUSample]
traceEvCPUSample // CPU profiling sample [timestamp, M ID, P ID, goroutine ID, stack ID]
traceEvFrequency // timestamp units per sec [freq]
// Procs.
traceEvProcsChange // current value of GOMAXPROCS [timestamp, GOMAXPROCS, stack ID]
traceEvProcStart // start of P [timestamp, P ID, P seq]
traceEvProcStop // stop of P [timestamp]
traceEvProcSteal // P was stolen [timestamp, P ID, P seq, M ID]
traceEvProcStatus // P status at the start of a generation [timestamp, P ID, status]
// Goroutines.
traceEvGoCreate // goroutine creation [timestamp, new goroutine ID, new stack ID, stack ID]
traceEvGoCreateSyscall // goroutine appears in syscall (cgo callback) [timestamp, new goroutine ID]
traceEvGoStart // goroutine starts running [timestamp, goroutine ID, goroutine seq]
traceEvGoDestroy // goroutine ends [timestamp]
traceEvGoDestroySyscall // goroutine ends in syscall (cgo callback) [timestamp]
traceEvGoStop // goroutine yields its time, but is runnable [timestamp, reason, stack ID]
traceEvGoBlock // goroutine blocks [timestamp, reason, stack ID]
traceEvGoUnblock // goroutine is unblocked [timestamp, goroutine ID, goroutine seq, stack ID]
traceEvGoSyscallBegin // syscall enter [timestamp, P seq, stack ID]
traceEvGoSyscallEnd // syscall exit [timestamp]
traceEvGoSyscallEndBlocked // syscall exit and it blocked at some point [timestamp]
traceEvGoStatus // goroutine status at the start of a generation [timestamp, goroutine ID, M ID, status]
// STW.
traceEvSTWBegin // STW start [timestamp, kind]
traceEvSTWEnd // STW done [timestamp]
// GC events.
traceEvGCActive // GC active [timestamp, seq]
traceEvGCBegin // GC start [timestamp, seq, stack ID]
traceEvGCEnd // GC done [timestamp, seq]
traceEvGCSweepActive // GC sweep active [timestamp, P ID]
traceEvGCSweepBegin // GC sweep start [timestamp, stack ID]
traceEvGCSweepEnd // GC sweep done [timestamp, swept bytes, reclaimed bytes]
traceEvGCMarkAssistActive // GC mark assist active [timestamp, goroutine ID]
traceEvGCMarkAssistBegin // GC mark assist start [timestamp, stack ID]
traceEvGCMarkAssistEnd // GC mark assist done [timestamp]
traceEvHeapAlloc // gcController.heapLive change [timestamp, heap alloc in bytes]
traceEvHeapGoal // gcController.heapGoal() change [timestamp, heap goal in bytes]
// Annotations.
traceEvGoLabel // apply string label to current running goroutine [timestamp, label string ID]
traceEvUserTaskBegin // trace.NewTask [timestamp, internal task ID, internal parent task ID, name string ID, stack ID]
traceEvUserTaskEnd // end of a task [timestamp, internal task ID, stack ID]
traceEvUserRegionBegin // trace.{Start,With}Region [timestamp, internal task ID, name string ID, stack ID]
traceEvUserRegionEnd // trace.{End,With}Region [timestamp, internal task ID, name string ID, stack ID]
traceEvUserLog // trace.Log [timestamp, internal task ID, key string ID, stack, value string ID]
// Coroutines.
traceEvGoSwitch // goroutine switch (coroswitch) [timestamp, goroutine ID, goroutine seq]
traceEvGoSwitchDestroy // goroutine switch and destroy [timestamp, goroutine ID, goroutine seq]
traceEvGoCreateBlocked // goroutine creation (starts blocked) [timestamp, new goroutine ID, new stack ID, stack ID]
)
// traceArg is a simple wrapper type to help ensure that arguments passed
// to traces are well-formed.
type traceArg uint64
// traceEventWriter is the high-level API for writing trace events.
//
// See the comment on traceWriter about style for more details as to why
// this type and its methods are structured the way they are.
type traceEventWriter struct {
w traceWriter
}
// eventWriter creates a new traceEventWriter. It is the main entrypoint for writing trace events.
//
// Before creating the event writer, this method will emit a status for the current goroutine
// or proc if it exists, and if it hasn't had its status emitted yet. goStatus and procStatus indicate
// what the status of goroutine or P should be immediately *before* the events that are about to
// be written using the eventWriter (if they exist). No status will be written if there's no active
// goroutine or P.
//
// Callers can elect to pass a constant value here if the status is clear (e.g. a goroutine must have
// been Runnable before a GoStart). Otherwise, callers can query the status of either the goroutine
// or P and pass the appropriate status.
//
// In this case, the default status should be traceGoBad or traceProcBad to help identify bugs sooner.
func (tl traceLocker) eventWriter(goStatus traceGoStatus, procStatus traceProcStatus) traceEventWriter {
w := tl.writer()
if pp := tl.mp.p.ptr(); pp != nil && !pp.trace.statusWasTraced(tl.gen) && pp.trace.acquireStatus(tl.gen) {
w = w.writeProcStatus(uint64(pp.id), procStatus, pp.trace.inSweep)
}
if gp := tl.mp.curg; gp != nil && !gp.trace.statusWasTraced(tl.gen) && gp.trace.acquireStatus(tl.gen) {
w = w.writeGoStatus(uint64(gp.goid), int64(tl.mp.procid), goStatus, gp.inMarkAssist)
}
return traceEventWriter{w}
}
// commit writes out a trace event and calls end. It's a helper to make the
// common case of writing out a single event less error-prone.
func (e traceEventWriter) commit(ev traceEv, args ...traceArg) {
e = e.write(ev, args...)
e.end()
}
// write writes an event into the trace.
func (e traceEventWriter) write(ev traceEv, args ...traceArg) traceEventWriter {
e.w = e.w.event(ev, args...)
return e
}
// end finishes writing to the trace. The traceEventWriter must not be used after this call.
func (e traceEventWriter) end() {
e.w.end()
}
// traceEventWrite is the part of traceEvent that actually writes the event.
func (w traceWriter) event(ev traceEv, args ...traceArg) traceWriter {
// Make sure we have room.
w, _ = w.ensure(1 + (len(args)+1)*traceBytesPerNumber)
// Compute the timestamp diff that we'll put in the trace.
ts := traceClockNow()
if ts <= w.traceBuf.lastTime {
ts = w.traceBuf.lastTime + 1
}
tsDiff := uint64(ts - w.traceBuf.lastTime)
w.traceBuf.lastTime = ts
// Write out event.
w.byte(byte(ev))
w.varint(tsDiff)
for _, arg := range args {
w.varint(uint64(arg))
}
return w
}
// stack takes a stack trace skipping the provided number of frames.
// It then returns a traceArg representing that stack which may be
// passed to write.
func (tl traceLocker) stack(skip int) traceArg {
return traceArg(traceStack(skip, tl.mp, tl.gen))
}
// startPC takes a start PC for a goroutine and produces a unique
// stack ID for it.
//
// It then returns a traceArg representing that stack which may be
// passed to write.
func (tl traceLocker) startPC(pc uintptr) traceArg {
// +PCQuantum because makeTraceFrame expects return PCs and subtracts PCQuantum.
return traceArg(trace.stackTab[tl.gen%2].put([]uintptr{
logicalStackSentinel,
startPCForTrace(pc) + sys.PCQuantum,
}))
}
// string returns a traceArg representing s which may be passed to write.
// The string is assumed to be relatively short and popular, so it may be
// stored for a while in the string dictionary.
func (tl traceLocker) string(s string) traceArg {
return traceArg(trace.stringTab[tl.gen%2].put(tl.gen, s))
}
// uniqueString returns a traceArg representing s which may be passed to write.
// The string is assumed to be unique or long, so it will be written out to
// the trace eagerly.
func (tl traceLocker) uniqueString(s string) traceArg {
return traceArg(trace.stringTab[tl.gen%2].emit(tl.gen, s))
}