]> Cypherpunks.ru repositories - gostls13.git/blob - src/runtime/trace.go
d85b0a985cbd6e05f336408beddfa83a487050e7
[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         "runtime/internal/atomic"
17         "unsafe"
18 )
19
20 // Event types in the trace, args are given in square brackets.
21 const (
22         traceEvNone           = 0  // unused
23         traceEvBatch          = 1  // start of per-P batch of events [pid, timestamp]
24         traceEvFrequency      = 2  // contains tracer timer frequency [frequency (ticks per second)]
25         traceEvStack          = 3  // stack [stack id, number of PCs, array of PCs]
26         traceEvGomaxprocs     = 4  // current value of GOMAXPROCS [timestamp, GOMAXPROCS, stack id]
27         traceEvProcStart      = 5  // start of P [timestamp, thread id]
28         traceEvProcStop       = 6  // stop of P [timestamp]
29         traceEvGCStart        = 7  // GC start [timestamp, stack id]
30         traceEvGCDone         = 8  // GC done [timestamp]
31         traceEvGCScanStart    = 9  // GC scan start [timestamp]
32         traceEvGCScanDone     = 10 // GC scan done [timestamp]
33         traceEvGCSweepStart   = 11 // GC sweep start [timestamp, stack id]
34         traceEvGCSweepDone    = 12 // GC sweep done [timestamp]
35         traceEvGoCreate       = 13 // goroutine creation [timestamp, new goroutine id, start PC, stack id]
36         traceEvGoStart        = 14 // goroutine starts running [timestamp, goroutine id]
37         traceEvGoEnd          = 15 // goroutine ends [timestamp]
38         traceEvGoStop         = 16 // goroutine stops (like in select{}) [timestamp, stack]
39         traceEvGoSched        = 17 // goroutine calls Gosched [timestamp, stack]
40         traceEvGoPreempt      = 18 // goroutine is preempted [timestamp, stack]
41         traceEvGoSleep        = 19 // goroutine calls Sleep [timestamp, stack]
42         traceEvGoBlock        = 20 // goroutine blocks [timestamp, stack]
43         traceEvGoUnblock      = 21 // goroutine is unblocked [timestamp, goroutine id, stack]
44         traceEvGoBlockSend    = 22 // goroutine blocks on chan send [timestamp, stack]
45         traceEvGoBlockRecv    = 23 // goroutine blocks on chan recv [timestamp, stack]
46         traceEvGoBlockSelect  = 24 // goroutine blocks on select [timestamp, stack]
47         traceEvGoBlockSync    = 25 // goroutine blocks on Mutex/RWMutex [timestamp, stack]
48         traceEvGoBlockCond    = 26 // goroutine blocks on Cond [timestamp, stack]
49         traceEvGoBlockNet     = 27 // goroutine blocks on network [timestamp, stack]
50         traceEvGoSysCall      = 28 // syscall enter [timestamp, stack]
51         traceEvGoSysExit      = 29 // syscall exit [timestamp, goroutine id, real timestamp]
52         traceEvGoSysBlock     = 30 // syscall blocks [timestamp]
53         traceEvGoWaiting      = 31 // denotes that goroutine is blocked when tracing starts [goroutine id]
54         traceEvGoInSyscall    = 32 // denotes that goroutine is in syscall when tracing starts [goroutine id]
55         traceEvHeapAlloc      = 33 // memstats.heap_live change [timestamp, heap_alloc]
56         traceEvNextGC         = 34 // memstats.next_gc change [timestamp, next_gc]
57         traceEvTimerGoroutine = 35 // denotes timer goroutine [timer goroutine id]
58         traceEvFutileWakeup   = 36 // denotes that the previous wakeup of this goroutine was futile [timestamp]
59         traceEvCount          = 37
60 )
61
62 const (
63         // Timestamps in trace are cputicks/traceTickDiv.
64         // This makes absolute values of timestamp diffs smaller,
65         // and so they are encoded in less number of bytes.
66         // 64 on x86 is somewhat arbitrary (one tick is ~20ns on a 3GHz machine).
67         // The suggested increment frequency for PowerPC's time base register is
68         // 512 MHz according to Power ISA v2.07 section 6.2, so we use 16 on ppc64
69         // and ppc64le.
70         // Tracing won't work reliably for architectures where cputicks is emulated
71         // by nanotime, so the value doesn't matter for those architectures.
72         traceTickDiv = 16 + 48*(goarch_386|goarch_amd64|goarch_amd64p32)
73         // Maximum number of PCs in a single stack trace.
74         // Since events contain only stack id rather than whole stack trace,
75         // we can allow quite large values here.
76         traceStackSize = 128
77         // Identifier of a fake P that is used when we trace without a real P.
78         traceGlobProc = -1
79         // Maximum number of bytes to encode uint64 in base-128.
80         traceBytesPerNumber = 10
81         // Shift of the number of arguments in the first event byte.
82         traceArgCountShift = 6
83         // Flag passed to traceGoPark to denote that the previous wakeup of this
84         // goroutine was futile. For example, a goroutine was unblocked on a mutex,
85         // but another goroutine got ahead and acquired the mutex before the first
86         // goroutine is scheduled, so the first goroutine has to block again.
87         // Such wakeups happen on buffered channels and sync.Mutex,
88         // but are generally not interesting for end user.
89         traceFutileWakeup byte = 128
90 )
91
92 // trace is global tracing context.
93 var trace struct {
94         lock          mutex       // protects the following members
95         lockOwner     *g          // to avoid deadlocks during recursive lock locks
96         enabled       bool        // when set runtime traces events
97         shutdown      bool        // set when we are waiting for trace reader to finish after setting enabled to false
98         headerWritten bool        // whether ReadTrace has emitted trace header
99         footerWritten bool        // whether ReadTrace has emitted trace footer
100         shutdownSema  uint32      // used to wait for ReadTrace completion
101         seqStart      uint64      // sequence number when tracing was started
102         ticksStart    int64       // cputicks when tracing was started
103         ticksEnd      int64       // cputicks when tracing was stopped
104         timeStart     int64       // nanotime when tracing was started
105         timeEnd       int64       // nanotime when tracing was stopped
106         reading       traceBufPtr // buffer currently handed off to user
107         empty         traceBufPtr // stack of empty buffers
108         fullHead      traceBufPtr // queue of full buffers
109         fullTail      traceBufPtr
110         reader        *g              // goroutine that called ReadTrace, or nil
111         stackTab      traceStackTable // maps stack traces to unique ids
112
113         bufLock mutex       // protects buf
114         buf     traceBufPtr // global trace buffer, used when running without a p
115 }
116
117 var traceseq uint64 // global trace sequence number
118
119 // tracestamp returns a consistent sequence number, time stamp pair
120 // for use in a trace. We need to make sure that time stamp ordering
121 // (assuming synchronized CPUs) and sequence ordering match.
122 // To do that, we increment traceseq, grab ticks, and increment traceseq again.
123 // We treat odd traceseq as a sign that another thread is in the middle
124 // of the sequence and spin until it is done.
125 // Not splitting stack to avoid preemption, just in case the call sites
126 // that used to call xadd64 and cputicks are sensitive to that.
127 //go:nosplit
128 func tracestamp() (seq uint64, ts int64) {
129         seq = atomic.Load64(&traceseq)
130         for seq&1 != 0 || !atomic.Cas64(&traceseq, seq, seq+1) {
131                 seq = atomic.Load64(&traceseq)
132         }
133         ts = cputicks()
134         atomic.Store64(&traceseq, seq+2)
135         return seq >> 1, ts
136 }
137
138 // traceBufHeader is per-P tracing buffer.
139 type traceBufHeader struct {
140         link      traceBufPtr             // in trace.empty/full
141         lastSeq   uint64                  // sequence number of last event
142         lastTicks uint64                  // when we wrote the last event
143         pos       int                     // next write offset in arr
144         stk       [traceStackSize]uintptr // scratch buffer for traceback
145 }
146
147 // traceBuf is per-P tracing buffer.
148 type traceBuf struct {
149         traceBufHeader
150         arr [64<<10 - unsafe.Sizeof(traceBufHeader{})]byte // underlying buffer for traceBufHeader.buf
151 }
152
153 // traceBufPtr is a *traceBuf that is not traced by the garbage
154 // collector and doesn't have write barriers. traceBufs are not
155 // allocated from the GC'd heap, so this is safe, and are often
156 // manipulated in contexts where write barriers are not allowed, so
157 // this is necessary.
158 type traceBufPtr uintptr
159
160 func (tp traceBufPtr) ptr() *traceBuf   { return (*traceBuf)(unsafe.Pointer(tp)) }
161 func (tp *traceBufPtr) set(b *traceBuf) { *tp = traceBufPtr(unsafe.Pointer(b)) }
162 func traceBufPtrOf(b *traceBuf) traceBufPtr {
163         return traceBufPtr(unsafe.Pointer(b))
164 }
165
166 // StartTrace enables tracing for the current process.
167 // While tracing, the data will be buffered and available via ReadTrace.
168 // StartTrace returns an error if tracing is already enabled.
169 // Most clients should use the runtime/trace package or the testing package's
170 // -test.trace flag instead of calling StartTrace directly.
171 func StartTrace() error {
172         // Stop the world, so that we can take a consistent snapshot
173         // of all goroutines at the beginning of the trace.
174         stopTheWorld("start tracing")
175
176         // We are in stop-the-world, but syscalls can finish and write to trace concurrently.
177         // Exitsyscall could check trace.enabled long before and then suddenly wake up
178         // and decide to write to trace at a random point in time.
179         // However, such syscall will use the global trace.buf buffer, because we've
180         // acquired all p's by doing stop-the-world. So this protects us from such races.
181         lock(&trace.bufLock)
182
183         if trace.enabled || trace.shutdown {
184                 unlock(&trace.bufLock)
185                 startTheWorld()
186                 return errorString("tracing is already enabled")
187         }
188
189         trace.seqStart, trace.ticksStart = tracestamp()
190         trace.timeStart = nanotime()
191         trace.headerWritten = false
192         trace.footerWritten = false
193
194         // Can't set trace.enabled yet. While the world is stopped, exitsyscall could
195         // already emit a delayed event (see exitTicks in exitsyscall) if we set trace.enabled here.
196         // That would lead to an inconsistent trace:
197         // - either GoSysExit appears before EvGoInSyscall,
198         // - or GoSysExit appears for a goroutine for which we don't emit EvGoInSyscall below.
199         // To instruct traceEvent that it must not ignore events below, we set startingtrace.
200         // trace.enabled is set afterwards once we have emitted all preliminary events.
201         _g_ := getg()
202         _g_.m.startingtrace = true
203         for _, gp := range allgs {
204                 status := readgstatus(gp)
205                 if status != _Gdead {
206                         traceGoCreate(gp, gp.startpc)
207                 }
208                 if status == _Gwaiting {
209                         traceEvent(traceEvGoWaiting, -1, uint64(gp.goid))
210                 }
211                 if status == _Gsyscall {
212                         traceEvent(traceEvGoInSyscall, -1, uint64(gp.goid))
213                 } else {
214                         gp.sysblocktraced = false
215                 }
216         }
217         traceProcStart()
218         traceGoStart()
219         _g_.m.startingtrace = false
220         trace.enabled = true
221
222         unlock(&trace.bufLock)
223
224         startTheWorld()
225         return nil
226 }
227
228 // StopTrace stops tracing, if it was previously enabled.
229 // StopTrace only returns after all the reads for the trace have completed.
230 func StopTrace() {
231         // Stop the world so that we can collect the trace buffers from all p's below,
232         // and also to avoid races with traceEvent.
233         stopTheWorld("stop tracing")
234
235         // See the comment in StartTrace.
236         lock(&trace.bufLock)
237
238         if !trace.enabled {
239                 unlock(&trace.bufLock)
240                 startTheWorld()
241                 return
242         }
243
244         traceGoSched()
245
246         for _, p := range &allp {
247                 if p == nil {
248                         break
249                 }
250                 buf := p.tracebuf
251                 if buf != 0 {
252                         traceFullQueue(buf)
253                         p.tracebuf = 0
254                 }
255         }
256         if trace.buf != 0 && trace.buf.ptr().pos != 0 {
257                 buf := trace.buf
258                 trace.buf = 0
259                 traceFullQueue(buf)
260         }
261
262         for {
263                 trace.ticksEnd = cputicks()
264                 trace.timeEnd = nanotime()
265                 // Windows time can tick only every 15ms, wait for at least one tick.
266                 if trace.timeEnd != trace.timeStart {
267                         break
268                 }
269                 osyield()
270         }
271
272         trace.enabled = false
273         trace.shutdown = true
274         trace.stackTab.dump()
275
276         unlock(&trace.bufLock)
277
278         startTheWorld()
279
280         // The world is started but we've set trace.shutdown, so new tracing can't start.
281         // Wait for the trace reader to flush pending buffers and stop.
282         semacquire(&trace.shutdownSema, false)
283         if raceenabled {
284                 raceacquire(unsafe.Pointer(&trace.shutdownSema))
285         }
286
287         // The lock protects us from races with StartTrace/StopTrace because they do stop-the-world.
288         lock(&trace.lock)
289         for _, p := range &allp {
290                 if p == nil {
291                         break
292                 }
293                 if p.tracebuf != 0 {
294                         throw("trace: non-empty trace buffer in proc")
295                 }
296         }
297         if trace.buf != 0 {
298                 throw("trace: non-empty global trace buffer")
299         }
300         if trace.fullHead != 0 || trace.fullTail != 0 {
301                 throw("trace: non-empty full trace buffer")
302         }
303         if trace.reading != 0 || trace.reader != nil {
304                 throw("trace: reading after shutdown")
305         }
306         for trace.empty != 0 {
307                 buf := trace.empty
308                 trace.empty = buf.ptr().link
309                 sysFree(unsafe.Pointer(buf), unsafe.Sizeof(*buf.ptr()), &memstats.other_sys)
310         }
311         trace.shutdown = false
312         unlock(&trace.lock)
313 }
314
315 // ReadTrace returns the next chunk of binary tracing data, blocking until data
316 // is available. If tracing is turned off and all the data accumulated while it
317 // was on has been returned, ReadTrace returns nil. The caller must copy the
318 // returned data before calling ReadTrace again.
319 // ReadTrace must be called from one goroutine at a time.
320 func ReadTrace() []byte {
321         // This function may need to lock trace.lock recursively
322         // (goparkunlock -> traceGoPark -> traceEvent -> traceFlush).
323         // To allow this we use trace.lockOwner.
324         // Also this function must not allocate while holding trace.lock:
325         // allocation can call heap allocate, which will try to emit a trace
326         // event while holding heap lock.
327         lock(&trace.lock)
328         trace.lockOwner = getg()
329
330         if trace.reader != nil {
331                 // More than one goroutine reads trace. This is bad.
332                 // But we rather do not crash the program because of tracing,
333                 // because tracing can be enabled at runtime on prod servers.
334                 trace.lockOwner = nil
335                 unlock(&trace.lock)
336                 println("runtime: ReadTrace called from multiple goroutines simultaneously")
337                 return nil
338         }
339         // Recycle the old buffer.
340         if buf := trace.reading; buf != 0 {
341                 buf.ptr().link = trace.empty
342                 trace.empty = buf
343                 trace.reading = 0
344         }
345         // Write trace header.
346         if !trace.headerWritten {
347                 trace.headerWritten = true
348                 trace.lockOwner = nil
349                 unlock(&trace.lock)
350                 return []byte("go 1.5 trace\x00\x00\x00\x00")
351         }
352         // Wait for new data.
353         if trace.fullHead == 0 && !trace.shutdown {
354                 trace.reader = getg()
355                 goparkunlock(&trace.lock, "trace reader (blocked)", traceEvGoBlock, 2)
356                 lock(&trace.lock)
357         }
358         // Write a buffer.
359         if trace.fullHead != 0 {
360                 buf := traceFullDequeue()
361                 trace.reading = buf
362                 trace.lockOwner = nil
363                 unlock(&trace.lock)
364                 return buf.ptr().arr[:buf.ptr().pos]
365         }
366         // Write footer with timer frequency.
367         if !trace.footerWritten {
368                 trace.footerWritten = true
369                 // Use float64 because (trace.ticksEnd - trace.ticksStart) * 1e9 can overflow int64.
370                 freq := float64(trace.ticksEnd-trace.ticksStart) * 1e9 / float64(trace.timeEnd-trace.timeStart) / traceTickDiv
371                 trace.lockOwner = nil
372                 unlock(&trace.lock)
373                 var data []byte
374                 data = append(data, traceEvFrequency|0<<traceArgCountShift)
375                 data = traceAppend(data, uint64(freq))
376                 data = traceAppend(data, 0)
377                 if timers.gp != nil {
378                         data = append(data, traceEvTimerGoroutine|0<<traceArgCountShift)
379                         data = traceAppend(data, uint64(timers.gp.goid))
380                         data = traceAppend(data, 0)
381                 }
382                 return data
383         }
384         // Done.
385         if trace.shutdown {
386                 trace.lockOwner = nil
387                 unlock(&trace.lock)
388                 if raceenabled {
389                         // Model synchronization on trace.shutdownSema, which race
390                         // detector does not see. This is required to avoid false
391                         // race reports on writer passed to trace.Start.
392                         racerelease(unsafe.Pointer(&trace.shutdownSema))
393                 }
394                 // trace.enabled is already reset, so can call traceable functions.
395                 semrelease(&trace.shutdownSema)
396                 return nil
397         }
398         // Also bad, but see the comment above.
399         trace.lockOwner = nil
400         unlock(&trace.lock)
401         println("runtime: spurious wakeup of trace reader")
402         return nil
403 }
404
405 // traceReader returns the trace reader that should be woken up, if any.
406 func traceReader() *g {
407         if trace.reader == nil || (trace.fullHead == 0 && !trace.shutdown) {
408                 return nil
409         }
410         lock(&trace.lock)
411         if trace.reader == nil || (trace.fullHead == 0 && !trace.shutdown) {
412                 unlock(&trace.lock)
413                 return nil
414         }
415         gp := trace.reader
416         trace.reader = nil
417         unlock(&trace.lock)
418         return gp
419 }
420
421 // traceProcFree frees trace buffer associated with pp.
422 func traceProcFree(pp *p) {
423         buf := pp.tracebuf
424         pp.tracebuf = 0
425         if buf == 0 {
426                 return
427         }
428         lock(&trace.lock)
429         traceFullQueue(buf)
430         unlock(&trace.lock)
431 }
432
433 // traceFullQueue queues buf into queue of full buffers.
434 func traceFullQueue(buf traceBufPtr) {
435         buf.ptr().link = 0
436         if trace.fullHead == 0 {
437                 trace.fullHead = buf
438         } else {
439                 trace.fullTail.ptr().link = buf
440         }
441         trace.fullTail = buf
442 }
443
444 // traceFullDequeue dequeues from queue of full buffers.
445 func traceFullDequeue() traceBufPtr {
446         buf := trace.fullHead
447         if buf == 0 {
448                 return 0
449         }
450         trace.fullHead = buf.ptr().link
451         if trace.fullHead == 0 {
452                 trace.fullTail = 0
453         }
454         buf.ptr().link = 0
455         return buf
456 }
457
458 // traceEvent writes a single event to trace buffer, flushing the buffer if necessary.
459 // ev is event type.
460 // If skip > 0, write current stack id as the last argument (skipping skip top frames).
461 // If skip = 0, this event type should contain a stack, but we don't want
462 // to collect and remember it for this particular call.
463 func traceEvent(ev byte, skip int, args ...uint64) {
464         mp, pid, bufp := traceAcquireBuffer()
465         // Double-check trace.enabled now that we've done m.locks++ and acquired bufLock.
466         // This protects from races between traceEvent and StartTrace/StopTrace.
467
468         // The caller checked that trace.enabled == true, but trace.enabled might have been
469         // turned off between the check and now. Check again. traceLockBuffer did mp.locks++,
470         // StopTrace does stopTheWorld, and stopTheWorld waits for mp.locks to go back to zero,
471         // so if we see trace.enabled == true now, we know it's true for the rest of the function.
472         // Exitsyscall can run even during stopTheWorld. The race with StartTrace/StopTrace
473         // during tracing in exitsyscall is resolved by locking trace.bufLock in traceLockBuffer.
474         if !trace.enabled && !mp.startingtrace {
475                 traceReleaseBuffer(pid)
476                 return
477         }
478         buf := (*bufp).ptr()
479         const maxSize = 2 + 5*traceBytesPerNumber // event type, length, sequence, timestamp, stack id and two add params
480         if buf == nil || len(buf.arr)-buf.pos < maxSize {
481                 buf = traceFlush(traceBufPtrOf(buf)).ptr()
482                 (*bufp).set(buf)
483         }
484
485         seq, ticksraw := tracestamp()
486         seqDiff := seq - buf.lastSeq
487         ticks := uint64(ticksraw) / traceTickDiv
488         tickDiff := ticks - buf.lastTicks
489         if buf.pos == 0 {
490                 buf.byte(traceEvBatch | 1<<traceArgCountShift)
491                 buf.varint(uint64(pid))
492                 buf.varint(seq)
493                 buf.varint(ticks)
494                 seqDiff = 0
495                 tickDiff = 0
496         }
497         buf.lastSeq = seq
498         buf.lastTicks = ticks
499         narg := byte(len(args))
500         if skip >= 0 {
501                 narg++
502         }
503         // We have only 2 bits for number of arguments.
504         // If number is >= 3, then the event type is followed by event length in bytes.
505         if narg > 3 {
506                 narg = 3
507         }
508         startPos := buf.pos
509         buf.byte(ev | narg<<traceArgCountShift)
510         var lenp *byte
511         if narg == 3 {
512                 // Reserve the byte for length assuming that length < 128.
513                 buf.varint(0)
514                 lenp = &buf.arr[buf.pos-1]
515         }
516         buf.varint(seqDiff)
517         buf.varint(tickDiff)
518         for _, a := range args {
519                 buf.varint(a)
520         }
521         if skip == 0 {
522                 buf.varint(0)
523         } else if skip > 0 {
524                 _g_ := getg()
525                 gp := mp.curg
526                 var nstk int
527                 if gp == _g_ {
528                         nstk = callers(skip, buf.stk[:])
529                 } else if gp != nil {
530                         gp = mp.curg
531                         nstk = gcallers(gp, skip, buf.stk[:])
532                 }
533                 if nstk > 0 {
534                         nstk-- // skip runtime.goexit
535                 }
536                 if nstk > 0 && gp.goid == 1 {
537                         nstk-- // skip runtime.main
538                 }
539                 id := trace.stackTab.put(buf.stk[:nstk])
540                 buf.varint(uint64(id))
541         }
542         evSize := buf.pos - startPos
543         if evSize > maxSize {
544                 throw("invalid length of trace event")
545         }
546         if lenp != nil {
547                 // Fill in actual length.
548                 *lenp = byte(evSize - 2)
549         }
550         traceReleaseBuffer(pid)
551 }
552
553 // traceAcquireBuffer returns trace buffer to use and, if necessary, locks it.
554 func traceAcquireBuffer() (mp *m, pid int32, bufp *traceBufPtr) {
555         mp = acquirem()
556         if p := mp.p.ptr(); p != nil {
557                 return mp, p.id, &p.tracebuf
558         }
559         lock(&trace.bufLock)
560         return mp, traceGlobProc, &trace.buf
561 }
562
563 // traceReleaseBuffer releases a buffer previously acquired with traceAcquireBuffer.
564 func traceReleaseBuffer(pid int32) {
565         if pid == traceGlobProc {
566                 unlock(&trace.bufLock)
567         }
568         releasem(getg().m)
569 }
570
571 // traceFlush puts buf onto stack of full buffers and returns an empty buffer.
572 func traceFlush(buf traceBufPtr) traceBufPtr {
573         owner := trace.lockOwner
574         dolock := owner == nil || owner != getg().m.curg
575         if dolock {
576                 lock(&trace.lock)
577         }
578         if buf != 0 {
579                 traceFullQueue(buf)
580         }
581         if trace.empty != 0 {
582                 buf = trace.empty
583                 trace.empty = buf.ptr().link
584         } else {
585                 buf = traceBufPtr(sysAlloc(unsafe.Sizeof(traceBuf{}), &memstats.other_sys))
586                 if buf == 0 {
587                         throw("trace: out of memory")
588                 }
589         }
590         bufp := buf.ptr()
591         bufp.link.set(nil)
592         bufp.pos = 0
593         bufp.lastTicks = 0
594         if dolock {
595                 unlock(&trace.lock)
596         }
597         return buf
598 }
599
600 // traceAppend appends v to buf in little-endian-base-128 encoding.
601 func traceAppend(buf []byte, v uint64) []byte {
602         for ; v >= 0x80; v >>= 7 {
603                 buf = append(buf, 0x80|byte(v))
604         }
605         buf = append(buf, byte(v))
606         return buf
607 }
608
609 // varint appends v to buf in little-endian-base-128 encoding.
610 func (buf *traceBuf) varint(v uint64) {
611         pos := buf.pos
612         for ; v >= 0x80; v >>= 7 {
613                 buf.arr[pos] = 0x80 | byte(v)
614                 pos++
615         }
616         buf.arr[pos] = byte(v)
617         pos++
618         buf.pos = pos
619 }
620
621 // byte appends v to buf.
622 func (buf *traceBuf) byte(v byte) {
623         buf.arr[buf.pos] = v
624         buf.pos++
625 }
626
627 // traceStackTable maps stack traces (arrays of PC's) to unique uint32 ids.
628 // It is lock-free for reading.
629 type traceStackTable struct {
630         lock mutex
631         seq  uint32
632         mem  traceAlloc
633         tab  [1 << 13]traceStackPtr
634 }
635
636 // traceStack is a single stack in traceStackTable.
637 type traceStack struct {
638         link traceStackPtr
639         hash uintptr
640         id   uint32
641         n    int
642         stk  [0]uintptr // real type [n]uintptr
643 }
644
645 type traceStackPtr uintptr
646
647 func (tp traceStackPtr) ptr() *traceStack { return (*traceStack)(unsafe.Pointer(tp)) }
648
649 // stack returns slice of PCs.
650 func (ts *traceStack) stack() []uintptr {
651         return (*[traceStackSize]uintptr)(unsafe.Pointer(&ts.stk))[:ts.n]
652 }
653
654 // put returns a unique id for the stack trace pcs and caches it in the table,
655 // if it sees the trace for the first time.
656 func (tab *traceStackTable) put(pcs []uintptr) uint32 {
657         if len(pcs) == 0 {
658                 return 0
659         }
660         hash := memhash(unsafe.Pointer(&pcs[0]), 0, uintptr(len(pcs))*unsafe.Sizeof(pcs[0]))
661         // First, search the hashtable w/o the mutex.
662         if id := tab.find(pcs, hash); id != 0 {
663                 return id
664         }
665         // Now, double check under the mutex.
666         lock(&tab.lock)
667         if id := tab.find(pcs, hash); id != 0 {
668                 unlock(&tab.lock)
669                 return id
670         }
671         // Create new record.
672         tab.seq++
673         stk := tab.newStack(len(pcs))
674         stk.hash = hash
675         stk.id = tab.seq
676         stk.n = len(pcs)
677         stkpc := stk.stack()
678         for i, pc := range pcs {
679                 stkpc[i] = pc
680         }
681         part := int(hash % uintptr(len(tab.tab)))
682         stk.link = tab.tab[part]
683         atomicstorep(unsafe.Pointer(&tab.tab[part]), unsafe.Pointer(stk))
684         unlock(&tab.lock)
685         return stk.id
686 }
687
688 // find checks if the stack trace pcs is already present in the table.
689 func (tab *traceStackTable) find(pcs []uintptr, hash uintptr) uint32 {
690         part := int(hash % uintptr(len(tab.tab)))
691 Search:
692         for stk := tab.tab[part].ptr(); stk != nil; stk = stk.link.ptr() {
693                 if stk.hash == hash && stk.n == len(pcs) {
694                         for i, stkpc := range stk.stack() {
695                                 if stkpc != pcs[i] {
696                                         continue Search
697                                 }
698                         }
699                         return stk.id
700                 }
701         }
702         return 0
703 }
704
705 // newStack allocates a new stack of size n.
706 func (tab *traceStackTable) newStack(n int) *traceStack {
707         return (*traceStack)(tab.mem.alloc(unsafe.Sizeof(traceStack{}) + uintptr(n)*ptrSize))
708 }
709
710 // dump writes all previously cached stacks to trace buffers,
711 // releases all memory and resets state.
712 func (tab *traceStackTable) dump() {
713         var tmp [(2 + traceStackSize) * traceBytesPerNumber]byte
714         buf := traceFlush(0).ptr()
715         for _, stk := range tab.tab {
716                 stk := stk.ptr()
717                 for ; stk != nil; stk = stk.link.ptr() {
718                         maxSize := 1 + (3+stk.n)*traceBytesPerNumber
719                         if len(buf.arr)-buf.pos < maxSize {
720                                 buf = traceFlush(traceBufPtrOf(buf)).ptr()
721                         }
722                         // Form the event in the temp buffer, we need to know the actual length.
723                         tmpbuf := tmp[:0]
724                         tmpbuf = traceAppend(tmpbuf, uint64(stk.id))
725                         tmpbuf = traceAppend(tmpbuf, uint64(stk.n))
726                         for _, pc := range stk.stack() {
727                                 tmpbuf = traceAppend(tmpbuf, uint64(pc))
728                         }
729                         // Now copy to the buffer.
730                         buf.byte(traceEvStack | 3<<traceArgCountShift)
731                         buf.varint(uint64(len(tmpbuf)))
732                         buf.pos += copy(buf.arr[buf.pos:], tmpbuf)
733                 }
734         }
735
736         lock(&trace.lock)
737         traceFullQueue(traceBufPtrOf(buf))
738         unlock(&trace.lock)
739
740         tab.mem.drop()
741         *tab = traceStackTable{}
742 }
743
744 // traceAlloc is a non-thread-safe region allocator.
745 // It holds a linked list of traceAllocBlock.
746 type traceAlloc struct {
747         head *traceAllocBlock
748         off  uintptr
749 }
750
751 // traceAllocBlock is a block in traceAlloc.
752 type traceAllocBlock struct {
753         next *traceAllocBlock
754         data [64<<10 - ptrSize]byte
755 }
756
757 // alloc allocates n-byte block.
758 func (a *traceAlloc) alloc(n uintptr) unsafe.Pointer {
759         n = round(n, ptrSize)
760         if a.head == nil || a.off+n > uintptr(len(a.head.data)) {
761                 if n > uintptr(len(a.head.data)) {
762                         throw("trace: alloc too large")
763                 }
764                 block := (*traceAllocBlock)(sysAlloc(unsafe.Sizeof(traceAllocBlock{}), &memstats.other_sys))
765                 if block == nil {
766                         throw("trace: out of memory")
767                 }
768                 block.next = a.head
769                 a.head = block
770                 a.off = 0
771         }
772         p := &a.head.data[a.off]
773         a.off += n
774         return unsafe.Pointer(p)
775 }
776
777 // drop frees all previously allocated memory and resets the allocator.
778 func (a *traceAlloc) drop() {
779         for a.head != nil {
780                 block := a.head
781                 a.head = block.next
782                 sysFree(unsafe.Pointer(block), unsafe.Sizeof(traceAllocBlock{}), &memstats.other_sys)
783         }
784 }
785
786 // The following functions write specific events to trace.
787
788 func traceGomaxprocs(procs int32) {
789         traceEvent(traceEvGomaxprocs, 1, uint64(procs))
790 }
791
792 func traceProcStart() {
793         traceEvent(traceEvProcStart, -1, uint64(getg().m.id))
794 }
795
796 func traceProcStop(pp *p) {
797         // Sysmon and stopTheWorld can stop Ps blocked in syscalls,
798         // to handle this we temporary employ the P.
799         mp := acquirem()
800         oldp := mp.p
801         mp.p.set(pp)
802         traceEvent(traceEvProcStop, -1)
803         mp.p = oldp
804         releasem(mp)
805 }
806
807 func traceGCStart() {
808         traceEvent(traceEvGCStart, 3)
809 }
810
811 func traceGCDone() {
812         traceEvent(traceEvGCDone, -1)
813 }
814
815 func traceGCScanStart() {
816         traceEvent(traceEvGCScanStart, -1)
817 }
818
819 func traceGCScanDone() {
820         traceEvent(traceEvGCScanDone, -1)
821 }
822
823 func traceGCSweepStart() {
824         traceEvent(traceEvGCSweepStart, 1)
825 }
826
827 func traceGCSweepDone() {
828         traceEvent(traceEvGCSweepDone, -1)
829 }
830
831 func traceGoCreate(newg *g, pc uintptr) {
832         traceEvent(traceEvGoCreate, 2, uint64(newg.goid), uint64(pc))
833 }
834
835 func traceGoStart() {
836         traceEvent(traceEvGoStart, -1, uint64(getg().m.curg.goid))
837 }
838
839 func traceGoEnd() {
840         traceEvent(traceEvGoEnd, -1)
841 }
842
843 func traceGoSched() {
844         traceEvent(traceEvGoSched, 1)
845 }
846
847 func traceGoPreempt() {
848         traceEvent(traceEvGoPreempt, 1)
849 }
850
851 func traceGoPark(traceEv byte, skip int, gp *g) {
852         if traceEv&traceFutileWakeup != 0 {
853                 traceEvent(traceEvFutileWakeup, -1)
854         }
855         traceEvent(traceEv & ^traceFutileWakeup, skip)
856 }
857
858 func traceGoUnpark(gp *g, skip int) {
859         traceEvent(traceEvGoUnblock, skip, uint64(gp.goid))
860 }
861
862 func traceGoSysCall() {
863         traceEvent(traceEvGoSysCall, 1)
864 }
865
866 func traceGoSysExit(seq uint64, ts int64) {
867         if int64(seq)-int64(trace.seqStart) < 0 {
868                 // The timestamp was obtained during a previous tracing session, ignore.
869                 return
870         }
871         traceEvent(traceEvGoSysExit, -1, uint64(getg().m.curg.goid), seq, uint64(ts)/traceTickDiv)
872 }
873
874 func traceGoSysBlock(pp *p) {
875         // Sysmon and stopTheWorld can declare syscalls running on remote Ps as blocked,
876         // to handle this we temporary employ the P.
877         mp := acquirem()
878         oldp := mp.p
879         mp.p.set(pp)
880         traceEvent(traceEvGoSysBlock, -1)
881         mp.p = oldp
882         releasem(mp)
883 }
884
885 func traceHeapAlloc() {
886         traceEvent(traceEvHeapAlloc, -1, memstats.heap_live)
887 }
888
889 func traceNextGC() {
890         traceEvent(traceEvNextGC, -1, memstats.next_gc)
891 }