blob: 4635662c08d56a2615507c30e545cbd2d7537a85 [file] [log] [blame]
// 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
// CPU profile -> trace
package runtime
// traceInitReadCPU initializes CPU profile -> tracer state for tracing.
//
// Returns a profBuf for reading from.
func traceInitReadCPU() {
if traceEnabled() {
throw("traceInitReadCPU called with trace enabled")
}
// Create new profBuf for CPU samples that will be emitted as events.
// Format: after the timestamp, header is [pp.id, gp.goid, mp.procid].
trace.cpuLogRead[0] = newProfBuf(3, profBufWordCount, profBufTagCount)
trace.cpuLogRead[1] = newProfBuf(3, profBufWordCount, profBufTagCount)
// We must not acquire trace.signalLock outside of a signal handler: a
// profiling signal may arrive at any time and try to acquire it, leading to
// deadlock. Because we can't use that lock to protect updates to
// trace.cpuLogWrite (only use of the structure it references), reads and
// writes of the pointer must be atomic. (And although this field is never
// the sole pointer to the profBuf value, it's best to allow a write barrier
// here.)
trace.cpuLogWrite[0].Store(trace.cpuLogRead[0])
trace.cpuLogWrite[1].Store(trace.cpuLogRead[1])
}
// traceStartReadCPU creates a goroutine to start reading CPU profile
// data into an active trace.
//
// traceAdvanceSema must be held.
func traceStartReadCPU() {
if !traceEnabled() {
throw("traceStartReadCPU called with trace disabled")
}
// Spin up the logger goroutine.
trace.cpuSleep = newWakeableSleep()
done := make(chan struct{}, 1)
go func() {
for traceEnabled() {
// Sleep here because traceReadCPU is non-blocking. This mirrors
// how the runtime/pprof package obtains CPU profile data.
//
// We can't do a blocking read here because Darwin can't do a
// wakeup from a signal handler, so all CPU profiling is just
// non-blocking. See #61768 for more details.
//
// Like the runtime/pprof package, even if that bug didn't exist
// we would still want to do a goroutine-level sleep in between
// reads to avoid frequent wakeups.
trace.cpuSleep.sleep(100_000_000)
tl := traceAcquire()
if !tl.ok() {
// Tracing disabled.
break
}
keepGoing := traceReadCPU(tl.gen)
traceRelease(tl)
if !keepGoing {
break
}
}
done <- struct{}{}
}()
trace.cpuLogDone = done
}
// traceStopReadCPU blocks until the trace CPU reading goroutine exits.
//
// traceAdvanceSema must be held, and tracing must be disabled.
func traceStopReadCPU() {
if traceEnabled() {
throw("traceStopReadCPU called with trace enabled")
}
// Once we close the profbuf, we'll be in one of two situations:
// - The logger goroutine has already exited because it observed
// that the trace is disabled.
// - The logger goroutine is asleep.
//
// Wake the goroutine so it can observe that their the buffer is
// closed an exit.
trace.cpuLogWrite[0].Store(nil)
trace.cpuLogWrite[1].Store(nil)
trace.cpuLogRead[0].close()
trace.cpuLogRead[1].close()
trace.cpuSleep.wake()
// Wait until the logger goroutine exits.
<-trace.cpuLogDone
// Clear state for the next trace.
trace.cpuLogDone = nil
trace.cpuLogRead[0] = nil
trace.cpuLogRead[1] = nil
trace.cpuSleep.close()
}
// traceReadCPU attempts to read from the provided profBuf[gen%2] and write
// into the trace. Returns true if there might be more to read or false
// if the profBuf is closed or the caller should otherwise stop reading.
//
// The caller is responsible for ensuring that gen does not change. Either
// the caller must be in a traceAcquire/traceRelease block, or must be calling
// with traceAdvanceSema held.
//
// No more than one goroutine may be in traceReadCPU for the same
// profBuf at a time.
//
// Must not run on the system stack because profBuf.read performs race
// operations.
func traceReadCPU(gen uintptr) bool {
var pcBuf [traceStackSize]uintptr
data, tags, eof := trace.cpuLogRead[gen%2].read(profBufNonBlocking)
for len(data) > 0 {
if len(data) < 4 || data[0] > uint64(len(data)) {
break // truncated profile
}
if data[0] < 4 || tags != nil && len(tags) < 1 {
break // malformed profile
}
if len(tags) < 1 {
break // mismatched profile records and tags
}
// Deserialize the data in the profile buffer.
recordLen := data[0]
timestamp := data[1]
ppid := data[2] >> 1
if hasP := (data[2] & 0b1) != 0; !hasP {
ppid = ^uint64(0)
}
goid := data[3]
mpid := data[4]
stk := data[5:recordLen]
// Overflow records always have their headers contain
// all zeroes.
isOverflowRecord := len(stk) == 1 && data[2] == 0 && data[3] == 0 && data[4] == 0
// Move the data iterator forward.
data = data[recordLen:]
// No support here for reporting goroutine tags at the moment; if
// that information is to be part of the execution trace, we'd
// probably want to see when the tags are applied and when they
// change, instead of only seeing them when we get a CPU sample.
tags = tags[1:]
if isOverflowRecord {
// Looks like an overflow record from the profBuf. Not much to
// do here, we only want to report full records.
continue
}
// Construct the stack for insertion to the stack table.
nstk := 1
pcBuf[0] = logicalStackSentinel
for ; nstk < len(pcBuf) && nstk-1 < len(stk); nstk++ {
pcBuf[nstk] = uintptr(stk[nstk-1])
}
// Write out a trace event.
w := unsafeTraceWriter(gen, trace.cpuBuf[gen%2])
// Ensure we have a place to write to.
var flushed bool
w, flushed = w.ensure(2 + 5*traceBytesPerNumber /* traceEvCPUSamples + traceEvCPUSample + timestamp + g + m + p + stack ID */)
if flushed {
// Annotate the batch as containing strings.
w.byte(byte(traceEvCPUSamples))
}
// Add the stack to the table.
stackID := trace.stackTab[gen%2].put(pcBuf[:nstk])
// Write out the CPU sample.
w.byte(byte(traceEvCPUSample))
w.varint(timestamp)
w.varint(mpid)
w.varint(ppid)
w.varint(goid)
w.varint(stackID)
trace.cpuBuf[gen%2] = w.traceBuf
}
return !eof
}
// traceCPUFlush flushes trace.cpuBuf[gen%2]. The caller must be certain that gen
// has completed and that there are no more writers to it.
//
// Must run on the systemstack because it flushes buffers and acquires trace.lock
// to do so.
//
//go:systemstack
func traceCPUFlush(gen uintptr) {
// Flush any remaining trace buffers containing CPU samples.
if buf := trace.cpuBuf[gen%2]; buf != nil {
lock(&trace.lock)
traceBufFlush(buf, gen)
unlock(&trace.lock)
trace.cpuBuf[gen%2] = nil
}
}
// traceCPUSample writes a CPU profile sample stack to the execution tracer's
// profiling buffer. It is called from a signal handler, so is limited in what
// it can do. mp must be the thread that is currently stopped in a signal.
func traceCPUSample(gp *g, mp *m, pp *p, stk []uintptr) {
if !traceEnabled() {
// Tracing is usually turned off; don't spend time acquiring the signal
// lock unless it's active.
return
}
if mp == nil {
// Drop samples that don't have an identifiable thread. We can't render
// this in any useful way anyway.
return
}
// We're going to conditionally write to one of two buffers based on the
// generation. To make sure we write to the correct one, we need to make
// sure this thread's trace seqlock is held. If it already is, then we're
// in the tracer and we can just take advantage of that. If it isn't, then
// we need to acquire it and read the generation.
locked := false
if mp.trace.seqlock.Load()%2 == 0 {
mp.trace.seqlock.Add(1)
locked = true
}
gen := trace.gen.Load()
if gen == 0 {
// Tracing is disabled, as it turns out. Release the seqlock if necessary
// and exit.
if locked {
mp.trace.seqlock.Add(1)
}
return
}
now := traceClockNow()
// The "header" here is the ID of the M that was running the profiled code,
// followed by the IDs of the P and goroutine. (For normal CPU profiling, it's
// usually the number of samples with the given stack.) Near syscalls, pp
// may be nil. Reporting goid of 0 is fine for either g0 or a nil gp.
var hdr [3]uint64
if pp != nil {
// Overflow records in profBuf have all header values set to zero. Make
// sure that real headers have at least one bit set.
hdr[0] = uint64(pp.id)<<1 | 0b1
} else {
hdr[0] = 0b10
}
if gp != nil {
hdr[1] = gp.goid
}
if mp != nil {
hdr[2] = uint64(mp.procid)
}
// Allow only one writer at a time
for !trace.signalLock.CompareAndSwap(0, 1) {
// TODO: Is it safe to osyield here? https://go.dev/issue/52672
osyield()
}
if log := trace.cpuLogWrite[gen%2].Load(); log != nil {
// Note: we don't pass a tag pointer here (how should profiling tags
// interact with the execution tracer?), but if we did we'd need to be
// careful about write barriers. See the long comment in profBuf.write.
log.write(nil, int64(now), hdr[:], stk)
}
trace.signalLock.Store(0)
// Release the seqlock if we acquired it earlier.
if locked {
mp.trace.seqlock.Add(1)
}
}