]> Cypherpunks.ru repositories - gostls13.git/blob - src/runtime/trace.go
runtime: refactor runtime->tracer API to appear more like a lock
[gostls13.git] / src / runtime / trace.go
1 // Copyright 2014 The Go Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style
3 // license that can be found in the LICENSE file.
4
5 // Go execution tracer.
6 // The tracer captures a wide range of execution events like goroutine
7 // creation/blocking/unblocking, syscall enter/exit/block, GC-related events,
8 // changes of heap size, processor start/stop, etc and writes them to a buffer
9 // in a compact form. A precise nanosecond-precision timestamp and a stack
10 // trace is captured for most events.
11 // See https://golang.org/s/go15trace for more info.
12
13 package runtime
14
15 import (
16         "internal/abi"
17         "internal/goarch"
18         "internal/goos"
19         "runtime/internal/atomic"
20         "runtime/internal/sys"
21         "unsafe"
22 )
23
24 // Event types in the trace, args are given in square brackets.
25 const (
26         traceEvNone              = 0  // unused
27         traceEvBatch             = 1  // start of per-P batch of events [pid, timestamp]
28         traceEvFrequency         = 2  // contains tracer timer frequency [frequency (ticks per second)]
29         traceEvStack             = 3  // stack [stack id, number of PCs, array of {PC, func string ID, file string ID, line}]
30         traceEvGomaxprocs        = 4  // current value of GOMAXPROCS [timestamp, GOMAXPROCS, stack id]
31         traceEvProcStart         = 5  // start of P [timestamp, thread id]
32         traceEvProcStop          = 6  // stop of P [timestamp]
33         traceEvGCStart           = 7  // GC start [timestamp, seq, stack id]
34         traceEvGCDone            = 8  // GC done [timestamp]
35         traceEvSTWStart          = 9  // STW start [timestamp, kind]
36         traceEvSTWDone           = 10 // STW done [timestamp]
37         traceEvGCSweepStart      = 11 // GC sweep start [timestamp, stack id]
38         traceEvGCSweepDone       = 12 // GC sweep done [timestamp, swept, reclaimed]
39         traceEvGoCreate          = 13 // goroutine creation [timestamp, new goroutine id, new stack id, stack id]
40         traceEvGoStart           = 14 // goroutine starts running [timestamp, goroutine id, seq]
41         traceEvGoEnd             = 15 // goroutine ends [timestamp]
42         traceEvGoStop            = 16 // goroutine stops (like in select{}) [timestamp, stack]
43         traceEvGoSched           = 17 // goroutine calls Gosched [timestamp, stack]
44         traceEvGoPreempt         = 18 // goroutine is preempted [timestamp, stack]
45         traceEvGoSleep           = 19 // goroutine calls Sleep [timestamp, stack]
46         traceEvGoBlock           = 20 // goroutine blocks [timestamp, stack]
47         traceEvGoUnblock         = 21 // goroutine is unblocked [timestamp, goroutine id, seq, stack]
48         traceEvGoBlockSend       = 22 // goroutine blocks on chan send [timestamp, stack]
49         traceEvGoBlockRecv       = 23 // goroutine blocks on chan recv [timestamp, stack]
50         traceEvGoBlockSelect     = 24 // goroutine blocks on select [timestamp, stack]
51         traceEvGoBlockSync       = 25 // goroutine blocks on Mutex/RWMutex [timestamp, stack]
52         traceEvGoBlockCond       = 26 // goroutine blocks on Cond [timestamp, stack]
53         traceEvGoBlockNet        = 27 // goroutine blocks on network [timestamp, stack]
54         traceEvGoSysCall         = 28 // syscall enter [timestamp, stack]
55         traceEvGoSysExit         = 29 // syscall exit [timestamp, goroutine id, seq, real timestamp]
56         traceEvGoSysBlock        = 30 // syscall blocks [timestamp]
57         traceEvGoWaiting         = 31 // denotes that goroutine is blocked when tracing starts [timestamp, goroutine id]
58         traceEvGoInSyscall       = 32 // denotes that goroutine is in syscall when tracing starts [timestamp, goroutine id]
59         traceEvHeapAlloc         = 33 // gcController.heapLive change [timestamp, heap_alloc]
60         traceEvHeapGoal          = 34 // gcController.heapGoal() (formerly next_gc) change [timestamp, heap goal in bytes]
61         traceEvTimerGoroutine    = 35 // not currently used; previously denoted timer goroutine [timer goroutine id]
62         traceEvFutileWakeup      = 36 // not currently used; denotes that the previous wakeup of this goroutine was futile [timestamp]
63         traceEvString            = 37 // string dictionary entry [ID, length, string]
64         traceEvGoStartLocal      = 38 // goroutine starts running on the same P as the last event [timestamp, goroutine id]
65         traceEvGoUnblockLocal    = 39 // goroutine is unblocked on the same P as the last event [timestamp, goroutine id, stack]
66         traceEvGoSysExitLocal    = 40 // syscall exit on the same P as the last event [timestamp, goroutine id, real timestamp]
67         traceEvGoStartLabel      = 41 // goroutine starts running with label [timestamp, goroutine id, seq, label string id]
68         traceEvGoBlockGC         = 42 // goroutine blocks on GC assist [timestamp, stack]
69         traceEvGCMarkAssistStart = 43 // GC mark assist start [timestamp, stack]
70         traceEvGCMarkAssistDone  = 44 // GC mark assist done [timestamp]
71         traceEvUserTaskCreate    = 45 // trace.NewTask [timestamp, internal task id, internal parent task id, name string, stack]
72         traceEvUserTaskEnd       = 46 // end of a task [timestamp, internal task id, stack]
73         traceEvUserRegion        = 47 // trace.WithRegion [timestamp, internal task id, mode(0:start, 1:end), name string, stack]
74         traceEvUserLog           = 48 // trace.Log [timestamp, internal task id, key string id, stack, value string]
75         traceEvCPUSample         = 49 // CPU profiling sample [timestamp, real timestamp, real P id (-1 when absent), goroutine id, stack]
76         traceEvCount             = 50
77         // Byte is used but only 6 bits are available for event type.
78         // The remaining 2 bits are used to specify the number of arguments.
79         // That means, the max event type value is 63.
80 )
81
82 // traceBlockReason is an enumeration of reasons a goroutine might block.
83 // This is the interface the rest of the runtime uses to tell the
84 // tracer why a goroutine blocked. The tracer then propagates this information
85 // into the trace however it sees fit.
86 //
87 // Note that traceBlockReasons should not be compared, since reasons that are
88 // distinct by name may *not* be distinct by value.
89 type traceBlockReason uint8
90
91 // For maximal efficiency, just map the trace block reason directly to a trace
92 // event.
93 const (
94         traceBlockGeneric         traceBlockReason = traceEvGoBlock
95         traceBlockForever                          = traceEvGoStop
96         traceBlockNet                              = traceEvGoBlockNet
97         traceBlockSelect                           = traceEvGoBlockSelect
98         traceBlockCondWait                         = traceEvGoBlockCond
99         traceBlockSync                             = traceEvGoBlockSync
100         traceBlockChanSend                         = traceEvGoBlockSend
101         traceBlockChanRecv                         = traceEvGoBlockRecv
102         traceBlockGCMarkAssist                     = traceEvGoBlockGC
103         traceBlockGCSweep                          = traceEvGoBlock
104         traceBlockSystemGoroutine                  = traceEvGoBlock
105         traceBlockPreempted                        = traceEvGoBlock
106         traceBlockDebugCall                        = traceEvGoBlock
107         traceBlockUntilGCEnds                      = traceEvGoBlock
108         traceBlockSleep                            = traceEvGoSleep
109 )
110
111 const (
112         // Timestamps in trace are cputicks/traceTickDiv.
113         // This makes absolute values of timestamp diffs smaller,
114         // and so they are encoded in less number of bytes.
115         // 64 on x86 is somewhat arbitrary (one tick is ~20ns on a 3GHz machine).
116         // The suggested increment frequency for PowerPC's time base register is
117         // 512 MHz according to Power ISA v2.07 section 6.2, so we use 16 on ppc64
118         // and ppc64le.
119         traceTimeDiv = 16 + 48*(goarch.Is386|goarch.IsAmd64)
120         // Maximum number of PCs in a single stack trace.
121         // Since events contain only stack id rather than whole stack trace,
122         // we can allow quite large values here.
123         traceStackSize = 128
124         // Identifier of a fake P that is used when we trace without a real P.
125         traceGlobProc = -1
126         // Maximum number of bytes to encode uint64 in base-128.
127         traceBytesPerNumber = 10
128         // Shift of the number of arguments in the first event byte.
129         traceArgCountShift = 6
130 )
131
132 // trace is global tracing context.
133 var trace struct {
134         // trace.lock must only be acquired on the system stack where
135         // stack splits cannot happen while it is held.
136         lock          mutex       // protects the following members
137         enabled       bool        // when set runtime traces events
138         shutdown      bool        // set when we are waiting for trace reader to finish after setting enabled to false
139         headerWritten bool        // whether ReadTrace has emitted trace header
140         footerWritten bool        // whether ReadTrace has emitted trace footer
141         shutdownSema  uint32      // used to wait for ReadTrace completion
142         seqStart      uint64      // sequence number when tracing was started
143         startTicks    int64       // cputicks when tracing was started
144         endTicks      int64       // cputicks when tracing was stopped
145         startNanotime int64       // nanotime when tracing was started
146         endNanotime   int64       // nanotime when tracing was stopped
147         startTime     traceTime   // traceClockNow when tracing started
148         endTime       traceTime   // traceClockNow when tracing stopped
149         seqGC         uint64      // GC start/done sequencer
150         reading       traceBufPtr // buffer currently handed off to user
151         empty         traceBufPtr // stack of empty buffers
152         fullHead      traceBufPtr // queue of full buffers
153         fullTail      traceBufPtr
154         stackTab      traceStackTable // maps stack traces to unique ids
155         // cpuLogRead accepts CPU profile samples from the signal handler where
156         // they're generated. It uses a two-word header to hold the IDs of the P and
157         // G (respectively) that were active at the time of the sample. Because
158         // profBuf uses a record with all zeros in its header to indicate overflow,
159         // we make sure to make the P field always non-zero: The ID of a real P will
160         // start at bit 1, and bit 0 will be set. Samples that arrive while no P is
161         // running (such as near syscalls) will set the first header field to 0b10.
162         // This careful handling of the first header field allows us to store ID of
163         // the active G directly in the second field, even though that will be 0
164         // when sampling g0.
165         cpuLogRead *profBuf
166         // cpuLogBuf is a trace buffer to hold events corresponding to CPU profile
167         // samples, which arrive out of band and not directly connected to a
168         // specific P.
169         cpuLogBuf traceBufPtr
170
171         reader atomic.Pointer[g] // goroutine that called ReadTrace, or nil
172
173         signalLock  atomic.Uint32 // protects use of the following member, only usable in signal handlers
174         cpuLogWrite *profBuf      // copy of cpuLogRead for use in signal handlers, set without signalLock
175
176         // Dictionary for traceEvString.
177         //
178         // TODO: central lock to access the map is not ideal.
179         //   option: pre-assign ids to all user annotation region names and tags
180         //   option: per-P cache
181         //   option: sync.Map like data structure
182         stringsLock mutex
183         strings     map[string]uint64
184         stringSeq   uint64
185
186         // markWorkerLabels maps gcMarkWorkerMode to string ID.
187         markWorkerLabels [len(gcMarkWorkerModeStrings)]uint64
188
189         bufLock mutex       // protects buf
190         buf     traceBufPtr // global trace buffer, used when running without a p
191 }
192
193 // gTraceState is per-G state for the tracer.
194 type gTraceState struct {
195         sysExitTime        traceTime // timestamp when syscall has returned
196         tracedSyscallEnter bool      // syscall or cgo was entered while trace was enabled or StartTrace has emitted EvGoInSyscall about this goroutine
197         seq                uint64    // trace event sequencer
198         lastP              puintptr  // last P emitted an event for this goroutine
199 }
200
201 // mTraceState is per-M state for the tracer.
202 type mTraceState struct {
203         startingTrace  bool // this M is in TraceStart, potentially before traceEnabled is true
204         tracedSTWStart bool // this M traced a STW start, so it should trace an end
205 }
206
207 // pTraceState is per-P state for the tracer.
208 type pTraceState struct {
209         buf traceBufPtr
210
211         // inSweep indicates the sweep events should be traced.
212         // This is used to defer the sweep start event until a span
213         // has actually been swept.
214         inSweep bool
215
216         // swept and reclaimed track the number of bytes swept and reclaimed
217         // by sweeping in the current sweep loop (while inSweep was true).
218         swept, reclaimed uintptr
219 }
220
221 // traceLockInit initializes global trace locks.
222 func traceLockInit() {
223         lockInit(&trace.bufLock, lockRankTraceBuf)
224         lockInit(&trace.stringsLock, lockRankTraceStrings)
225         lockInit(&trace.lock, lockRankTrace)
226         lockInit(&trace.stackTab.lock, lockRankTraceStackTab)
227 }
228
229 // traceBufHeader is per-P tracing buffer.
230 type traceBufHeader struct {
231         link     traceBufPtr             // in trace.empty/full
232         lastTime traceTime               // when we wrote the last event
233         pos      int                     // next write offset in arr
234         stk      [traceStackSize]uintptr // scratch buffer for traceback
235 }
236
237 // traceBuf is per-P tracing buffer.
238 type traceBuf struct {
239         _ sys.NotInHeap
240         traceBufHeader
241         arr [64<<10 - unsafe.Sizeof(traceBufHeader{})]byte // underlying buffer for traceBufHeader.buf
242 }
243
244 // traceBufPtr is a *traceBuf that is not traced by the garbage
245 // collector and doesn't have write barriers. traceBufs are not
246 // allocated from the GC'd heap, so this is safe, and are often
247 // manipulated in contexts where write barriers are not allowed, so
248 // this is necessary.
249 //
250 // TODO: Since traceBuf is now embedded runtime/internal/sys.NotInHeap, this isn't necessary.
251 type traceBufPtr uintptr
252
253 func (tp traceBufPtr) ptr() *traceBuf   { return (*traceBuf)(unsafe.Pointer(tp)) }
254 func (tp *traceBufPtr) set(b *traceBuf) { *tp = traceBufPtr(unsafe.Pointer(b)) }
255 func traceBufPtrOf(b *traceBuf) traceBufPtr {
256         return traceBufPtr(unsafe.Pointer(b))
257 }
258
259 // traceEnabled returns true if the trace is currently enabled.
260 //
261 // nosplit because it's called on the syscall path when stack movement is forbidden.
262 //
263 //go:nosplit
264 func traceEnabled() bool {
265         return trace.enabled
266 }
267
268 // traceShuttingDown returns true if the trace is currently shutting down.
269 //
270 //go:nosplit
271 func traceShuttingDown() bool {
272         return trace.shutdown
273 }
274
275 // traceLocker represents an M writing trace events. While a traceLocker value
276 // is valid, the tracer observes all operations on the G/M/P or trace events being
277 // written as happening atomically.
278 //
279 // This doesn't do much for the current tracer, because the current tracer doesn't
280 // need atomicity around non-trace runtime operations. All the state it needs it
281 // collects carefully during a STW.
282 type traceLocker struct {
283         enabled bool
284 }
285
286 // traceAcquire prepares this M for writing one or more trace events.
287 //
288 // This exists for compatibility with the upcoming new tracer; it doesn't do much
289 // in the current tracer.
290 //
291 // nosplit because it's called on the syscall path when stack movement is forbidden.
292 //
293 //go:nosplit
294 func traceAcquire() traceLocker {
295         if !traceEnabled() {
296                 return traceLocker{false}
297         }
298         return traceLocker{true}
299 }
300
301 // ok returns true if the traceLocker is valid (i.e. tracing is enabled).
302 //
303 // nosplit because it's called on the syscall path when stack movement is forbidden.
304 //
305 //go:nosplit
306 func (tl traceLocker) ok() bool {
307         return tl.enabled
308 }
309
310 // traceRelease indicates that this M is done writing trace events.
311 //
312 // This exists for compatibility with the upcoming new tracer; it doesn't do anything
313 // in the current tracer.
314 //
315 // nosplit because it's called on the syscall path when stack movement is forbidden.
316 //
317 //go:nosplit
318 func traceRelease(tl traceLocker) {
319 }
320
321 // StartTrace enables tracing for the current process.
322 // While tracing, the data will be buffered and available via ReadTrace.
323 // StartTrace returns an error if tracing is already enabled.
324 // Most clients should use the runtime/trace package or the testing package's
325 // -test.trace flag instead of calling StartTrace directly.
326 func StartTrace() error {
327         // Stop the world so that we can take a consistent snapshot
328         // of all goroutines at the beginning of the trace.
329         // Do not stop the world during GC so we ensure we always see
330         // a consistent view of GC-related events (e.g. a start is always
331         // paired with an end).
332         stopTheWorldGC(stwStartTrace)
333
334         // Prevent sysmon from running any code that could generate events.
335         lock(&sched.sysmonlock)
336
337         // We are in stop-the-world, but syscalls can finish and write to trace concurrently.
338         // Exitsyscall could check trace.enabled long before and then suddenly wake up
339         // and decide to write to trace at a random point in time.
340         // However, such syscall will use the global trace.buf buffer, because we've
341         // acquired all p's by doing stop-the-world. So this protects us from such races.
342         lock(&trace.bufLock)
343
344         if trace.enabled || trace.shutdown {
345                 unlock(&trace.bufLock)
346                 unlock(&sched.sysmonlock)
347                 startTheWorldGC()
348                 return errorString("tracing is already enabled")
349         }
350
351         // Can't set trace.enabled yet. While the world is stopped, exitsyscall could
352         // already emit a delayed event (see exitTicks in exitsyscall) if we set trace.enabled here.
353         // That would lead to an inconsistent trace:
354         // - either GoSysExit appears before EvGoInSyscall,
355         // - or GoSysExit appears for a goroutine for which we don't emit EvGoInSyscall below.
356         // To instruct traceEvent that it must not ignore events below, we set trace.startingTrace.
357         // trace.enabled is set afterwards once we have emitted all preliminary events.
358         mp := getg().m
359         mp.trace.startingTrace = true
360
361         // Obtain current stack ID to use in all traceEvGoCreate events below.
362         stkBuf := make([]uintptr, traceStackSize)
363         stackID := traceStackID(mp, stkBuf, 2)
364
365         profBuf := newProfBuf(2, profBufWordCount, profBufTagCount) // after the timestamp, header is [pp.id, gp.goid]
366         trace.cpuLogRead = profBuf
367
368         // We must not acquire trace.signalLock outside of a signal handler: a
369         // profiling signal may arrive at any time and try to acquire it, leading to
370         // deadlock. Because we can't use that lock to protect updates to
371         // trace.cpuLogWrite (only use of the structure it references), reads and
372         // writes of the pointer must be atomic. (And although this field is never
373         // the sole pointer to the profBuf value, it's best to allow a write barrier
374         // here.)
375         atomicstorep(unsafe.Pointer(&trace.cpuLogWrite), unsafe.Pointer(profBuf))
376
377         // World is stopped, no need to lock.
378         forEachGRace(func(gp *g) {
379                 status := readgstatus(gp)
380                 if status != _Gdead {
381                         gp.trace.seq = 0
382                         gp.trace.lastP = getg().m.p
383                         // +PCQuantum because traceFrameForPC expects return PCs and subtracts PCQuantum.
384                         id := trace.stackTab.put([]uintptr{logicalStackSentinel, startPCforTrace(gp.startpc) + sys.PCQuantum})
385                         traceEvent(traceEvGoCreate, -1, gp.goid, uint64(id), stackID)
386                 }
387                 if status == _Gwaiting {
388                         // traceEvGoWaiting is implied to have seq=1.
389                         gp.trace.seq++
390                         traceEvent(traceEvGoWaiting, -1, gp.goid)
391                 }
392                 if status == _Gsyscall {
393                         gp.trace.seq++
394                         gp.trace.tracedSyscallEnter = true
395                         traceEvent(traceEvGoInSyscall, -1, gp.goid)
396                 } else if status == _Gdead && gp.m != nil && gp.m.isextra {
397                         // Trigger two trace events for the dead g in the extra m,
398                         // since the next event of the g will be traceEvGoSysExit in exitsyscall,
399                         // while calling from C thread to Go.
400                         gp.trace.seq = 0
401                         gp.trace.lastP = getg().m.p
402                         // +PCQuantum because traceFrameForPC expects return PCs and subtracts PCQuantum.
403                         id := trace.stackTab.put([]uintptr{logicalStackSentinel, startPCforTrace(0) + sys.PCQuantum}) // no start pc
404                         traceEvent(traceEvGoCreate, -1, gp.goid, uint64(id), stackID)
405                         gp.trace.seq++
406                         gp.trace.tracedSyscallEnter = true
407                         traceEvent(traceEvGoInSyscall, -1, gp.goid)
408                 } else {
409                         // We need to explicitly clear the flag. A previous trace might have ended with a goroutine
410                         // not emitting a GoSysExit and clearing the flag, leaving it in a stale state. Clearing
411                         // it here makes it unambiguous to any goroutine exiting a syscall racing with us that
412                         // no EvGoInSyscall event was emitted for it. (It's not racy to set this flag here, because
413                         // it'll only get checked when the goroutine runs again, which will be after the world starts
414                         // again.)
415                         gp.trace.tracedSyscallEnter = false
416                 }
417         })
418         // Use a dummy traceLocker. The trace isn't enabled yet, but we can still write events.
419         tl := traceLocker{}
420         tl.ProcStart()
421         tl.GoStart()
422         // Note: startTicks needs to be set after we emit traceEvGoInSyscall events.
423         // If we do it the other way around, it is possible that exitsyscall will
424         // query sysExitTime after startTicks but before traceEvGoInSyscall timestamp.
425         // It will lead to a false conclusion that cputicks is broken.
426         trace.startTime = traceClockNow()
427         trace.startTicks = cputicks()
428         trace.startNanotime = nanotime()
429         trace.headerWritten = false
430         trace.footerWritten = false
431
432         // string to id mapping
433         //  0 : reserved for an empty string
434         //  remaining: other strings registered by traceString
435         trace.stringSeq = 0
436         trace.strings = make(map[string]uint64)
437
438         trace.seqGC = 0
439         mp.trace.startingTrace = false
440         trace.enabled = true
441
442         // Register runtime goroutine labels.
443         _, pid, bufp := traceAcquireBuffer()
444         for i, label := range gcMarkWorkerModeStrings[:] {
445                 trace.markWorkerLabels[i], bufp = traceString(bufp, pid, label)
446         }
447         traceReleaseBuffer(mp, pid)
448
449         unlock(&trace.bufLock)
450
451         unlock(&sched.sysmonlock)
452
453         // Record the current state of HeapGoal to avoid information loss in trace.
454         //
455         // Use the same dummy trace locker. The trace can't end until after we start
456         // the world, and we can safely trace from here.
457         tl.HeapGoal()
458
459         startTheWorldGC()
460         return nil
461 }
462
463 // StopTrace stops tracing, if it was previously enabled.
464 // StopTrace only returns after all the reads for the trace have completed.
465 func StopTrace() {
466         // Stop the world so that we can collect the trace buffers from all p's below,
467         // and also to avoid races with traceEvent.
468         stopTheWorldGC(stwStopTrace)
469
470         // See the comment in StartTrace.
471         lock(&sched.sysmonlock)
472
473         // See the comment in StartTrace.
474         lock(&trace.bufLock)
475
476         if !trace.enabled {
477                 unlock(&trace.bufLock)
478                 unlock(&sched.sysmonlock)
479                 startTheWorldGC()
480                 return
481         }
482
483         // Trace GoSched for us, and use a dummy locker. The world is stopped
484         // and we control whether the trace is enabled, so this is safe.
485         tl := traceLocker{}
486         tl.GoSched()
487
488         atomicstorep(unsafe.Pointer(&trace.cpuLogWrite), nil)
489         trace.cpuLogRead.close()
490         traceReadCPU()
491
492         // Loop over all allocated Ps because dead Ps may still have
493         // trace buffers.
494         for _, p := range allp[:cap(allp)] {
495                 buf := p.trace.buf
496                 if buf != 0 {
497                         traceFullQueue(buf)
498                         p.trace.buf = 0
499                 }
500         }
501         if trace.buf != 0 {
502                 buf := trace.buf
503                 trace.buf = 0
504                 if buf.ptr().pos != 0 {
505                         traceFullQueue(buf)
506                 }
507         }
508         if trace.cpuLogBuf != 0 {
509                 buf := trace.cpuLogBuf
510                 trace.cpuLogBuf = 0
511                 if buf.ptr().pos != 0 {
512                         traceFullQueue(buf)
513                 }
514         }
515
516         // Wait for startNanotime != endNanotime. On Windows the default interval between
517         // system clock ticks is typically between 1 and 15 milliseconds, which may not
518         // have passed since the trace started. Without nanotime moving forward, trace
519         // tooling has no way of identifying how much real time each cputicks time deltas
520         // represent.
521         for {
522                 trace.endTime = traceClockNow()
523                 trace.endTicks = cputicks()
524                 trace.endNanotime = nanotime()
525
526                 if trace.endNanotime != trace.startNanotime || faketime != 0 {
527                         break
528                 }
529                 osyield()
530         }
531
532         trace.enabled = false
533         trace.shutdown = true
534         unlock(&trace.bufLock)
535
536         unlock(&sched.sysmonlock)
537
538         startTheWorldGC()
539
540         // The world is started but we've set trace.shutdown, so new tracing can't start.
541         // Wait for the trace reader to flush pending buffers and stop.
542         semacquire(&trace.shutdownSema)
543         if raceenabled {
544                 raceacquire(unsafe.Pointer(&trace.shutdownSema))
545         }
546
547         systemstack(func() {
548                 // The lock protects us from races with StartTrace/StopTrace because they do stop-the-world.
549                 lock(&trace.lock)
550                 for _, p := range allp[:cap(allp)] {
551                         if p.trace.buf != 0 {
552                                 throw("trace: non-empty trace buffer in proc")
553                         }
554                 }
555                 if trace.buf != 0 {
556                         throw("trace: non-empty global trace buffer")
557                 }
558                 if trace.fullHead != 0 || trace.fullTail != 0 {
559                         throw("trace: non-empty full trace buffer")
560                 }
561                 if trace.reading != 0 || trace.reader.Load() != nil {
562                         throw("trace: reading after shutdown")
563                 }
564                 for trace.empty != 0 {
565                         buf := trace.empty
566                         trace.empty = buf.ptr().link
567                         sysFree(unsafe.Pointer(buf), unsafe.Sizeof(*buf.ptr()), &memstats.other_sys)
568                 }
569                 trace.strings = nil
570                 trace.shutdown = false
571                 trace.cpuLogRead = nil
572                 unlock(&trace.lock)
573         })
574 }
575
576 // ReadTrace returns the next chunk of binary tracing data, blocking until data
577 // is available. If tracing is turned off and all the data accumulated while it
578 // was on has been returned, ReadTrace returns nil. The caller must copy the
579 // returned data before calling ReadTrace again.
580 // ReadTrace must be called from one goroutine at a time.
581 func ReadTrace() []byte {
582 top:
583         var buf []byte
584         var park bool
585         systemstack(func() {
586                 buf, park = readTrace0()
587         })
588         if park {
589                 gopark(func(gp *g, _ unsafe.Pointer) bool {
590                         if !trace.reader.CompareAndSwapNoWB(nil, gp) {
591                                 // We're racing with another reader.
592                                 // Wake up and handle this case.
593                                 return false
594                         }
595
596                         if g2 := traceReader(); gp == g2 {
597                                 // New data arrived between unlocking
598                                 // and the CAS and we won the wake-up
599                                 // race, so wake up directly.
600                                 return false
601                         } else if g2 != nil {
602                                 printlock()
603                                 println("runtime: got trace reader", g2, g2.goid)
604                                 throw("unexpected trace reader")
605                         }
606
607                         return true
608                 }, nil, waitReasonTraceReaderBlocked, traceBlockSystemGoroutine, 2)
609                 goto top
610         }
611
612         return buf
613 }
614
615 // readTrace0 is ReadTrace's continuation on g0. This must run on the
616 // system stack because it acquires trace.lock.
617 //
618 //go:systemstack
619 func readTrace0() (buf []byte, park bool) {
620         if raceenabled {
621                 // g0 doesn't have a race context. Borrow the user G's.
622                 if getg().racectx != 0 {
623                         throw("expected racectx == 0")
624                 }
625                 getg().racectx = getg().m.curg.racectx
626                 // (This defer should get open-coded, which is safe on
627                 // the system stack.)
628                 defer func() { getg().racectx = 0 }()
629         }
630
631         // Optimistically look for CPU profile samples. This may write new stack
632         // records, and may write new tracing buffers. This must be done with the
633         // trace lock not held. footerWritten and shutdown are safe to access
634         // here. They are only mutated by this goroutine or during a STW.
635         if !trace.footerWritten && !trace.shutdown {
636                 traceReadCPU()
637         }
638
639         // This function must not allocate while holding trace.lock:
640         // allocation can call heap allocate, which will try to emit a trace
641         // event while holding heap lock.
642         lock(&trace.lock)
643
644         if trace.reader.Load() != nil {
645                 // More than one goroutine reads trace. This is bad.
646                 // But we rather do not crash the program because of tracing,
647                 // because tracing can be enabled at runtime on prod servers.
648                 unlock(&trace.lock)
649                 println("runtime: ReadTrace called from multiple goroutines simultaneously")
650                 return nil, false
651         }
652         // Recycle the old buffer.
653         if buf := trace.reading; buf != 0 {
654                 buf.ptr().link = trace.empty
655                 trace.empty = buf
656                 trace.reading = 0
657         }
658         // Write trace header.
659         if !trace.headerWritten {
660                 trace.headerWritten = true
661                 unlock(&trace.lock)
662                 return []byte("go 1.21 trace\x00\x00\x00"), false
663         }
664         // Wait for new data.
665         if trace.fullHead == 0 && !trace.shutdown {
666                 // We don't simply use a note because the scheduler
667                 // executes this goroutine directly when it wakes up
668                 // (also a note would consume an M).
669                 unlock(&trace.lock)
670                 return nil, true
671         }
672 newFull:
673         assertLockHeld(&trace.lock)
674         // Write a buffer.
675         if trace.fullHead != 0 {
676                 buf := traceFullDequeue()
677                 trace.reading = buf
678                 unlock(&trace.lock)
679                 return buf.ptr().arr[:buf.ptr().pos], false
680         }
681
682         // Write footer with timer frequency.
683         if !trace.footerWritten {
684                 trace.footerWritten = true
685                 freq := (float64(trace.endTicks-trace.startTicks) / traceTimeDiv) / (float64(trace.endNanotime-trace.startNanotime) / 1e9)
686                 if freq <= 0 {
687                         throw("trace: ReadTrace got invalid frequency")
688                 }
689                 unlock(&trace.lock)
690
691                 // Write frequency event.
692                 bufp := traceFlush(0, 0)
693                 buf := bufp.ptr()
694                 buf.byte(traceEvFrequency | 0<<traceArgCountShift)
695                 buf.varint(uint64(freq))
696
697                 // Dump stack table.
698                 // This will emit a bunch of full buffers, we will pick them up
699                 // on the next iteration.
700                 bufp = trace.stackTab.dump(bufp)
701
702                 // Flush final buffer.
703                 lock(&trace.lock)
704                 traceFullQueue(bufp)
705                 goto newFull // trace.lock should be held at newFull
706         }
707         // Done.
708         if trace.shutdown {
709                 unlock(&trace.lock)
710                 if raceenabled {
711                         // Model synchronization on trace.shutdownSema, which race
712                         // detector does not see. This is required to avoid false
713                         // race reports on writer passed to trace.Start.
714                         racerelease(unsafe.Pointer(&trace.shutdownSema))
715                 }
716                 // trace.enabled is already reset, so can call traceable functions.
717                 semrelease(&trace.shutdownSema)
718                 return nil, false
719         }
720         // Also bad, but see the comment above.
721         unlock(&trace.lock)
722         println("runtime: spurious wakeup of trace reader")
723         return nil, false
724 }
725
726 // traceReader returns the trace reader that should be woken up, if any.
727 // Callers should first check that trace.enabled or trace.shutdown is set.
728 //
729 // This must run on the system stack because it acquires trace.lock.
730 //
731 //go:systemstack
732 func traceReader() *g {
733         // Optimistic check first
734         if traceReaderAvailable() == nil {
735                 return nil
736         }
737         lock(&trace.lock)
738         gp := traceReaderAvailable()
739         if gp == nil || !trace.reader.CompareAndSwapNoWB(gp, nil) {
740                 unlock(&trace.lock)
741                 return nil
742         }
743         unlock(&trace.lock)
744         return gp
745 }
746
747 // traceReaderAvailable returns the trace reader if it is not currently
748 // scheduled and should be. Callers should first check that trace.enabled
749 // or trace.shutdown is set.
750 func traceReaderAvailable() *g {
751         if trace.fullHead != 0 || trace.shutdown {
752                 return trace.reader.Load()
753         }
754         return nil
755 }
756
757 // traceProcFree frees trace buffer associated with pp.
758 //
759 // This must run on the system stack because it acquires trace.lock.
760 //
761 //go:systemstack
762 func traceProcFree(pp *p) {
763         buf := pp.trace.buf
764         pp.trace.buf = 0
765         if buf == 0 {
766                 return
767         }
768         lock(&trace.lock)
769         traceFullQueue(buf)
770         unlock(&trace.lock)
771 }
772
773 // traceFullQueue queues buf into queue of full buffers.
774 func traceFullQueue(buf traceBufPtr) {
775         buf.ptr().link = 0
776         if trace.fullHead == 0 {
777                 trace.fullHead = buf
778         } else {
779                 trace.fullTail.ptr().link = buf
780         }
781         trace.fullTail = buf
782 }
783
784 // traceFullDequeue dequeues from queue of full buffers.
785 func traceFullDequeue() traceBufPtr {
786         buf := trace.fullHead
787         if buf == 0 {
788                 return 0
789         }
790         trace.fullHead = buf.ptr().link
791         if trace.fullHead == 0 {
792                 trace.fullTail = 0
793         }
794         buf.ptr().link = 0
795         return buf
796 }
797
798 // traceEvent writes a single event to trace buffer, flushing the buffer if necessary.
799 // ev is event type.
800 // If skip > 0, write current stack id as the last argument (skipping skip top frames).
801 // If skip = 0, this event type should contain a stack, but we don't want
802 // to collect and remember it for this particular call.
803 func traceEvent(ev byte, skip int, args ...uint64) {
804         mp, pid, bufp := traceAcquireBuffer()
805         // Double-check trace.enabled now that we've done m.locks++ and acquired bufLock.
806         // This protects from races between traceEvent and StartTrace/StopTrace.
807
808         // The caller checked that trace.enabled == true, but trace.enabled might have been
809         // turned off between the check and now. Check again. traceLockBuffer did mp.locks++,
810         // StopTrace does stopTheWorld, and stopTheWorld waits for mp.locks to go back to zero,
811         // so if we see trace.enabled == true now, we know it's true for the rest of the function.
812         // Exitsyscall can run even during stopTheWorld. The race with StartTrace/StopTrace
813         // during tracing in exitsyscall is resolved by locking trace.bufLock in traceLockBuffer.
814         //
815         // Note trace_userTaskCreate runs the same check.
816         if !trace.enabled && !mp.trace.startingTrace {
817                 traceReleaseBuffer(mp, pid)
818                 return
819         }
820
821         if skip > 0 {
822                 if getg() == mp.curg {
823                         skip++ // +1 because stack is captured in traceEventLocked.
824                 }
825         }
826         traceEventLocked(0, mp, pid, bufp, ev, 0, skip, args...)
827         traceReleaseBuffer(mp, pid)
828 }
829
830 // traceEventLocked writes a single event of type ev to the trace buffer bufp,
831 // flushing the buffer if necessary. pid is the id of the current P, or
832 // traceGlobProc if we're tracing without a real P.
833 //
834 // Preemption is disabled, and if running without a real P the global tracing
835 // buffer is locked.
836 //
837 // Events types that do not include a stack set skip to -1. Event types that
838 // include a stack may explicitly reference a stackID from the trace.stackTab
839 // (obtained by an earlier call to traceStackID). Without an explicit stackID,
840 // this function will automatically capture the stack of the goroutine currently
841 // running on mp, skipping skip top frames or, if skip is 0, writing out an
842 // empty stack record.
843 //
844 // It records the event's args to the traceBuf, and also makes an effort to
845 // reserve extraBytes bytes of additional space immediately following the event,
846 // in the same traceBuf.
847 func traceEventLocked(extraBytes int, mp *m, pid int32, bufp *traceBufPtr, ev byte, stackID uint32, skip int, args ...uint64) {
848         buf := bufp.ptr()
849         // TODO: test on non-zero extraBytes param.
850         maxSize := 2 + 5*traceBytesPerNumber + extraBytes // event type, length, sequence, timestamp, stack id and two add params
851         if buf == nil || len(buf.arr)-buf.pos < maxSize {
852                 systemstack(func() {
853                         buf = traceFlush(traceBufPtrOf(buf), pid).ptr()
854                 })
855                 bufp.set(buf)
856         }
857
858         ts := traceClockNow()
859         if ts <= buf.lastTime {
860                 ts = buf.lastTime + 1
861         }
862         tsDiff := uint64(ts - buf.lastTime)
863         buf.lastTime = ts
864         narg := byte(len(args))
865         if stackID != 0 || skip >= 0 {
866                 narg++
867         }
868         // We have only 2 bits for number of arguments.
869         // If number is >= 3, then the event type is followed by event length in bytes.
870         if narg > 3 {
871                 narg = 3
872         }
873         startPos := buf.pos
874         buf.byte(ev | narg<<traceArgCountShift)
875         var lenp *byte
876         if narg == 3 {
877                 // Reserve the byte for length assuming that length < 128.
878                 buf.varint(0)
879                 lenp = &buf.arr[buf.pos-1]
880         }
881         buf.varint(tsDiff)
882         for _, a := range args {
883                 buf.varint(a)
884         }
885         if stackID != 0 {
886                 buf.varint(uint64(stackID))
887         } else if skip == 0 {
888                 buf.varint(0)
889         } else if skip > 0 {
890                 buf.varint(traceStackID(mp, buf.stk[:], skip))
891         }
892         evSize := buf.pos - startPos
893         if evSize > maxSize {
894                 throw("invalid length of trace event")
895         }
896         if lenp != nil {
897                 // Fill in actual length.
898                 *lenp = byte(evSize - 2)
899         }
900 }
901
902 // traceCPUSample writes a CPU profile sample stack to the execution tracer's
903 // profiling buffer. It is called from a signal handler, so is limited in what
904 // it can do.
905 func traceCPUSample(gp *g, pp *p, stk []uintptr) {
906         if !traceEnabled() {
907                 // Tracing is usually turned off; don't spend time acquiring the signal
908                 // lock unless it's active.
909                 return
910         }
911
912         // Match the clock used in traceEventLocked
913         now := traceClockNow()
914         // The "header" here is the ID of the P that was running the profiled code,
915         // followed by the ID of the goroutine. (For normal CPU profiling, it's
916         // usually the number of samples with the given stack.) Near syscalls, pp
917         // may be nil. Reporting goid of 0 is fine for either g0 or a nil gp.
918         var hdr [2]uint64
919         if pp != nil {
920                 // Overflow records in profBuf have all header values set to zero. Make
921                 // sure that real headers have at least one bit set.
922                 hdr[0] = uint64(pp.id)<<1 | 0b1
923         } else {
924                 hdr[0] = 0b10
925         }
926         if gp != nil {
927                 hdr[1] = gp.goid
928         }
929
930         // Allow only one writer at a time
931         for !trace.signalLock.CompareAndSwap(0, 1) {
932                 // TODO: Is it safe to osyield here? https://go.dev/issue/52672
933                 osyield()
934         }
935
936         if log := (*profBuf)(atomic.Loadp(unsafe.Pointer(&trace.cpuLogWrite))); log != nil {
937                 // Note: we don't pass a tag pointer here (how should profiling tags
938                 // interact with the execution tracer?), but if we did we'd need to be
939                 // careful about write barriers. See the long comment in profBuf.write.
940                 log.write(nil, int64(now), hdr[:], stk)
941         }
942
943         trace.signalLock.Store(0)
944 }
945
946 func traceReadCPU() {
947         bufp := &trace.cpuLogBuf
948
949         for {
950                 data, tags, _ := trace.cpuLogRead.read(profBufNonBlocking)
951                 if len(data) == 0 {
952                         break
953                 }
954                 for len(data) > 0 {
955                         if len(data) < 4 || data[0] > uint64(len(data)) {
956                                 break // truncated profile
957                         }
958                         if data[0] < 4 || tags != nil && len(tags) < 1 {
959                                 break // malformed profile
960                         }
961                         if len(tags) < 1 {
962                                 break // mismatched profile records and tags
963                         }
964                         timestamp := data[1]
965                         ppid := data[2] >> 1
966                         if hasP := (data[2] & 0b1) != 0; !hasP {
967                                 ppid = ^uint64(0)
968                         }
969                         goid := data[3]
970                         stk := data[4:data[0]]
971                         empty := len(stk) == 1 && data[2] == 0 && data[3] == 0
972                         data = data[data[0]:]
973                         // No support here for reporting goroutine tags at the moment; if
974                         // that information is to be part of the execution trace, we'd
975                         // probably want to see when the tags are applied and when they
976                         // change, instead of only seeing them when we get a CPU sample.
977                         tags = tags[1:]
978
979                         if empty {
980                                 // Looks like an overflow record from the profBuf. Not much to
981                                 // do here, we only want to report full records.
982                                 //
983                                 // TODO: should we start a goroutine to drain the profBuf,
984                                 // rather than relying on a high-enough volume of tracing events
985                                 // to keep ReadTrace busy? https://go.dev/issue/52674
986                                 continue
987                         }
988
989                         buf := bufp.ptr()
990                         if buf == nil {
991                                 systemstack(func() {
992                                         *bufp = traceFlush(*bufp, 0)
993                                 })
994                                 buf = bufp.ptr()
995                         }
996                         nstk := 1
997                         buf.stk[0] = logicalStackSentinel
998                         for ; nstk < len(buf.stk) && nstk-1 < len(stk); nstk++ {
999                                 buf.stk[nstk] = uintptr(stk[nstk-1])
1000                         }
1001                         stackID := trace.stackTab.put(buf.stk[:nstk])
1002
1003                         traceEventLocked(0, nil, 0, bufp, traceEvCPUSample, stackID, 1, timestamp, ppid, goid)
1004                 }
1005         }
1006 }
1007
1008 // logicalStackSentinel is a sentinel value at pcBuf[0] signifying that
1009 // pcBuf[1:] holds a logical stack requiring no further processing. Any other
1010 // value at pcBuf[0] represents a skip value to apply to the physical stack in
1011 // pcBuf[1:] after inline expansion.
1012 const logicalStackSentinel = ^uintptr(0)
1013
1014 // traceStackID captures a stack trace into pcBuf, registers it in the trace
1015 // stack table, and returns its unique ID. pcBuf should have a length equal to
1016 // traceStackSize. skip controls the number of leaf frames to omit in order to
1017 // hide tracer internals from stack traces, see CL 5523.
1018 func traceStackID(mp *m, pcBuf []uintptr, skip int) uint64 {
1019         gp := getg()
1020         curgp := mp.curg
1021         nstk := 1
1022         if tracefpunwindoff() || mp.hasCgoOnStack() {
1023                 // Slow path: Unwind using default unwinder. Used when frame pointer
1024                 // unwinding is unavailable or disabled (tracefpunwindoff), or might
1025                 // produce incomplete results or crashes (hasCgoOnStack). Note that no
1026                 // cgo callback related crashes have been observed yet. The main
1027                 // motivation is to take advantage of a potentially registered cgo
1028                 // symbolizer.
1029                 pcBuf[0] = logicalStackSentinel
1030                 if curgp == gp {
1031                         nstk += callers(skip+1, pcBuf[1:])
1032                 } else if curgp != nil {
1033                         nstk += gcallers(curgp, skip, pcBuf[1:])
1034                 }
1035         } else {
1036                 // Fast path: Unwind using frame pointers.
1037                 pcBuf[0] = uintptr(skip)
1038                 if curgp == gp {
1039                         nstk += fpTracebackPCs(unsafe.Pointer(getfp()), pcBuf[1:])
1040                 } else if curgp != nil {
1041                         // We're called on the g0 stack through mcall(fn) or systemstack(fn). To
1042                         // behave like gcallers above, we start unwinding from sched.bp, which
1043                         // points to the caller frame of the leaf frame on g's stack. The return
1044                         // address of the leaf frame is stored in sched.pc, which we manually
1045                         // capture here.
1046                         pcBuf[1] = curgp.sched.pc
1047                         nstk += 1 + fpTracebackPCs(unsafe.Pointer(curgp.sched.bp), pcBuf[2:])
1048                 }
1049         }
1050         if nstk > 0 {
1051                 nstk-- // skip runtime.goexit
1052         }
1053         if nstk > 0 && curgp.goid == 1 {
1054                 nstk-- // skip runtime.main
1055         }
1056         id := trace.stackTab.put(pcBuf[:nstk])
1057         return uint64(id)
1058 }
1059
1060 // tracefpunwindoff returns true if frame pointer unwinding for the tracer is
1061 // disabled via GODEBUG or not supported by the architecture.
1062 // TODO(#60254): support frame pointer unwinding on plan9/amd64.
1063 func tracefpunwindoff() bool {
1064         return debug.tracefpunwindoff != 0 || (goarch.ArchFamily != goarch.AMD64 && goarch.ArchFamily != goarch.ARM64) || goos.IsPlan9 == 1
1065 }
1066
1067 // fpTracebackPCs populates pcBuf with the return addresses for each frame and
1068 // returns the number of PCs written to pcBuf. The returned PCs correspond to
1069 // "physical frames" rather than "logical frames"; that is if A is inlined into
1070 // B, this will return a PC for only B.
1071 func fpTracebackPCs(fp unsafe.Pointer, pcBuf []uintptr) (i int) {
1072         for i = 0; i < len(pcBuf) && fp != nil; i++ {
1073                 // return addr sits one word above the frame pointer
1074                 pcBuf[i] = *(*uintptr)(unsafe.Pointer(uintptr(fp) + goarch.PtrSize))
1075                 // follow the frame pointer to the next one
1076                 fp = unsafe.Pointer(*(*uintptr)(fp))
1077         }
1078         return i
1079 }
1080
1081 // traceAcquireBuffer returns trace buffer to use and, if necessary, locks it.
1082 func traceAcquireBuffer() (mp *m, pid int32, bufp *traceBufPtr) {
1083         // Any time we acquire a buffer, we may end up flushing it,
1084         // but flushes are rare. Record the lock edge even if it
1085         // doesn't happen this time.
1086         lockRankMayTraceFlush()
1087
1088         mp = acquirem()
1089         if p := mp.p.ptr(); p != nil {
1090                 return mp, p.id, &p.trace.buf
1091         }
1092         lock(&trace.bufLock)
1093         return mp, traceGlobProc, &trace.buf
1094 }
1095
1096 // traceReleaseBuffer releases a buffer previously acquired with traceAcquireBuffer.
1097 func traceReleaseBuffer(mp *m, pid int32) {
1098         if pid == traceGlobProc {
1099                 unlock(&trace.bufLock)
1100         }
1101         releasem(mp)
1102 }
1103
1104 // lockRankMayTraceFlush records the lock ranking effects of a
1105 // potential call to traceFlush.
1106 func lockRankMayTraceFlush() {
1107         lockWithRankMayAcquire(&trace.lock, getLockRank(&trace.lock))
1108 }
1109
1110 // traceFlush puts buf onto stack of full buffers and returns an empty buffer.
1111 //
1112 // This must run on the system stack because it acquires trace.lock.
1113 //
1114 //go:systemstack
1115 func traceFlush(buf traceBufPtr, pid int32) traceBufPtr {
1116         lock(&trace.lock)
1117         if buf != 0 {
1118                 traceFullQueue(buf)
1119         }
1120         if trace.empty != 0 {
1121                 buf = trace.empty
1122                 trace.empty = buf.ptr().link
1123         } else {
1124                 buf = traceBufPtr(sysAlloc(unsafe.Sizeof(traceBuf{}), &memstats.other_sys))
1125                 if buf == 0 {
1126                         throw("trace: out of memory")
1127                 }
1128         }
1129         bufp := buf.ptr()
1130         bufp.link.set(nil)
1131         bufp.pos = 0
1132
1133         // initialize the buffer for a new batch
1134         ts := traceClockNow()
1135         if ts <= bufp.lastTime {
1136                 ts = bufp.lastTime + 1
1137         }
1138         bufp.lastTime = ts
1139         bufp.byte(traceEvBatch | 1<<traceArgCountShift)
1140         bufp.varint(uint64(pid))
1141         bufp.varint(uint64(ts))
1142
1143         unlock(&trace.lock)
1144         return buf
1145 }
1146
1147 // traceString adds a string to the trace.strings and returns the id.
1148 func traceString(bufp *traceBufPtr, pid int32, s string) (uint64, *traceBufPtr) {
1149         if s == "" {
1150                 return 0, bufp
1151         }
1152
1153         lock(&trace.stringsLock)
1154         if raceenabled {
1155                 // raceacquire is necessary because the map access
1156                 // below is race annotated.
1157                 raceacquire(unsafe.Pointer(&trace.stringsLock))
1158         }
1159
1160         if id, ok := trace.strings[s]; ok {
1161                 if raceenabled {
1162                         racerelease(unsafe.Pointer(&trace.stringsLock))
1163                 }
1164                 unlock(&trace.stringsLock)
1165
1166                 return id, bufp
1167         }
1168
1169         trace.stringSeq++
1170         id := trace.stringSeq
1171         trace.strings[s] = id
1172
1173         if raceenabled {
1174                 racerelease(unsafe.Pointer(&trace.stringsLock))
1175         }
1176         unlock(&trace.stringsLock)
1177
1178         // memory allocation in above may trigger tracing and
1179         // cause *bufp changes. Following code now works with *bufp,
1180         // so there must be no memory allocation or any activities
1181         // that causes tracing after this point.
1182
1183         buf := bufp.ptr()
1184         size := 1 + 2*traceBytesPerNumber + len(s)
1185         if buf == nil || len(buf.arr)-buf.pos < size {
1186                 systemstack(func() {
1187                         buf = traceFlush(traceBufPtrOf(buf), pid).ptr()
1188                         bufp.set(buf)
1189                 })
1190         }
1191         buf.byte(traceEvString)
1192         buf.varint(id)
1193
1194         // double-check the string and the length can fit.
1195         // Otherwise, truncate the string.
1196         slen := len(s)
1197         if room := len(buf.arr) - buf.pos; room < slen+traceBytesPerNumber {
1198                 slen = room
1199         }
1200
1201         buf.varint(uint64(slen))
1202         buf.pos += copy(buf.arr[buf.pos:], s[:slen])
1203
1204         bufp.set(buf)
1205         return id, bufp
1206 }
1207
1208 // varint appends v to buf in little-endian-base-128 encoding.
1209 func (buf *traceBuf) varint(v uint64) {
1210         pos := buf.pos
1211         for ; v >= 0x80; v >>= 7 {
1212                 buf.arr[pos] = 0x80 | byte(v)
1213                 pos++
1214         }
1215         buf.arr[pos] = byte(v)
1216         pos++
1217         buf.pos = pos
1218 }
1219
1220 // varintAt writes varint v at byte position pos in buf. This always
1221 // consumes traceBytesPerNumber bytes. This is intended for when the
1222 // caller needs to reserve space for a varint but can't populate it
1223 // until later.
1224 func (buf *traceBuf) varintAt(pos int, v uint64) {
1225         for i := 0; i < traceBytesPerNumber; i++ {
1226                 if i < traceBytesPerNumber-1 {
1227                         buf.arr[pos] = 0x80 | byte(v)
1228                 } else {
1229                         buf.arr[pos] = byte(v)
1230                 }
1231                 v >>= 7
1232                 pos++
1233         }
1234 }
1235
1236 // byte appends v to buf.
1237 func (buf *traceBuf) byte(v byte) {
1238         buf.arr[buf.pos] = v
1239         buf.pos++
1240 }
1241
1242 // traceStackTable maps stack traces (arrays of PC's) to unique uint32 ids.
1243 // It is lock-free for reading.
1244 type traceStackTable struct {
1245         lock mutex // Must be acquired on the system stack
1246         seq  uint32
1247         mem  traceAlloc
1248         tab  [1 << 13]traceStackPtr
1249 }
1250
1251 // traceStack is a single stack in traceStackTable.
1252 type traceStack struct {
1253         link traceStackPtr
1254         hash uintptr
1255         id   uint32
1256         n    int
1257         stk  [0]uintptr // real type [n]uintptr
1258 }
1259
1260 type traceStackPtr uintptr
1261
1262 func (tp traceStackPtr) ptr() *traceStack { return (*traceStack)(unsafe.Pointer(tp)) }
1263
1264 // stack returns slice of PCs.
1265 func (ts *traceStack) stack() []uintptr {
1266         return (*[traceStackSize]uintptr)(unsafe.Pointer(&ts.stk))[:ts.n]
1267 }
1268
1269 // put returns a unique id for the stack trace pcs and caches it in the table,
1270 // if it sees the trace for the first time.
1271 func (tab *traceStackTable) put(pcs []uintptr) uint32 {
1272         if len(pcs) == 0 {
1273                 return 0
1274         }
1275         hash := memhash(unsafe.Pointer(&pcs[0]), 0, uintptr(len(pcs))*unsafe.Sizeof(pcs[0]))
1276         // First, search the hashtable w/o the mutex.
1277         if id := tab.find(pcs, hash); id != 0 {
1278                 return id
1279         }
1280         // Now, double check under the mutex.
1281         // Switch to the system stack so we can acquire tab.lock
1282         var id uint32
1283         systemstack(func() {
1284                 lock(&tab.lock)
1285                 if id = tab.find(pcs, hash); id != 0 {
1286                         unlock(&tab.lock)
1287                         return
1288                 }
1289                 // Create new record.
1290                 tab.seq++
1291                 stk := tab.newStack(len(pcs))
1292                 stk.hash = hash
1293                 stk.id = tab.seq
1294                 id = stk.id
1295                 stk.n = len(pcs)
1296                 stkpc := stk.stack()
1297                 copy(stkpc, pcs)
1298                 part := int(hash % uintptr(len(tab.tab)))
1299                 stk.link = tab.tab[part]
1300                 atomicstorep(unsafe.Pointer(&tab.tab[part]), unsafe.Pointer(stk))
1301                 unlock(&tab.lock)
1302         })
1303         return id
1304 }
1305
1306 // find checks if the stack trace pcs is already present in the table.
1307 func (tab *traceStackTable) find(pcs []uintptr, hash uintptr) uint32 {
1308         part := int(hash % uintptr(len(tab.tab)))
1309 Search:
1310         for stk := tab.tab[part].ptr(); stk != nil; stk = stk.link.ptr() {
1311                 if stk.hash == hash && stk.n == len(pcs) {
1312                         for i, stkpc := range stk.stack() {
1313                                 if stkpc != pcs[i] {
1314                                         continue Search
1315                                 }
1316                         }
1317                         return stk.id
1318                 }
1319         }
1320         return 0
1321 }
1322
1323 // newStack allocates a new stack of size n.
1324 func (tab *traceStackTable) newStack(n int) *traceStack {
1325         return (*traceStack)(tab.mem.alloc(unsafe.Sizeof(traceStack{}) + uintptr(n)*goarch.PtrSize))
1326 }
1327
1328 // traceFrames returns the frames corresponding to pcs. It may
1329 // allocate and may emit trace events.
1330 func traceFrames(bufp traceBufPtr, pcs []uintptr) ([]traceFrame, traceBufPtr) {
1331         frames := make([]traceFrame, 0, len(pcs))
1332         ci := CallersFrames(pcs)
1333         for {
1334                 var frame traceFrame
1335                 f, more := ci.Next()
1336                 frame, bufp = traceFrameForPC(bufp, 0, f)
1337                 frames = append(frames, frame)
1338                 if !more {
1339                         return frames, bufp
1340                 }
1341         }
1342 }
1343
1344 // dump writes all previously cached stacks to trace buffers,
1345 // releases all memory and resets state.
1346 //
1347 // This must run on the system stack because it calls traceFlush.
1348 //
1349 //go:systemstack
1350 func (tab *traceStackTable) dump(bufp traceBufPtr) traceBufPtr {
1351         for i := range tab.tab {
1352                 stk := tab.tab[i].ptr()
1353                 for ; stk != nil; stk = stk.link.ptr() {
1354                         var frames []traceFrame
1355                         frames, bufp = traceFrames(bufp, fpunwindExpand(stk.stack()))
1356
1357                         // Estimate the size of this record. This
1358                         // bound is pretty loose, but avoids counting
1359                         // lots of varint sizes.
1360                         maxSize := 1 + traceBytesPerNumber + (2+4*len(frames))*traceBytesPerNumber
1361                         // Make sure we have enough buffer space.
1362                         if buf := bufp.ptr(); len(buf.arr)-buf.pos < maxSize {
1363                                 bufp = traceFlush(bufp, 0)
1364                         }
1365
1366                         // Emit header, with space reserved for length.
1367                         buf := bufp.ptr()
1368                         buf.byte(traceEvStack | 3<<traceArgCountShift)
1369                         lenPos := buf.pos
1370                         buf.pos += traceBytesPerNumber
1371
1372                         // Emit body.
1373                         recPos := buf.pos
1374                         buf.varint(uint64(stk.id))
1375                         buf.varint(uint64(len(frames)))
1376                         for _, frame := range frames {
1377                                 buf.varint(uint64(frame.PC))
1378                                 buf.varint(frame.funcID)
1379                                 buf.varint(frame.fileID)
1380                                 buf.varint(frame.line)
1381                         }
1382
1383                         // Fill in size header.
1384                         buf.varintAt(lenPos, uint64(buf.pos-recPos))
1385                 }
1386         }
1387
1388         tab.mem.drop()
1389         *tab = traceStackTable{}
1390         lockInit(&((*tab).lock), lockRankTraceStackTab)
1391
1392         return bufp
1393 }
1394
1395 // fpunwindExpand checks if pcBuf contains logical frames (which include inlined
1396 // frames) or physical frames (produced by frame pointer unwinding) using a
1397 // sentinel value in pcBuf[0]. Logical frames are simply returned without the
1398 // sentinel. Physical frames are turned into logical frames via inline unwinding
1399 // and by applying the skip value that's stored in pcBuf[0].
1400 func fpunwindExpand(pcBuf []uintptr) []uintptr {
1401         if len(pcBuf) > 0 && pcBuf[0] == logicalStackSentinel {
1402                 // pcBuf contains logical rather than inlined frames, skip has already been
1403                 // applied, just return it without the sentinel value in pcBuf[0].
1404                 return pcBuf[1:]
1405         }
1406
1407         var (
1408                 lastFuncID = abi.FuncIDNormal
1409                 newPCBuf   = make([]uintptr, 0, traceStackSize)
1410                 skip       = pcBuf[0]
1411                 // skipOrAdd skips or appends retPC to newPCBuf and returns true if more
1412                 // pcs can be added.
1413                 skipOrAdd = func(retPC uintptr) bool {
1414                         if skip > 0 {
1415                                 skip--
1416                         } else {
1417                                 newPCBuf = append(newPCBuf, retPC)
1418                         }
1419                         return len(newPCBuf) < cap(newPCBuf)
1420                 }
1421         )
1422
1423 outer:
1424         for _, retPC := range pcBuf[1:] {
1425                 callPC := retPC - 1
1426                 fi := findfunc(callPC)
1427                 if !fi.valid() {
1428                         // There is no funcInfo if callPC belongs to a C function. In this case
1429                         // we still keep the pc, but don't attempt to expand inlined frames.
1430                         if more := skipOrAdd(retPC); !more {
1431                                 break outer
1432                         }
1433                         continue
1434                 }
1435
1436                 u, uf := newInlineUnwinder(fi, callPC)
1437                 for ; uf.valid(); uf = u.next(uf) {
1438                         sf := u.srcFunc(uf)
1439                         if sf.funcID == abi.FuncIDWrapper && elideWrapperCalling(lastFuncID) {
1440                                 // ignore wrappers
1441                         } else if more := skipOrAdd(uf.pc + 1); !more {
1442                                 break outer
1443                         }
1444                         lastFuncID = sf.funcID
1445                 }
1446         }
1447         return newPCBuf
1448 }
1449
1450 type traceFrame struct {
1451         PC     uintptr
1452         funcID uint64
1453         fileID uint64
1454         line   uint64
1455 }
1456
1457 // traceFrameForPC records the frame information.
1458 // It may allocate memory.
1459 func traceFrameForPC(buf traceBufPtr, pid int32, f Frame) (traceFrame, traceBufPtr) {
1460         bufp := &buf
1461         var frame traceFrame
1462         frame.PC = f.PC
1463
1464         fn := f.Function
1465         const maxLen = 1 << 10
1466         if len(fn) > maxLen {
1467                 fn = fn[len(fn)-maxLen:]
1468         }
1469         frame.funcID, bufp = traceString(bufp, pid, fn)
1470         frame.line = uint64(f.Line)
1471         file := f.File
1472         if len(file) > maxLen {
1473                 file = file[len(file)-maxLen:]
1474         }
1475         frame.fileID, bufp = traceString(bufp, pid, file)
1476         return frame, (*bufp)
1477 }
1478
1479 // traceAlloc is a non-thread-safe region allocator.
1480 // It holds a linked list of traceAllocBlock.
1481 type traceAlloc struct {
1482         head traceAllocBlockPtr
1483         off  uintptr
1484 }
1485
1486 // traceAllocBlock is a block in traceAlloc.
1487 //
1488 // traceAllocBlock is allocated from non-GC'd memory, so it must not
1489 // contain heap pointers. Writes to pointers to traceAllocBlocks do
1490 // not need write barriers.
1491 type traceAllocBlock struct {
1492         _    sys.NotInHeap
1493         next traceAllocBlockPtr
1494         data [64<<10 - goarch.PtrSize]byte
1495 }
1496
1497 // TODO: Since traceAllocBlock is now embedded runtime/internal/sys.NotInHeap, this isn't necessary.
1498 type traceAllocBlockPtr uintptr
1499
1500 func (p traceAllocBlockPtr) ptr() *traceAllocBlock   { return (*traceAllocBlock)(unsafe.Pointer(p)) }
1501 func (p *traceAllocBlockPtr) set(x *traceAllocBlock) { *p = traceAllocBlockPtr(unsafe.Pointer(x)) }
1502
1503 // alloc allocates n-byte block.
1504 func (a *traceAlloc) alloc(n uintptr) unsafe.Pointer {
1505         n = alignUp(n, goarch.PtrSize)
1506         if a.head == 0 || a.off+n > uintptr(len(a.head.ptr().data)) {
1507                 if n > uintptr(len(a.head.ptr().data)) {
1508                         throw("trace: alloc too large")
1509                 }
1510                 block := (*traceAllocBlock)(sysAlloc(unsafe.Sizeof(traceAllocBlock{}), &memstats.other_sys))
1511                 if block == nil {
1512                         throw("trace: out of memory")
1513                 }
1514                 block.next.set(a.head.ptr())
1515                 a.head.set(block)
1516                 a.off = 0
1517         }
1518         p := &a.head.ptr().data[a.off]
1519         a.off += n
1520         return unsafe.Pointer(p)
1521 }
1522
1523 // drop frees all previously allocated memory and resets the allocator.
1524 func (a *traceAlloc) drop() {
1525         for a.head != 0 {
1526                 block := a.head.ptr()
1527                 a.head.set(block.next.ptr())
1528                 sysFree(unsafe.Pointer(block), unsafe.Sizeof(traceAllocBlock{}), &memstats.other_sys)
1529         }
1530 }
1531
1532 // The following functions write specific events to trace.
1533
1534 func (_ traceLocker) Gomaxprocs(procs int32) {
1535         traceEvent(traceEvGomaxprocs, 1, uint64(procs))
1536 }
1537
1538 func (_ traceLocker) ProcStart() {
1539         traceEvent(traceEvProcStart, -1, uint64(getg().m.id))
1540 }
1541
1542 func (_ traceLocker) ProcStop(pp *p) {
1543         // Sysmon and stopTheWorld can stop Ps blocked in syscalls,
1544         // to handle this we temporary employ the P.
1545         mp := acquirem()
1546         oldp := mp.p
1547         mp.p.set(pp)
1548         traceEvent(traceEvProcStop, -1)
1549         mp.p = oldp
1550         releasem(mp)
1551 }
1552
1553 func (_ traceLocker) GCStart() {
1554         traceEvent(traceEvGCStart, 3, trace.seqGC)
1555         trace.seqGC++
1556 }
1557
1558 func (_ traceLocker) GCDone() {
1559         traceEvent(traceEvGCDone, -1)
1560 }
1561
1562 func (_ traceLocker) STWStart(reason stwReason) {
1563         // Don't trace if this STW is for trace start/stop, since traceEnabled
1564         // switches during a STW.
1565         if reason == stwStartTrace || reason == stwStopTrace {
1566                 return
1567         }
1568         getg().m.trace.tracedSTWStart = true
1569         traceEvent(traceEvSTWStart, -1, uint64(reason))
1570 }
1571
1572 func (_ traceLocker) STWDone() {
1573         mp := getg().m
1574         if !mp.trace.tracedSTWStart {
1575                 return
1576         }
1577         mp.trace.tracedSTWStart = false
1578         traceEvent(traceEvSTWDone, -1)
1579 }
1580
1581 // traceGCSweepStart prepares to trace a sweep loop. This does not
1582 // emit any events until traceGCSweepSpan is called.
1583 //
1584 // traceGCSweepStart must be paired with traceGCSweepDone and there
1585 // must be no preemption points between these two calls.
1586 func (_ traceLocker) GCSweepStart() {
1587         // Delay the actual GCSweepStart event until the first span
1588         // sweep. If we don't sweep anything, don't emit any events.
1589         pp := getg().m.p.ptr()
1590         if pp.trace.inSweep {
1591                 throw("double traceGCSweepStart")
1592         }
1593         pp.trace.inSweep, pp.trace.swept, pp.trace.reclaimed = true, 0, 0
1594 }
1595
1596 // traceGCSweepSpan traces the sweep of a single page.
1597 //
1598 // This may be called outside a traceGCSweepStart/traceGCSweepDone
1599 // pair; however, it will not emit any trace events in this case.
1600 func (_ traceLocker) GCSweepSpan(bytesSwept uintptr) {
1601         pp := getg().m.p.ptr()
1602         if pp.trace.inSweep {
1603                 if pp.trace.swept == 0 {
1604                         traceEvent(traceEvGCSweepStart, 1)
1605                 }
1606                 pp.trace.swept += bytesSwept
1607         }
1608 }
1609
1610 func (_ traceLocker) GCSweepDone() {
1611         pp := getg().m.p.ptr()
1612         if !pp.trace.inSweep {
1613                 throw("missing traceGCSweepStart")
1614         }
1615         if pp.trace.swept != 0 {
1616                 traceEvent(traceEvGCSweepDone, -1, uint64(pp.trace.swept), uint64(pp.trace.reclaimed))
1617         }
1618         pp.trace.inSweep = false
1619 }
1620
1621 func (_ traceLocker) GCMarkAssistStart() {
1622         traceEvent(traceEvGCMarkAssistStart, 1)
1623 }
1624
1625 func (_ traceLocker) GCMarkAssistDone() {
1626         traceEvent(traceEvGCMarkAssistDone, -1)
1627 }
1628
1629 func (_ traceLocker) GoCreate(newg *g, pc uintptr) {
1630         newg.trace.seq = 0
1631         newg.trace.lastP = getg().m.p
1632         // +PCQuantum because traceFrameForPC expects return PCs and subtracts PCQuantum.
1633         id := trace.stackTab.put([]uintptr{logicalStackSentinel, startPCforTrace(pc) + sys.PCQuantum})
1634         traceEvent(traceEvGoCreate, 2, newg.goid, uint64(id))
1635 }
1636
1637 func (_ traceLocker) GoStart() {
1638         gp := getg().m.curg
1639         pp := gp.m.p
1640         gp.trace.seq++
1641         if pp.ptr().gcMarkWorkerMode != gcMarkWorkerNotWorker {
1642                 traceEvent(traceEvGoStartLabel, -1, gp.goid, gp.trace.seq, trace.markWorkerLabels[pp.ptr().gcMarkWorkerMode])
1643         } else if gp.trace.lastP == pp {
1644                 traceEvent(traceEvGoStartLocal, -1, gp.goid)
1645         } else {
1646                 gp.trace.lastP = pp
1647                 traceEvent(traceEvGoStart, -1, gp.goid, gp.trace.seq)
1648         }
1649 }
1650
1651 func (_ traceLocker) GoEnd() {
1652         traceEvent(traceEvGoEnd, -1)
1653 }
1654
1655 func (_ traceLocker) GoSched() {
1656         gp := getg()
1657         gp.trace.lastP = gp.m.p
1658         traceEvent(traceEvGoSched, 1)
1659 }
1660
1661 func (_ traceLocker) GoPreempt() {
1662         gp := getg()
1663         gp.trace.lastP = gp.m.p
1664         traceEvent(traceEvGoPreempt, 1)
1665 }
1666
1667 func (_ traceLocker) GoPark(reason traceBlockReason, skip int) {
1668         // Convert the block reason directly to a trace event type.
1669         // See traceBlockReason for more information.
1670         traceEvent(byte(reason), skip)
1671 }
1672
1673 func (_ traceLocker) GoUnpark(gp *g, skip int) {
1674         pp := getg().m.p
1675         gp.trace.seq++
1676         if gp.trace.lastP == pp {
1677                 traceEvent(traceEvGoUnblockLocal, skip, gp.goid)
1678         } else {
1679                 gp.trace.lastP = pp
1680                 traceEvent(traceEvGoUnblock, skip, gp.goid, gp.trace.seq)
1681         }
1682 }
1683
1684 func (_ traceLocker) GoSysCall() {
1685         var skip int
1686         switch {
1687         case tracefpunwindoff():
1688                 // Unwind by skipping 1 frame relative to gp.syscallsp which is captured 3
1689                 // frames above this frame. For frame pointer unwinding we produce the same
1690                 // results by hard coding the number of frames in between our caller and the
1691                 // actual syscall, see cases below.
1692                 // TODO(felixge): Implement gp.syscallbp to avoid this workaround?
1693                 skip = 1
1694         case GOOS == "solaris" || GOOS == "illumos":
1695                 // These platforms don't use a libc_read_trampoline.
1696                 skip = 3
1697         default:
1698                 // Skip the extra trampoline frame used on most systems.
1699                 skip = 4
1700         }
1701         getg().m.curg.trace.tracedSyscallEnter = true
1702         traceEvent(traceEvGoSysCall, skip)
1703 }
1704
1705 func (_ traceLocker) GoSysExit() {
1706         gp := getg().m.curg
1707         if !gp.trace.tracedSyscallEnter {
1708                 // There was no syscall entry traced for us at all, so there's definitely
1709                 // no EvGoSysBlock or EvGoInSyscall before us, which EvGoSysExit requires.
1710                 return
1711         }
1712         gp.trace.tracedSyscallEnter = false
1713         ts := gp.trace.sysExitTime
1714         if ts != 0 && ts < trace.startTime {
1715                 // There is a race between the code that initializes sysExitTimes
1716                 // (in exitsyscall, which runs without a P, and therefore is not
1717                 // stopped with the rest of the world) and the code that initializes
1718                 // a new trace. The recorded sysExitTime must therefore be treated
1719                 // as "best effort". If they are valid for this trace, then great,
1720                 // use them for greater accuracy. But if they're not valid for this
1721                 // trace, assume that the trace was started after the actual syscall
1722                 // exit (but before we actually managed to start the goroutine,
1723                 // aka right now), and assign a fresh time stamp to keep the log consistent.
1724                 ts = 0
1725         }
1726         gp.trace.sysExitTime = 0
1727         gp.trace.seq++
1728         gp.trace.lastP = gp.m.p
1729         traceEvent(traceEvGoSysExit, -1, gp.goid, gp.trace.seq, uint64(ts))
1730 }
1731
1732 func (_ traceLocker) GoSysBlock(pp *p) {
1733         // Sysmon and stopTheWorld can declare syscalls running on remote Ps as blocked,
1734         // to handle this we temporary employ the P.
1735         mp := acquirem()
1736         oldp := mp.p
1737         mp.p.set(pp)
1738         traceEvent(traceEvGoSysBlock, -1)
1739         mp.p = oldp
1740         releasem(mp)
1741 }
1742
1743 func (_ traceLocker) HeapAlloc(live uint64) {
1744         traceEvent(traceEvHeapAlloc, -1, live)
1745 }
1746
1747 func (_ traceLocker) HeapGoal() {
1748         heapGoal := gcController.heapGoal()
1749         if heapGoal == ^uint64(0) {
1750                 // Heap-based triggering is disabled.
1751                 traceEvent(traceEvHeapGoal, -1, 0)
1752         } else {
1753                 traceEvent(traceEvHeapGoal, -1, heapGoal)
1754         }
1755 }
1756
1757 // To access runtime functions from runtime/trace.
1758 // See runtime/trace/annotation.go
1759
1760 //go:linkname trace_userTaskCreate runtime/trace.userTaskCreate
1761 func trace_userTaskCreate(id, parentID uint64, taskType string) {
1762         if !trace.enabled {
1763                 return
1764         }
1765
1766         // Same as in traceEvent.
1767         mp, pid, bufp := traceAcquireBuffer()
1768         if !trace.enabled && !mp.trace.startingTrace {
1769                 traceReleaseBuffer(mp, pid)
1770                 return
1771         }
1772
1773         typeStringID, bufp := traceString(bufp, pid, taskType)
1774         traceEventLocked(0, mp, pid, bufp, traceEvUserTaskCreate, 0, 3, id, parentID, typeStringID)
1775         traceReleaseBuffer(mp, pid)
1776 }
1777
1778 //go:linkname trace_userTaskEnd runtime/trace.userTaskEnd
1779 func trace_userTaskEnd(id uint64) {
1780         traceEvent(traceEvUserTaskEnd, 2, id)
1781 }
1782
1783 //go:linkname trace_userRegion runtime/trace.userRegion
1784 func trace_userRegion(id, mode uint64, name string) {
1785         if !trace.enabled {
1786                 return
1787         }
1788
1789         mp, pid, bufp := traceAcquireBuffer()
1790         if !trace.enabled && !mp.trace.startingTrace {
1791                 traceReleaseBuffer(mp, pid)
1792                 return
1793         }
1794
1795         nameStringID, bufp := traceString(bufp, pid, name)
1796         traceEventLocked(0, mp, pid, bufp, traceEvUserRegion, 0, 3, id, mode, nameStringID)
1797         traceReleaseBuffer(mp, pid)
1798 }
1799
1800 //go:linkname trace_userLog runtime/trace.userLog
1801 func trace_userLog(id uint64, category, message string) {
1802         if !trace.enabled {
1803                 return
1804         }
1805
1806         mp, pid, bufp := traceAcquireBuffer()
1807         if !trace.enabled && !mp.trace.startingTrace {
1808                 traceReleaseBuffer(mp, pid)
1809                 return
1810         }
1811
1812         categoryID, bufp := traceString(bufp, pid, category)
1813
1814         // The log message is recorded after all of the normal trace event
1815         // arguments, including the task, category, and stack IDs. We must ask
1816         // traceEventLocked to reserve extra space for the length of the message
1817         // and the message itself.
1818         extraSpace := traceBytesPerNumber + len(message)
1819         traceEventLocked(extraSpace, mp, pid, bufp, traceEvUserLog, 0, 3, id, categoryID)
1820         buf := bufp.ptr()
1821
1822         // double-check the message and its length can fit.
1823         // Otherwise, truncate the message.
1824         slen := len(message)
1825         if room := len(buf.arr) - buf.pos; room < slen+traceBytesPerNumber {
1826                 slen = room
1827         }
1828         buf.varint(uint64(slen))
1829         buf.pos += copy(buf.arr[buf.pos:], message[:slen])
1830
1831         traceReleaseBuffer(mp, pid)
1832 }
1833
1834 // the start PC of a goroutine for tracing purposes. If pc is a wrapper,
1835 // it returns the PC of the wrapped function. Otherwise it returns pc.
1836 func startPCforTrace(pc uintptr) uintptr {
1837         f := findfunc(pc)
1838         if !f.valid() {
1839                 return pc // may happen for locked g in extra M since its pc is 0.
1840         }
1841         w := funcdata(f, abi.FUNCDATA_WrapInfo)
1842         if w == nil {
1843                 return pc // not a wrapper
1844         }
1845         return f.datap.textAddr(*(*uint32)(w))
1846 }
1847
1848 // OneNewExtraM registers the fact that a new extra M was created with
1849 // the tracer. This matters if the M (which has an attached G) is used while
1850 // the trace is still active because if it is, we need the fact that it exists
1851 // to show up in the final trace.
1852 func (tl traceLocker) OneNewExtraM(gp *g) {
1853         // Trigger two trace events for the locked g in the extra m,
1854         // since the next event of the g will be traceEvGoSysExit in exitsyscall,
1855         // while calling from C thread to Go.
1856         tl.GoCreate(gp, 0) // no start pc
1857         gp.trace.seq++
1858         traceEvent(traceEvGoInSyscall, -1, gp.goid)
1859 }
1860
1861 // traceTime represents a timestamp for the trace.
1862 type traceTime uint64
1863
1864 // traceClockNow returns a monotonic timestamp. The clock this function gets
1865 // the timestamp from is specific to tracing, and shouldn't be mixed with other
1866 // clock sources.
1867 //
1868 // nosplit because it's called from exitsyscall, which is nosplit.
1869 //
1870 //go:nosplit
1871 func traceClockNow() traceTime {
1872         return traceTime(cputicks() / traceTimeDiv)
1873 }