Source file
src/runtime/trace.go
1
2
3
4
5
6
7
8
9
10
11
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
25 const (
26 traceEvNone = 0
27 traceEvBatch = 1
28 traceEvFrequency = 2
29 traceEvStack = 3
30 traceEvGomaxprocs = 4
31 traceEvProcStart = 5
32 traceEvProcStop = 6
33 traceEvGCStart = 7
34 traceEvGCDone = 8
35 traceEvSTWStart = 9
36 traceEvSTWDone = 10
37 traceEvGCSweepStart = 11
38 traceEvGCSweepDone = 12
39 traceEvGoCreate = 13
40 traceEvGoStart = 14
41 traceEvGoEnd = 15
42 traceEvGoStop = 16
43 traceEvGoSched = 17
44 traceEvGoPreempt = 18
45 traceEvGoSleep = 19
46 traceEvGoBlock = 20
47 traceEvGoUnblock = 21
48 traceEvGoBlockSend = 22
49 traceEvGoBlockRecv = 23
50 traceEvGoBlockSelect = 24
51 traceEvGoBlockSync = 25
52 traceEvGoBlockCond = 26
53 traceEvGoBlockNet = 27
54 traceEvGoSysCall = 28
55 traceEvGoSysExit = 29
56 traceEvGoSysBlock = 30
57 traceEvGoWaiting = 31
58 traceEvGoInSyscall = 32
59 traceEvHeapAlloc = 33
60 traceEvHeapGoal = 34
61 traceEvTimerGoroutine = 35
62 traceEvFutileWakeup = 36
63 traceEvString = 37
64 traceEvGoStartLocal = 38
65 traceEvGoUnblockLocal = 39
66 traceEvGoSysExitLocal = 40
67 traceEvGoStartLabel = 41
68 traceEvGoBlockGC = 42
69 traceEvGCMarkAssistStart = 43
70 traceEvGCMarkAssistDone = 44
71 traceEvUserTaskCreate = 45
72 traceEvUserTaskEnd = 46
73 traceEvUserRegion = 47
74 traceEvUserLog = 48
75 traceEvCPUSample = 49
76 traceEvCount = 50
77
78
79
80 )
81
82
83
84
85
86
87
88
89 type traceBlockReason uint8
90
91
92
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
113
114
115
116
117
118
119 traceTimeDiv = 16 + 48*(goarch.Is386|goarch.IsAmd64)
120
121
122
123 traceStackSize = 128
124
125 traceGlobProc = -1
126
127 traceBytesPerNumber = 10
128
129 traceArgCountShift = 6
130 )
131
132
133 var trace struct {
134
135
136 lock mutex
137 enabled bool
138 shutdown bool
139 headerWritten bool
140 footerWritten bool
141 shutdownSema uint32
142 seqStart uint64
143 startTicks int64
144 endTicks int64
145 startNanotime int64
146 endNanotime int64
147 startTime traceTime
148 endTime traceTime
149 seqGC uint64
150 reading traceBufPtr
151 empty traceBufPtr
152 fullHead traceBufPtr
153 fullTail traceBufPtr
154 stackTab traceStackTable
155
156
157
158
159
160
161
162
163
164
165 cpuLogRead *profBuf
166
167
168
169 cpuLogBuf traceBufPtr
170
171 reader atomic.Pointer[g]
172
173 signalLock atomic.Uint32
174 cpuLogWrite *profBuf
175
176
177
178
179
180
181
182 stringsLock mutex
183 strings map[string]uint64
184 stringSeq uint64
185
186
187 markWorkerLabels [len(gcMarkWorkerModeStrings)]uint64
188
189 bufLock mutex
190 buf traceBufPtr
191 }
192
193
194 type gTraceState struct {
195 sysExitTime traceTime
196 tracedSyscallEnter bool
197 seq uint64
198 lastP puintptr
199 }
200
201
202 type mTraceState struct {
203 startingTrace bool
204 tracedSTWStart bool
205 }
206
207
208 type pTraceState struct {
209 buf traceBufPtr
210
211
212
213
214 inSweep bool
215
216
217
218 swept, reclaimed uintptr
219 }
220
221
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
230 type traceBufHeader struct {
231 link traceBufPtr
232 lastTime traceTime
233 pos int
234 stk [traceStackSize]uintptr
235 }
236
237
238 type traceBuf struct {
239 _ sys.NotInHeap
240 traceBufHeader
241 arr [64<<10 - unsafe.Sizeof(traceBufHeader{})]byte
242 }
243
244
245
246
247
248
249
250
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
260
261
262 func traceEnabled() bool {
263 return trace.enabled
264 }
265
266
267
268
269 func traceShuttingDown() bool {
270 return trace.shutdown
271 }
272
273
274
275
276
277
278 func StartTrace() error {
279
280
281
282
283
284 stopTheWorldGC(stwStartTrace)
285
286
287 lock(&sched.sysmonlock)
288
289
290
291
292
293
294 lock(&trace.bufLock)
295
296 if trace.enabled || trace.shutdown {
297 unlock(&trace.bufLock)
298 unlock(&sched.sysmonlock)
299 startTheWorldGC()
300 return errorString("tracing is already enabled")
301 }
302
303
304
305
306
307
308
309
310 mp := getg().m
311 mp.trace.startingTrace = true
312
313
314 stkBuf := make([]uintptr, traceStackSize)
315 stackID := traceStackID(mp, stkBuf, 2)
316
317 profBuf := newProfBuf(2, profBufWordCount, profBufTagCount)
318 trace.cpuLogRead = profBuf
319
320
321
322
323
324
325
326
327 atomicstorep(unsafe.Pointer(&trace.cpuLogWrite), unsafe.Pointer(profBuf))
328
329
330 forEachGRace(func(gp *g) {
331 status := readgstatus(gp)
332 if status != _Gdead {
333 gp.trace.seq = 0
334 gp.trace.lastP = getg().m.p
335
336 id := trace.stackTab.put([]uintptr{logicalStackSentinel, startPCforTrace(gp.startpc) + sys.PCQuantum})
337 traceEvent(traceEvGoCreate, -1, gp.goid, uint64(id), stackID)
338 }
339 if status == _Gwaiting {
340
341 gp.trace.seq++
342 traceEvent(traceEvGoWaiting, -1, gp.goid)
343 }
344 if status == _Gsyscall {
345 gp.trace.seq++
346 gp.trace.tracedSyscallEnter = true
347 traceEvent(traceEvGoInSyscall, -1, gp.goid)
348 } else if status == _Gdead && gp.m != nil && gp.m.isextra {
349
350
351
352 gp.trace.seq = 0
353 gp.trace.lastP = getg().m.p
354
355 id := trace.stackTab.put([]uintptr{logicalStackSentinel, startPCforTrace(0) + sys.PCQuantum})
356 traceEvent(traceEvGoCreate, -1, gp.goid, uint64(id), stackID)
357 gp.trace.seq++
358 gp.trace.tracedSyscallEnter = true
359 traceEvent(traceEvGoInSyscall, -1, gp.goid)
360 } else {
361
362
363
364
365
366
367 gp.trace.tracedSyscallEnter = false
368 }
369 })
370 traceProcStart()
371 traceGoStart()
372
373
374
375
376 trace.startTime = traceClockNow()
377 trace.startTicks = cputicks()
378 trace.startNanotime = nanotime()
379 trace.headerWritten = false
380 trace.footerWritten = false
381
382
383
384
385 trace.stringSeq = 0
386 trace.strings = make(map[string]uint64)
387
388 trace.seqGC = 0
389 mp.trace.startingTrace = false
390 trace.enabled = true
391
392
393 _, pid, bufp := traceAcquireBuffer()
394 for i, label := range gcMarkWorkerModeStrings[:] {
395 trace.markWorkerLabels[i], bufp = traceString(bufp, pid, label)
396 }
397 traceReleaseBuffer(mp, pid)
398
399 unlock(&trace.bufLock)
400
401 unlock(&sched.sysmonlock)
402
403
404 traceHeapGoal()
405
406 startTheWorldGC()
407 return nil
408 }
409
410
411
412 func StopTrace() {
413
414
415 stopTheWorldGC(stwStopTrace)
416
417
418 lock(&sched.sysmonlock)
419
420
421 lock(&trace.bufLock)
422
423 if !trace.enabled {
424 unlock(&trace.bufLock)
425 unlock(&sched.sysmonlock)
426 startTheWorldGC()
427 return
428 }
429
430 traceGoSched()
431
432 atomicstorep(unsafe.Pointer(&trace.cpuLogWrite), nil)
433 trace.cpuLogRead.close()
434 traceReadCPU()
435
436
437
438 for _, p := range allp[:cap(allp)] {
439 buf := p.trace.buf
440 if buf != 0 {
441 traceFullQueue(buf)
442 p.trace.buf = 0
443 }
444 }
445 if trace.buf != 0 {
446 buf := trace.buf
447 trace.buf = 0
448 if buf.ptr().pos != 0 {
449 traceFullQueue(buf)
450 }
451 }
452 if trace.cpuLogBuf != 0 {
453 buf := trace.cpuLogBuf
454 trace.cpuLogBuf = 0
455 if buf.ptr().pos != 0 {
456 traceFullQueue(buf)
457 }
458 }
459
460
461
462
463
464
465 for {
466 trace.endTime = traceClockNow()
467 trace.endTicks = cputicks()
468 trace.endNanotime = nanotime()
469
470 if trace.endNanotime != trace.startNanotime || faketime != 0 {
471 break
472 }
473 osyield()
474 }
475
476 trace.enabled = false
477 trace.shutdown = true
478 unlock(&trace.bufLock)
479
480 unlock(&sched.sysmonlock)
481
482 startTheWorldGC()
483
484
485
486 semacquire(&trace.shutdownSema)
487 if raceenabled {
488 raceacquire(unsafe.Pointer(&trace.shutdownSema))
489 }
490
491 systemstack(func() {
492
493 lock(&trace.lock)
494 for _, p := range allp[:cap(allp)] {
495 if p.trace.buf != 0 {
496 throw("trace: non-empty trace buffer in proc")
497 }
498 }
499 if trace.buf != 0 {
500 throw("trace: non-empty global trace buffer")
501 }
502 if trace.fullHead != 0 || trace.fullTail != 0 {
503 throw("trace: non-empty full trace buffer")
504 }
505 if trace.reading != 0 || trace.reader.Load() != nil {
506 throw("trace: reading after shutdown")
507 }
508 for trace.empty != 0 {
509 buf := trace.empty
510 trace.empty = buf.ptr().link
511 sysFree(unsafe.Pointer(buf), unsafe.Sizeof(*buf.ptr()), &memstats.other_sys)
512 }
513 trace.strings = nil
514 trace.shutdown = false
515 trace.cpuLogRead = nil
516 unlock(&trace.lock)
517 })
518 }
519
520
521
522
523
524
525 func ReadTrace() []byte {
526 top:
527 var buf []byte
528 var park bool
529 systemstack(func() {
530 buf, park = readTrace0()
531 })
532 if park {
533 gopark(func(gp *g, _ unsafe.Pointer) bool {
534 if !trace.reader.CompareAndSwapNoWB(nil, gp) {
535
536
537 return false
538 }
539
540 if g2 := traceReader(); gp == g2 {
541
542
543
544 return false
545 } else if g2 != nil {
546 printlock()
547 println("runtime: got trace reader", g2, g2.goid)
548 throw("unexpected trace reader")
549 }
550
551 return true
552 }, nil, waitReasonTraceReaderBlocked, traceBlockSystemGoroutine, 2)
553 goto top
554 }
555
556 return buf
557 }
558
559
560
561
562
563 func readTrace0() (buf []byte, park bool) {
564 if raceenabled {
565
566 if getg().racectx != 0 {
567 throw("expected racectx == 0")
568 }
569 getg().racectx = getg().m.curg.racectx
570
571
572 defer func() { getg().racectx = 0 }()
573 }
574
575
576
577
578
579 if !trace.footerWritten && !trace.shutdown {
580 traceReadCPU()
581 }
582
583
584
585
586 lock(&trace.lock)
587
588 if trace.reader.Load() != nil {
589
590
591
592 unlock(&trace.lock)
593 println("runtime: ReadTrace called from multiple goroutines simultaneously")
594 return nil, false
595 }
596
597 if buf := trace.reading; buf != 0 {
598 buf.ptr().link = trace.empty
599 trace.empty = buf
600 trace.reading = 0
601 }
602
603 if !trace.headerWritten {
604 trace.headerWritten = true
605 unlock(&trace.lock)
606 return []byte("go 1.21 trace\x00\x00\x00"), false
607 }
608
609 if trace.fullHead == 0 && !trace.shutdown {
610
611
612
613 unlock(&trace.lock)
614 return nil, true
615 }
616 newFull:
617 assertLockHeld(&trace.lock)
618
619 if trace.fullHead != 0 {
620 buf := traceFullDequeue()
621 trace.reading = buf
622 unlock(&trace.lock)
623 return buf.ptr().arr[:buf.ptr().pos], false
624 }
625
626
627 if !trace.footerWritten {
628 trace.footerWritten = true
629 freq := (float64(trace.endTicks-trace.startTicks) / traceTimeDiv) / (float64(trace.endNanotime-trace.startNanotime) / 1e9)
630 if freq <= 0 {
631 throw("trace: ReadTrace got invalid frequency")
632 }
633 unlock(&trace.lock)
634
635
636 bufp := traceFlush(0, 0)
637 buf := bufp.ptr()
638 buf.byte(traceEvFrequency | 0<<traceArgCountShift)
639 buf.varint(uint64(freq))
640
641
642
643
644 bufp = trace.stackTab.dump(bufp)
645
646
647 lock(&trace.lock)
648 traceFullQueue(bufp)
649 goto newFull
650 }
651
652 if trace.shutdown {
653 unlock(&trace.lock)
654 if raceenabled {
655
656
657
658 racerelease(unsafe.Pointer(&trace.shutdownSema))
659 }
660
661 semrelease(&trace.shutdownSema)
662 return nil, false
663 }
664
665 unlock(&trace.lock)
666 println("runtime: spurious wakeup of trace reader")
667 return nil, false
668 }
669
670
671
672
673
674
675
676 func traceReader() *g {
677
678 if traceReaderAvailable() == nil {
679 return nil
680 }
681 lock(&trace.lock)
682 gp := traceReaderAvailable()
683 if gp == nil || !trace.reader.CompareAndSwapNoWB(gp, nil) {
684 unlock(&trace.lock)
685 return nil
686 }
687 unlock(&trace.lock)
688 return gp
689 }
690
691
692
693
694 func traceReaderAvailable() *g {
695 if trace.fullHead != 0 || trace.shutdown {
696 return trace.reader.Load()
697 }
698 return nil
699 }
700
701
702
703
704
705
706 func traceProcFree(pp *p) {
707 buf := pp.trace.buf
708 pp.trace.buf = 0
709 if buf == 0 {
710 return
711 }
712 lock(&trace.lock)
713 traceFullQueue(buf)
714 unlock(&trace.lock)
715 }
716
717
718 func traceFullQueue(buf traceBufPtr) {
719 buf.ptr().link = 0
720 if trace.fullHead == 0 {
721 trace.fullHead = buf
722 } else {
723 trace.fullTail.ptr().link = buf
724 }
725 trace.fullTail = buf
726 }
727
728
729 func traceFullDequeue() traceBufPtr {
730 buf := trace.fullHead
731 if buf == 0 {
732 return 0
733 }
734 trace.fullHead = buf.ptr().link
735 if trace.fullHead == 0 {
736 trace.fullTail = 0
737 }
738 buf.ptr().link = 0
739 return buf
740 }
741
742
743
744
745
746
747 func traceEvent(ev byte, skip int, args ...uint64) {
748 mp, pid, bufp := traceAcquireBuffer()
749
750
751
752
753
754
755
756
757
758
759
760 if !trace.enabled && !mp.trace.startingTrace {
761 traceReleaseBuffer(mp, pid)
762 return
763 }
764
765 if skip > 0 {
766 if getg() == mp.curg {
767 skip++
768 }
769 }
770 traceEventLocked(0, mp, pid, bufp, ev, 0, skip, args...)
771 traceReleaseBuffer(mp, pid)
772 }
773
774
775
776
777
778
779
780
781
782
783
784
785
786
787
788
789
790
791 func traceEventLocked(extraBytes int, mp *m, pid int32, bufp *traceBufPtr, ev byte, stackID uint32, skip int, args ...uint64) {
792 buf := bufp.ptr()
793
794 maxSize := 2 + 5*traceBytesPerNumber + extraBytes
795 if buf == nil || len(buf.arr)-buf.pos < maxSize {
796 systemstack(func() {
797 buf = traceFlush(traceBufPtrOf(buf), pid).ptr()
798 })
799 bufp.set(buf)
800 }
801
802 ts := traceClockNow()
803 if ts <= buf.lastTime {
804 ts = buf.lastTime + 1
805 }
806 tsDiff := uint64(ts - buf.lastTime)
807 buf.lastTime = ts
808 narg := byte(len(args))
809 if stackID != 0 || skip >= 0 {
810 narg++
811 }
812
813
814 if narg > 3 {
815 narg = 3
816 }
817 startPos := buf.pos
818 buf.byte(ev | narg<<traceArgCountShift)
819 var lenp *byte
820 if narg == 3 {
821
822 buf.varint(0)
823 lenp = &buf.arr[buf.pos-1]
824 }
825 buf.varint(tsDiff)
826 for _, a := range args {
827 buf.varint(a)
828 }
829 if stackID != 0 {
830 buf.varint(uint64(stackID))
831 } else if skip == 0 {
832 buf.varint(0)
833 } else if skip > 0 {
834 buf.varint(traceStackID(mp, buf.stk[:], skip))
835 }
836 evSize := buf.pos - startPos
837 if evSize > maxSize {
838 throw("invalid length of trace event")
839 }
840 if lenp != nil {
841
842 *lenp = byte(evSize - 2)
843 }
844 }
845
846
847
848
849 func traceCPUSample(gp *g, pp *p, stk []uintptr) {
850 if !trace.enabled {
851
852
853 return
854 }
855
856
857 now := traceClockNow()
858
859
860
861
862 var hdr [2]uint64
863 if pp != nil {
864
865
866 hdr[0] = uint64(pp.id)<<1 | 0b1
867 } else {
868 hdr[0] = 0b10
869 }
870 if gp != nil {
871 hdr[1] = gp.goid
872 }
873
874
875 for !trace.signalLock.CompareAndSwap(0, 1) {
876
877 osyield()
878 }
879
880 if log := (*profBuf)(atomic.Loadp(unsafe.Pointer(&trace.cpuLogWrite))); log != nil {
881
882
883
884 log.write(nil, int64(now), hdr[:], stk)
885 }
886
887 trace.signalLock.Store(0)
888 }
889
890 func traceReadCPU() {
891 bufp := &trace.cpuLogBuf
892
893 for {
894 data, tags, _ := trace.cpuLogRead.read(profBufNonBlocking)
895 if len(data) == 0 {
896 break
897 }
898 for len(data) > 0 {
899 if len(data) < 4 || data[0] > uint64(len(data)) {
900 break
901 }
902 if data[0] < 4 || tags != nil && len(tags) < 1 {
903 break
904 }
905 if len(tags) < 1 {
906 break
907 }
908 timestamp := data[1]
909 ppid := data[2] >> 1
910 if hasP := (data[2] & 0b1) != 0; !hasP {
911 ppid = ^uint64(0)
912 }
913 goid := data[3]
914 stk := data[4:data[0]]
915 empty := len(stk) == 1 && data[2] == 0 && data[3] == 0
916 data = data[data[0]:]
917
918
919
920
921 tags = tags[1:]
922
923 if empty {
924
925
926
927
928
929
930 continue
931 }
932
933 buf := bufp.ptr()
934 if buf == nil {
935 systemstack(func() {
936 *bufp = traceFlush(*bufp, 0)
937 })
938 buf = bufp.ptr()
939 }
940 nstk := 1
941 buf.stk[0] = logicalStackSentinel
942 for ; nstk < len(buf.stk) && nstk-1 < len(stk); nstk++ {
943 buf.stk[nstk] = uintptr(stk[nstk-1])
944 }
945 stackID := trace.stackTab.put(buf.stk[:nstk])
946
947 traceEventLocked(0, nil, 0, bufp, traceEvCPUSample, stackID, 1, uint64(timestamp), ppid, goid)
948 }
949 }
950 }
951
952
953
954
955
956 const logicalStackSentinel = ^uintptr(0)
957
958
959
960
961
962 func traceStackID(mp *m, pcBuf []uintptr, skip int) uint64 {
963 gp := getg()
964 curgp := mp.curg
965 nstk := 1
966 if tracefpunwindoff() || mp.hasCgoOnStack() {
967
968
969
970
971
972
973 pcBuf[0] = logicalStackSentinel
974 if curgp == gp {
975 nstk += callers(skip+1, pcBuf[1:])
976 } else if curgp != nil {
977 nstk += gcallers(curgp, skip, pcBuf[1:])
978 }
979 } else {
980
981 pcBuf[0] = uintptr(skip)
982 if curgp == gp {
983 nstk += fpTracebackPCs(unsafe.Pointer(getfp()), pcBuf[1:])
984 } else if curgp != nil {
985
986
987
988
989
990 pcBuf[1] = curgp.sched.pc
991 nstk += 1 + fpTracebackPCs(unsafe.Pointer(curgp.sched.bp), pcBuf[2:])
992 }
993 }
994 if nstk > 0 {
995 nstk--
996 }
997 if nstk > 0 && curgp.goid == 1 {
998 nstk--
999 }
1000 id := trace.stackTab.put(pcBuf[:nstk])
1001 return uint64(id)
1002 }
1003
1004
1005
1006
1007 func tracefpunwindoff() bool {
1008 return debug.tracefpunwindoff != 0 || (goarch.ArchFamily != goarch.AMD64 && goarch.ArchFamily != goarch.ARM64) || goos.IsPlan9 == 1
1009 }
1010
1011
1012
1013
1014
1015 func fpTracebackPCs(fp unsafe.Pointer, pcBuf []uintptr) (i int) {
1016 for i = 0; i < len(pcBuf) && fp != nil; i++ {
1017
1018 pcBuf[i] = *(*uintptr)(unsafe.Pointer(uintptr(fp) + goarch.PtrSize))
1019
1020 fp = unsafe.Pointer(*(*uintptr)(fp))
1021 }
1022 return i
1023 }
1024
1025
1026 func traceAcquireBuffer() (mp *m, pid int32, bufp *traceBufPtr) {
1027
1028
1029
1030 lockRankMayTraceFlush()
1031
1032 mp = acquirem()
1033 if p := mp.p.ptr(); p != nil {
1034 return mp, p.id, &p.trace.buf
1035 }
1036 lock(&trace.bufLock)
1037 return mp, traceGlobProc, &trace.buf
1038 }
1039
1040
1041 func traceReleaseBuffer(mp *m, pid int32) {
1042 if pid == traceGlobProc {
1043 unlock(&trace.bufLock)
1044 }
1045 releasem(mp)
1046 }
1047
1048
1049
1050 func lockRankMayTraceFlush() {
1051 lockWithRankMayAcquire(&trace.lock, getLockRank(&trace.lock))
1052 }
1053
1054
1055
1056
1057
1058
1059 func traceFlush(buf traceBufPtr, pid int32) traceBufPtr {
1060 lock(&trace.lock)
1061 if buf != 0 {
1062 traceFullQueue(buf)
1063 }
1064 if trace.empty != 0 {
1065 buf = trace.empty
1066 trace.empty = buf.ptr().link
1067 } else {
1068 buf = traceBufPtr(sysAlloc(unsafe.Sizeof(traceBuf{}), &memstats.other_sys))
1069 if buf == 0 {
1070 throw("trace: out of memory")
1071 }
1072 }
1073 bufp := buf.ptr()
1074 bufp.link.set(nil)
1075 bufp.pos = 0
1076
1077
1078 ts := traceClockNow()
1079 if ts <= bufp.lastTime {
1080 ts = bufp.lastTime + 1
1081 }
1082 bufp.lastTime = ts
1083 bufp.byte(traceEvBatch | 1<<traceArgCountShift)
1084 bufp.varint(uint64(pid))
1085 bufp.varint(uint64(ts))
1086
1087 unlock(&trace.lock)
1088 return buf
1089 }
1090
1091
1092 func traceString(bufp *traceBufPtr, pid int32, s string) (uint64, *traceBufPtr) {
1093 if s == "" {
1094 return 0, bufp
1095 }
1096
1097 lock(&trace.stringsLock)
1098 if raceenabled {
1099
1100
1101 raceacquire(unsafe.Pointer(&trace.stringsLock))
1102 }
1103
1104 if id, ok := trace.strings[s]; ok {
1105 if raceenabled {
1106 racerelease(unsafe.Pointer(&trace.stringsLock))
1107 }
1108 unlock(&trace.stringsLock)
1109
1110 return id, bufp
1111 }
1112
1113 trace.stringSeq++
1114 id := trace.stringSeq
1115 trace.strings[s] = id
1116
1117 if raceenabled {
1118 racerelease(unsafe.Pointer(&trace.stringsLock))
1119 }
1120 unlock(&trace.stringsLock)
1121
1122
1123
1124
1125
1126
1127 buf := bufp.ptr()
1128 size := 1 + 2*traceBytesPerNumber + len(s)
1129 if buf == nil || len(buf.arr)-buf.pos < size {
1130 systemstack(func() {
1131 buf = traceFlush(traceBufPtrOf(buf), pid).ptr()
1132 bufp.set(buf)
1133 })
1134 }
1135 buf.byte(traceEvString)
1136 buf.varint(id)
1137
1138
1139
1140 slen := len(s)
1141 if room := len(buf.arr) - buf.pos; room < slen+traceBytesPerNumber {
1142 slen = room
1143 }
1144
1145 buf.varint(uint64(slen))
1146 buf.pos += copy(buf.arr[buf.pos:], s[:slen])
1147
1148 bufp.set(buf)
1149 return id, bufp
1150 }
1151
1152
1153 func (buf *traceBuf) varint(v uint64) {
1154 pos := buf.pos
1155 for ; v >= 0x80; v >>= 7 {
1156 buf.arr[pos] = 0x80 | byte(v)
1157 pos++
1158 }
1159 buf.arr[pos] = byte(v)
1160 pos++
1161 buf.pos = pos
1162 }
1163
1164
1165
1166
1167
1168 func (buf *traceBuf) varintAt(pos int, v uint64) {
1169 for i := 0; i < traceBytesPerNumber; i++ {
1170 if i < traceBytesPerNumber-1 {
1171 buf.arr[pos] = 0x80 | byte(v)
1172 } else {
1173 buf.arr[pos] = byte(v)
1174 }
1175 v >>= 7
1176 pos++
1177 }
1178 }
1179
1180
1181 func (buf *traceBuf) byte(v byte) {
1182 buf.arr[buf.pos] = v
1183 buf.pos++
1184 }
1185
1186
1187
1188 type traceStackTable struct {
1189 lock mutex
1190 seq uint32
1191 mem traceAlloc
1192 tab [1 << 13]traceStackPtr
1193 }
1194
1195
1196 type traceStack struct {
1197 link traceStackPtr
1198 hash uintptr
1199 id uint32
1200 n int
1201 stk [0]uintptr
1202 }
1203
1204 type traceStackPtr uintptr
1205
1206 func (tp traceStackPtr) ptr() *traceStack { return (*traceStack)(unsafe.Pointer(tp)) }
1207
1208
1209 func (ts *traceStack) stack() []uintptr {
1210 return (*[traceStackSize]uintptr)(unsafe.Pointer(&ts.stk))[:ts.n]
1211 }
1212
1213
1214
1215 func (tab *traceStackTable) put(pcs []uintptr) uint32 {
1216 if len(pcs) == 0 {
1217 return 0
1218 }
1219 hash := memhash(unsafe.Pointer(&pcs[0]), 0, uintptr(len(pcs))*unsafe.Sizeof(pcs[0]))
1220
1221 if id := tab.find(pcs, hash); id != 0 {
1222 return id
1223 }
1224
1225
1226 var id uint32
1227 systemstack(func() {
1228 lock(&tab.lock)
1229 if id = tab.find(pcs, hash); id != 0 {
1230 unlock(&tab.lock)
1231 return
1232 }
1233
1234 tab.seq++
1235 stk := tab.newStack(len(pcs))
1236 stk.hash = hash
1237 stk.id = tab.seq
1238 id = stk.id
1239 stk.n = len(pcs)
1240 stkpc := stk.stack()
1241 copy(stkpc, pcs)
1242 part := int(hash % uintptr(len(tab.tab)))
1243 stk.link = tab.tab[part]
1244 atomicstorep(unsafe.Pointer(&tab.tab[part]), unsafe.Pointer(stk))
1245 unlock(&tab.lock)
1246 })
1247 return id
1248 }
1249
1250
1251 func (tab *traceStackTable) find(pcs []uintptr, hash uintptr) uint32 {
1252 part := int(hash % uintptr(len(tab.tab)))
1253 Search:
1254 for stk := tab.tab[part].ptr(); stk != nil; stk = stk.link.ptr() {
1255 if stk.hash == hash && stk.n == len(pcs) {
1256 for i, stkpc := range stk.stack() {
1257 if stkpc != pcs[i] {
1258 continue Search
1259 }
1260 }
1261 return stk.id
1262 }
1263 }
1264 return 0
1265 }
1266
1267
1268 func (tab *traceStackTable) newStack(n int) *traceStack {
1269 return (*traceStack)(tab.mem.alloc(unsafe.Sizeof(traceStack{}) + uintptr(n)*goarch.PtrSize))
1270 }
1271
1272
1273
1274 func traceFrames(bufp traceBufPtr, pcs []uintptr) ([]traceFrame, traceBufPtr) {
1275 frames := make([]traceFrame, 0, len(pcs))
1276 ci := CallersFrames(pcs)
1277 for {
1278 var frame traceFrame
1279 f, more := ci.Next()
1280 frame, bufp = traceFrameForPC(bufp, 0, f)
1281 frames = append(frames, frame)
1282 if !more {
1283 return frames, bufp
1284 }
1285 }
1286 }
1287
1288
1289
1290
1291
1292
1293
1294 func (tab *traceStackTable) dump(bufp traceBufPtr) traceBufPtr {
1295 for i := range tab.tab {
1296 stk := tab.tab[i].ptr()
1297 for ; stk != nil; stk = stk.link.ptr() {
1298 var frames []traceFrame
1299 frames, bufp = traceFrames(bufp, fpunwindExpand(stk.stack()))
1300
1301
1302
1303
1304 maxSize := 1 + traceBytesPerNumber + (2+4*len(frames))*traceBytesPerNumber
1305
1306 if buf := bufp.ptr(); len(buf.arr)-buf.pos < maxSize {
1307 bufp = traceFlush(bufp, 0)
1308 }
1309
1310
1311 buf := bufp.ptr()
1312 buf.byte(traceEvStack | 3<<traceArgCountShift)
1313 lenPos := buf.pos
1314 buf.pos += traceBytesPerNumber
1315
1316
1317 recPos := buf.pos
1318 buf.varint(uint64(stk.id))
1319 buf.varint(uint64(len(frames)))
1320 for _, frame := range frames {
1321 buf.varint(uint64(frame.PC))
1322 buf.varint(frame.funcID)
1323 buf.varint(frame.fileID)
1324 buf.varint(frame.line)
1325 }
1326
1327
1328 buf.varintAt(lenPos, uint64(buf.pos-recPos))
1329 }
1330 }
1331
1332 tab.mem.drop()
1333 *tab = traceStackTable{}
1334 lockInit(&((*tab).lock), lockRankTraceStackTab)
1335
1336 return bufp
1337 }
1338
1339
1340
1341
1342
1343
1344 func fpunwindExpand(pcBuf []uintptr) []uintptr {
1345 if len(pcBuf) > 0 && pcBuf[0] == logicalStackSentinel {
1346
1347
1348 return pcBuf[1:]
1349 }
1350
1351 var (
1352 cache pcvalueCache
1353 lastFuncID = abi.FuncIDNormal
1354 newPCBuf = make([]uintptr, 0, traceStackSize)
1355 skip = pcBuf[0]
1356
1357
1358 skipOrAdd = func(retPC uintptr) bool {
1359 if skip > 0 {
1360 skip--
1361 } else {
1362 newPCBuf = append(newPCBuf, retPC)
1363 }
1364 return len(newPCBuf) < cap(newPCBuf)
1365 }
1366 )
1367
1368 outer:
1369 for _, retPC := range pcBuf[1:] {
1370 callPC := retPC - 1
1371 fi := findfunc(callPC)
1372 if !fi.valid() {
1373
1374
1375 if more := skipOrAdd(retPC); !more {
1376 break outer
1377 }
1378 continue
1379 }
1380
1381 u, uf := newInlineUnwinder(fi, callPC, &cache)
1382 for ; uf.valid(); uf = u.next(uf) {
1383 sf := u.srcFunc(uf)
1384 if sf.funcID == abi.FuncIDWrapper && elideWrapperCalling(lastFuncID) {
1385
1386 } else if more := skipOrAdd(uf.pc + 1); !more {
1387 break outer
1388 }
1389 lastFuncID = sf.funcID
1390 }
1391 }
1392 return newPCBuf
1393 }
1394
1395 type traceFrame struct {
1396 PC uintptr
1397 funcID uint64
1398 fileID uint64
1399 line uint64
1400 }
1401
1402
1403
1404 func traceFrameForPC(buf traceBufPtr, pid int32, f Frame) (traceFrame, traceBufPtr) {
1405 bufp := &buf
1406 var frame traceFrame
1407 frame.PC = f.PC
1408
1409 fn := f.Function
1410 const maxLen = 1 << 10
1411 if len(fn) > maxLen {
1412 fn = fn[len(fn)-maxLen:]
1413 }
1414 frame.funcID, bufp = traceString(bufp, pid, fn)
1415 frame.line = uint64(f.Line)
1416 file := f.File
1417 if len(file) > maxLen {
1418 file = file[len(file)-maxLen:]
1419 }
1420 frame.fileID, bufp = traceString(bufp, pid, file)
1421 return frame, (*bufp)
1422 }
1423
1424
1425
1426 type traceAlloc struct {
1427 head traceAllocBlockPtr
1428 off uintptr
1429 }
1430
1431
1432
1433
1434
1435
1436 type traceAllocBlock struct {
1437 _ sys.NotInHeap
1438 next traceAllocBlockPtr
1439 data [64<<10 - goarch.PtrSize]byte
1440 }
1441
1442
1443 type traceAllocBlockPtr uintptr
1444
1445 func (p traceAllocBlockPtr) ptr() *traceAllocBlock { return (*traceAllocBlock)(unsafe.Pointer(p)) }
1446 func (p *traceAllocBlockPtr) set(x *traceAllocBlock) { *p = traceAllocBlockPtr(unsafe.Pointer(x)) }
1447
1448
1449 func (a *traceAlloc) alloc(n uintptr) unsafe.Pointer {
1450 n = alignUp(n, goarch.PtrSize)
1451 if a.head == 0 || a.off+n > uintptr(len(a.head.ptr().data)) {
1452 if n > uintptr(len(a.head.ptr().data)) {
1453 throw("trace: alloc too large")
1454 }
1455 block := (*traceAllocBlock)(sysAlloc(unsafe.Sizeof(traceAllocBlock{}), &memstats.other_sys))
1456 if block == nil {
1457 throw("trace: out of memory")
1458 }
1459 block.next.set(a.head.ptr())
1460 a.head.set(block)
1461 a.off = 0
1462 }
1463 p := &a.head.ptr().data[a.off]
1464 a.off += n
1465 return unsafe.Pointer(p)
1466 }
1467
1468
1469 func (a *traceAlloc) drop() {
1470 for a.head != 0 {
1471 block := a.head.ptr()
1472 a.head.set(block.next.ptr())
1473 sysFree(unsafe.Pointer(block), unsafe.Sizeof(traceAllocBlock{}), &memstats.other_sys)
1474 }
1475 }
1476
1477
1478
1479 func traceGomaxprocs(procs int32) {
1480 traceEvent(traceEvGomaxprocs, 1, uint64(procs))
1481 }
1482
1483 func traceProcStart() {
1484 traceEvent(traceEvProcStart, -1, uint64(getg().m.id))
1485 }
1486
1487 func traceProcStop(pp *p) {
1488
1489
1490 mp := acquirem()
1491 oldp := mp.p
1492 mp.p.set(pp)
1493 traceEvent(traceEvProcStop, -1)
1494 mp.p = oldp
1495 releasem(mp)
1496 }
1497
1498 func traceGCStart() {
1499 traceEvent(traceEvGCStart, 3, trace.seqGC)
1500 trace.seqGC++
1501 }
1502
1503 func traceGCDone() {
1504 traceEvent(traceEvGCDone, -1)
1505 }
1506
1507 func traceSTWStart(reason stwReason) {
1508
1509
1510 if reason == stwStartTrace || reason == stwStopTrace {
1511 return
1512 }
1513 getg().m.trace.tracedSTWStart = true
1514 traceEvent(traceEvSTWStart, -1, uint64(reason))
1515 }
1516
1517 func traceSTWDone() {
1518 mp := getg().m
1519 if !mp.trace.tracedSTWStart {
1520 return
1521 }
1522 mp.trace.tracedSTWStart = false
1523 traceEvent(traceEvSTWDone, -1)
1524 }
1525
1526
1527
1528
1529
1530
1531 func traceGCSweepStart() {
1532
1533
1534 pp := getg().m.p.ptr()
1535 if pp.trace.inSweep {
1536 throw("double traceGCSweepStart")
1537 }
1538 pp.trace.inSweep, pp.trace.swept, pp.trace.reclaimed = true, 0, 0
1539 }
1540
1541
1542
1543
1544
1545 func traceGCSweepSpan(bytesSwept uintptr) {
1546 pp := getg().m.p.ptr()
1547 if pp.trace.inSweep {
1548 if pp.trace.swept == 0 {
1549 traceEvent(traceEvGCSweepStart, 1)
1550 }
1551 pp.trace.swept += bytesSwept
1552 }
1553 }
1554
1555 func traceGCSweepDone() {
1556 pp := getg().m.p.ptr()
1557 if !pp.trace.inSweep {
1558 throw("missing traceGCSweepStart")
1559 }
1560 if pp.trace.swept != 0 {
1561 traceEvent(traceEvGCSweepDone, -1, uint64(pp.trace.swept), uint64(pp.trace.reclaimed))
1562 }
1563 pp.trace.inSweep = false
1564 }
1565
1566 func traceGCMarkAssistStart() {
1567 traceEvent(traceEvGCMarkAssistStart, 1)
1568 }
1569
1570 func traceGCMarkAssistDone() {
1571 traceEvent(traceEvGCMarkAssistDone, -1)
1572 }
1573
1574 func traceGoCreate(newg *g, pc uintptr) {
1575 newg.trace.seq = 0
1576 newg.trace.lastP = getg().m.p
1577
1578 id := trace.stackTab.put([]uintptr{logicalStackSentinel, startPCforTrace(pc) + sys.PCQuantum})
1579 traceEvent(traceEvGoCreate, 2, newg.goid, uint64(id))
1580 }
1581
1582 func traceGoStart() {
1583 gp := getg().m.curg
1584 pp := gp.m.p
1585 gp.trace.seq++
1586 if pp.ptr().gcMarkWorkerMode != gcMarkWorkerNotWorker {
1587 traceEvent(traceEvGoStartLabel, -1, gp.goid, gp.trace.seq, trace.markWorkerLabels[pp.ptr().gcMarkWorkerMode])
1588 } else if gp.trace.lastP == pp {
1589 traceEvent(traceEvGoStartLocal, -1, gp.goid)
1590 } else {
1591 gp.trace.lastP = pp
1592 traceEvent(traceEvGoStart, -1, gp.goid, gp.trace.seq)
1593 }
1594 }
1595
1596 func traceGoEnd() {
1597 traceEvent(traceEvGoEnd, -1)
1598 }
1599
1600 func traceGoSched() {
1601 gp := getg()
1602 gp.trace.lastP = gp.m.p
1603 traceEvent(traceEvGoSched, 1)
1604 }
1605
1606 func traceGoPreempt() {
1607 gp := getg()
1608 gp.trace.lastP = gp.m.p
1609 traceEvent(traceEvGoPreempt, 1)
1610 }
1611
1612 func traceGoPark(reason traceBlockReason, skip int) {
1613
1614
1615 traceEvent(byte(reason), skip)
1616 }
1617
1618 func traceGoUnpark(gp *g, skip int) {
1619 pp := getg().m.p
1620 gp.trace.seq++
1621 if gp.trace.lastP == pp {
1622 traceEvent(traceEvGoUnblockLocal, skip, gp.goid)
1623 } else {
1624 gp.trace.lastP = pp
1625 traceEvent(traceEvGoUnblock, skip, gp.goid, gp.trace.seq)
1626 }
1627 }
1628
1629 func traceGoSysCall() {
1630 var skip int
1631 switch {
1632 case tracefpunwindoff():
1633
1634
1635
1636
1637
1638 skip = 1
1639 case GOOS == "solaris" || GOOS == "illumos":
1640
1641 skip = 3
1642 default:
1643
1644 skip = 4
1645 }
1646 getg().m.curg.trace.tracedSyscallEnter = true
1647 traceEvent(traceEvGoSysCall, skip)
1648 }
1649
1650 func traceGoSysExit() {
1651 gp := getg().m.curg
1652 if !gp.trace.tracedSyscallEnter {
1653
1654
1655 return
1656 }
1657 gp.trace.tracedSyscallEnter = false
1658 ts := gp.trace.sysExitTime
1659 if ts != 0 && ts < trace.startTime {
1660
1661
1662
1663
1664
1665
1666
1667
1668
1669 ts = 0
1670 }
1671 gp.trace.sysExitTime = 0
1672 gp.trace.seq++
1673 gp.trace.lastP = gp.m.p
1674 traceEvent(traceEvGoSysExit, -1, gp.goid, gp.trace.seq, uint64(ts))
1675 }
1676
1677 func traceGoSysBlock(pp *p) {
1678
1679
1680 mp := acquirem()
1681 oldp := mp.p
1682 mp.p.set(pp)
1683 traceEvent(traceEvGoSysBlock, -1)
1684 mp.p = oldp
1685 releasem(mp)
1686 }
1687
1688 func traceHeapAlloc(live uint64) {
1689 traceEvent(traceEvHeapAlloc, -1, live)
1690 }
1691
1692 func traceHeapGoal() {
1693 heapGoal := gcController.heapGoal()
1694 if heapGoal == ^uint64(0) {
1695
1696 traceEvent(traceEvHeapGoal, -1, 0)
1697 } else {
1698 traceEvent(traceEvHeapGoal, -1, heapGoal)
1699 }
1700 }
1701
1702
1703
1704
1705
1706 func trace_userTaskCreate(id, parentID uint64, taskType string) {
1707 if !trace.enabled {
1708 return
1709 }
1710
1711
1712 mp, pid, bufp := traceAcquireBuffer()
1713 if !trace.enabled && !mp.trace.startingTrace {
1714 traceReleaseBuffer(mp, pid)
1715 return
1716 }
1717
1718 typeStringID, bufp := traceString(bufp, pid, taskType)
1719 traceEventLocked(0, mp, pid, bufp, traceEvUserTaskCreate, 0, 3, id, parentID, typeStringID)
1720 traceReleaseBuffer(mp, pid)
1721 }
1722
1723
1724 func trace_userTaskEnd(id uint64) {
1725 traceEvent(traceEvUserTaskEnd, 2, id)
1726 }
1727
1728
1729 func trace_userRegion(id, mode uint64, name string) {
1730 if !trace.enabled {
1731 return
1732 }
1733
1734 mp, pid, bufp := traceAcquireBuffer()
1735 if !trace.enabled && !mp.trace.startingTrace {
1736 traceReleaseBuffer(mp, pid)
1737 return
1738 }
1739
1740 nameStringID, bufp := traceString(bufp, pid, name)
1741 traceEventLocked(0, mp, pid, bufp, traceEvUserRegion, 0, 3, id, mode, nameStringID)
1742 traceReleaseBuffer(mp, pid)
1743 }
1744
1745
1746 func trace_userLog(id uint64, category, message string) {
1747 if !trace.enabled {
1748 return
1749 }
1750
1751 mp, pid, bufp := traceAcquireBuffer()
1752 if !trace.enabled && !mp.trace.startingTrace {
1753 traceReleaseBuffer(mp, pid)
1754 return
1755 }
1756
1757 categoryID, bufp := traceString(bufp, pid, category)
1758
1759
1760
1761
1762
1763 extraSpace := traceBytesPerNumber + len(message)
1764 traceEventLocked(extraSpace, mp, pid, bufp, traceEvUserLog, 0, 3, id, categoryID)
1765 buf := bufp.ptr()
1766
1767
1768
1769 slen := len(message)
1770 if room := len(buf.arr) - buf.pos; room < slen+traceBytesPerNumber {
1771 slen = room
1772 }
1773 buf.varint(uint64(slen))
1774 buf.pos += copy(buf.arr[buf.pos:], message[:slen])
1775
1776 traceReleaseBuffer(mp, pid)
1777 }
1778
1779
1780
1781 func startPCforTrace(pc uintptr) uintptr {
1782 f := findfunc(pc)
1783 if !f.valid() {
1784 return pc
1785 }
1786 w := funcdata(f, abi.FUNCDATA_WrapInfo)
1787 if w == nil {
1788 return pc
1789 }
1790 return f.datap.textAddr(*(*uint32)(w))
1791 }
1792
1793
1794
1795
1796
1797 func traceOneNewExtraM(gp *g) {
1798
1799
1800
1801 traceGoCreate(gp, 0)
1802 gp.trace.seq++
1803 traceEvent(traceEvGoInSyscall, -1, gp.goid)
1804 }
1805
1806
1807 type traceTime uint64
1808
1809
1810
1811
1812
1813
1814
1815
1816 func traceClockNow() traceTime {
1817 return traceTime(cputicks() / traceTimeDiv)
1818 }
1819
View as plain text