1
2
3
4
5 package trace
6
7 import (
8 "fmt"
9 "math"
10 "strings"
11 "time"
12
13 "internal/trace/event"
14 "internal/trace/event/go122"
15 "internal/trace/version"
16 )
17
18
19
20
21
22 type EventKind uint16
23
24 const (
25 EventBad EventKind = iota
26
27
28
29
30
31 EventSync
32
33
34
35 EventMetric
36
37
38 EventLabel
39
40
41
42
43
44
45
46
47
48 EventStackSample
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64 EventRangeBegin
65 EventRangeActive
66 EventRangeEnd
67
68
69 EventTaskBegin
70 EventTaskEnd
71
72
73 EventRegionBegin
74 EventRegionEnd
75
76
77 EventLog
78
79
80 EventStateTransition
81
82
83
84
85 EventExperimental
86 )
87
88
89 func (e EventKind) String() string {
90 if int(e) >= len(eventKindStrings) {
91 return eventKindStrings[0]
92 }
93 return eventKindStrings[e]
94 }
95
96 var eventKindStrings = [...]string{
97 EventBad: "Bad",
98 EventSync: "Sync",
99 EventMetric: "Metric",
100 EventLabel: "Label",
101 EventStackSample: "StackSample",
102 EventRangeBegin: "RangeBegin",
103 EventRangeActive: "RangeActive",
104 EventRangeEnd: "RangeEnd",
105 EventTaskBegin: "TaskBegin",
106 EventTaskEnd: "TaskEnd",
107 EventRegionBegin: "RegionBegin",
108 EventRegionEnd: "RegionEnd",
109 EventLog: "Log",
110 EventStateTransition: "StateTransition",
111 EventExperimental: "Experimental",
112 }
113
114 const maxTime = Time(math.MaxInt64)
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135 type Time int64
136
137
138 func (t Time) Sub(t0 Time) time.Duration {
139 return time.Duration(int64(t) - int64(t0))
140 }
141
142
143 type Metric struct {
144
145
146
147
148
149
150
151
152 Name string
153
154
155
156
157
158 Value Value
159 }
160
161
162 type Label struct {
163
164 Label string
165
166
167 Resource ResourceID
168 }
169
170
171 type Range struct {
172
173
174
175
176
177
178
179 Name string
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196 Scope ResourceID
197 }
198
199
200 type RangeAttribute struct {
201
202 Name string
203
204
205 Value Value
206 }
207
208
209
210 type TaskID uint64
211
212 const (
213
214 NoTask = TaskID(^uint64(0))
215
216
217
218 BackgroundTask = TaskID(0)
219 )
220
221
222 type Task struct {
223
224
225
226 ID TaskID
227
228
229 Parent TaskID
230
231
232
233
234 Type string
235 }
236
237
238 type Region struct {
239
240 Task TaskID
241
242
243 Type string
244 }
245
246
247 type Log struct {
248
249 Task TaskID
250
251
252 Category string
253
254
255 Message string
256 }
257
258
259
260
261
262 type Stack struct {
263 table *evTable
264 id stackID
265 }
266
267
268 func (s Stack) Frames(yield func(f StackFrame) bool) bool {
269 if s.id == 0 {
270 return true
271 }
272 stk := s.table.stacks.mustGet(s.id)
273 for _, pc := range stk.pcs {
274 f := s.table.pcs[pc]
275 sf := StackFrame{
276 PC: f.pc,
277 Func: s.table.strings.mustGet(f.funcID),
278 File: s.table.strings.mustGet(f.fileID),
279 Line: f.line,
280 }
281 if !yield(sf) {
282 return false
283 }
284 }
285 return true
286 }
287
288
289
290 var NoStack = Stack{}
291
292
293 type StackFrame struct {
294
295
296
297 PC uint64
298
299
300 Func string
301
302
303 File string
304
305
306 Line uint64
307 }
308
309
310 type ExperimentalEvent struct {
311
312 Name string
313
314
315
316 ArgNames []string
317
318
319 Args []uint64
320
321
322
323
324 Data *ExperimentalData
325 }
326
327
328
329
330
331 type ExperimentalData struct {
332
333 Batches []ExperimentalBatch
334 }
335
336
337 type ExperimentalBatch struct {
338
339 Thread ThreadID
340
341
342 Data []byte
343 }
344
345
346 type Event struct {
347 table *evTable
348 ctx schedCtx
349 base baseEvent
350 }
351
352
353 func (e Event) Kind() EventKind {
354 return go122Type2Kind[e.base.typ]
355 }
356
357
358 func (e Event) Time() Time {
359 return e.base.time
360 }
361
362
363
364
365
366
367
368
369
370
371 func (e Event) Goroutine() GoID {
372 return e.ctx.G
373 }
374
375
376
377
378
379
380 func (e Event) Proc() ProcID {
381 return e.ctx.P
382 }
383
384
385
386
387
388
389
390
391
392
393
394 func (e Event) Thread() ThreadID {
395 return e.ctx.M
396 }
397
398
399
400
401
402 func (e Event) Stack() Stack {
403 if e.base.typ == evSync {
404 return NoStack
405 }
406 if e.base.typ == go122.EvCPUSample {
407 return Stack{table: e.table, id: stackID(e.base.args[0])}
408 }
409 spec := go122.Specs()[e.base.typ]
410 if len(spec.StackIDs) == 0 {
411 return NoStack
412 }
413
414
415
416 id := stackID(e.base.args[spec.StackIDs[0]-1])
417 if id == 0 {
418 return NoStack
419 }
420 return Stack{table: e.table, id: id}
421 }
422
423
424
425
426 func (e Event) Metric() Metric {
427 if e.Kind() != EventMetric {
428 panic("Metric called on non-Metric event")
429 }
430 var m Metric
431 switch e.base.typ {
432 case go122.EvProcsChange:
433 m.Name = "/sched/gomaxprocs:threads"
434 m.Value = Value{kind: ValueUint64, scalar: e.base.args[0]}
435 case go122.EvHeapAlloc:
436 m.Name = "/memory/classes/heap/objects:bytes"
437 m.Value = Value{kind: ValueUint64, scalar: e.base.args[0]}
438 case go122.EvHeapGoal:
439 m.Name = "/gc/heap/goal:bytes"
440 m.Value = Value{kind: ValueUint64, scalar: e.base.args[0]}
441 default:
442 panic(fmt.Sprintf("internal error: unexpected event type for Metric kind: %s", go122.EventString(e.base.typ)))
443 }
444 return m
445 }
446
447
448
449
450 func (e Event) Label() Label {
451 if e.Kind() != EventLabel {
452 panic("Label called on non-Label event")
453 }
454 if e.base.typ != go122.EvGoLabel {
455 panic(fmt.Sprintf("internal error: unexpected event type for Label kind: %s", go122.EventString(e.base.typ)))
456 }
457 return Label{
458 Label: e.table.strings.mustGet(stringID(e.base.args[0])),
459 Resource: ResourceID{Kind: ResourceGoroutine, id: int64(e.ctx.G)},
460 }
461 }
462
463
464
465
466 func (e Event) Range() Range {
467 if kind := e.Kind(); kind != EventRangeBegin && kind != EventRangeActive && kind != EventRangeEnd {
468 panic("Range called on non-Range event")
469 }
470 var r Range
471 switch e.base.typ {
472 case go122.EvSTWBegin, go122.EvSTWEnd:
473
474
475 r.Name = "stop-the-world (" + e.table.strings.mustGet(stringID(e.base.args[0])) + ")"
476 r.Scope = ResourceID{Kind: ResourceGoroutine, id: int64(e.Goroutine())}
477 case go122.EvGCBegin, go122.EvGCActive, go122.EvGCEnd:
478 r.Name = "GC concurrent mark phase"
479 r.Scope = ResourceID{Kind: ResourceNone}
480 case go122.EvGCSweepBegin, go122.EvGCSweepActive, go122.EvGCSweepEnd:
481 r.Name = "GC incremental sweep"
482 r.Scope = ResourceID{Kind: ResourceProc}
483 if e.base.typ == go122.EvGCSweepActive {
484 r.Scope.id = int64(e.base.args[0])
485 } else {
486 r.Scope.id = int64(e.Proc())
487 }
488 r.Scope.id = int64(e.Proc())
489 case go122.EvGCMarkAssistBegin, go122.EvGCMarkAssistActive, go122.EvGCMarkAssistEnd:
490 r.Name = "GC mark assist"
491 r.Scope = ResourceID{Kind: ResourceGoroutine}
492 if e.base.typ == go122.EvGCMarkAssistActive {
493 r.Scope.id = int64(e.base.args[0])
494 } else {
495 r.Scope.id = int64(e.Goroutine())
496 }
497 default:
498 panic(fmt.Sprintf("internal error: unexpected event type for Range kind: %s", go122.EventString(e.base.typ)))
499 }
500 return r
501 }
502
503
504
505
506 func (e Event) RangeAttributes() []RangeAttribute {
507 if e.Kind() != EventRangeEnd {
508 panic("Range called on non-Range event")
509 }
510 if e.base.typ != go122.EvGCSweepEnd {
511 return nil
512 }
513 return []RangeAttribute{
514 {
515 Name: "bytes swept",
516 Value: Value{kind: ValueUint64, scalar: e.base.args[0]},
517 },
518 {
519 Name: "bytes reclaimed",
520 Value: Value{kind: ValueUint64, scalar: e.base.args[1]},
521 },
522 }
523 }
524
525
526
527
528 func (e Event) Task() Task {
529 if kind := e.Kind(); kind != EventTaskBegin && kind != EventTaskEnd {
530 panic("Task called on non-Task event")
531 }
532 parentID := NoTask
533 var typ string
534 switch e.base.typ {
535 case go122.EvUserTaskBegin:
536 parentID = TaskID(e.base.args[1])
537 typ = e.table.strings.mustGet(stringID(e.base.args[2]))
538 case go122.EvUserTaskEnd:
539 parentID = TaskID(e.base.extra(version.Go122)[0])
540 typ = e.table.getExtraString(extraStringID(e.base.extra(version.Go122)[1]))
541 default:
542 panic(fmt.Sprintf("internal error: unexpected event type for Task kind: %s", go122.EventString(e.base.typ)))
543 }
544 return Task{
545 ID: TaskID(e.base.args[0]),
546 Parent: parentID,
547 Type: typ,
548 }
549 }
550
551
552
553
554 func (e Event) Region() Region {
555 if kind := e.Kind(); kind != EventRegionBegin && kind != EventRegionEnd {
556 panic("Region called on non-Region event")
557 }
558 if e.base.typ != go122.EvUserRegionBegin && e.base.typ != go122.EvUserRegionEnd {
559 panic(fmt.Sprintf("internal error: unexpected event type for Region kind: %s", go122.EventString(e.base.typ)))
560 }
561 return Region{
562 Task: TaskID(e.base.args[0]),
563 Type: e.table.strings.mustGet(stringID(e.base.args[1])),
564 }
565 }
566
567
568
569
570 func (e Event) Log() Log {
571 if e.Kind() != EventLog {
572 panic("Log called on non-Log event")
573 }
574 if e.base.typ != go122.EvUserLog {
575 panic(fmt.Sprintf("internal error: unexpected event type for Log kind: %s", go122.EventString(e.base.typ)))
576 }
577 return Log{
578 Task: TaskID(e.base.args[0]),
579 Category: e.table.strings.mustGet(stringID(e.base.args[1])),
580 Message: e.table.strings.mustGet(stringID(e.base.args[2])),
581 }
582 }
583
584
585
586
587 func (e Event) StateTransition() StateTransition {
588 if e.Kind() != EventStateTransition {
589 panic("StateTransition called on non-StateTransition event")
590 }
591 var s StateTransition
592 switch e.base.typ {
593 case go122.EvProcStart:
594 s = procStateTransition(ProcID(e.base.args[0]), ProcIdle, ProcRunning)
595 case go122.EvProcStop:
596 s = procStateTransition(e.ctx.P, ProcRunning, ProcIdle)
597 case go122.EvProcSteal:
598
599 beforeState := ProcRunning
600 if go122.ProcStatus(e.base.extra(version.Go122)[0]) == go122.ProcSyscallAbandoned {
601
602
603
604
605 beforeState = ProcIdle
606 }
607 s = procStateTransition(ProcID(e.base.args[0]), beforeState, ProcIdle)
608 case go122.EvProcStatus:
609
610 s = procStateTransition(ProcID(e.base.args[0]), ProcState(e.base.extra(version.Go122)[0]), go122ProcStatus2ProcState[e.base.args[1]])
611 case go122.EvGoCreate, go122.EvGoCreateBlocked:
612 status := GoRunnable
613 if e.base.typ == go122.EvGoCreateBlocked {
614 status = GoWaiting
615 }
616 s = goStateTransition(GoID(e.base.args[0]), GoNotExist, status)
617 s.Stack = Stack{table: e.table, id: stackID(e.base.args[1])}
618 case go122.EvGoCreateSyscall:
619 s = goStateTransition(GoID(e.base.args[0]), GoNotExist, GoSyscall)
620 case go122.EvGoStart:
621 s = goStateTransition(GoID(e.base.args[0]), GoRunnable, GoRunning)
622 case go122.EvGoDestroy:
623 s = goStateTransition(e.ctx.G, GoRunning, GoNotExist)
624 s.Stack = e.Stack()
625 case go122.EvGoDestroySyscall:
626 s = goStateTransition(e.ctx.G, GoSyscall, GoNotExist)
627 case go122.EvGoStop:
628 s = goStateTransition(e.ctx.G, GoRunning, GoRunnable)
629 s.Reason = e.table.strings.mustGet(stringID(e.base.args[0]))
630 s.Stack = e.Stack()
631 case go122.EvGoBlock:
632 s = goStateTransition(e.ctx.G, GoRunning, GoWaiting)
633 s.Reason = e.table.strings.mustGet(stringID(e.base.args[0]))
634 s.Stack = e.Stack()
635 case go122.EvGoUnblock, go122.EvGoSwitch, go122.EvGoSwitchDestroy:
636
637
638
639 s = goStateTransition(GoID(e.base.args[0]), GoWaiting, GoRunnable)
640 case go122.EvGoSyscallBegin:
641 s = goStateTransition(e.ctx.G, GoRunning, GoSyscall)
642 s.Stack = e.Stack()
643 case go122.EvGoSyscallEnd:
644 s = goStateTransition(e.ctx.G, GoSyscall, GoRunning)
645 s.Stack = e.Stack()
646 case go122.EvGoSyscallEndBlocked:
647 s = goStateTransition(e.ctx.G, GoSyscall, GoRunnable)
648 s.Stack = e.Stack()
649 case go122.EvGoStatus, go122.EvGoStatusStack:
650
651 s = goStateTransition(GoID(e.base.args[0]), GoState(e.base.extra(version.Go122)[0]), go122GoStatus2GoState[e.base.args[2]])
652 default:
653 panic(fmt.Sprintf("internal error: unexpected event type for StateTransition kind: %s", go122.EventString(e.base.typ)))
654 }
655 return s
656 }
657
658
659
660
661 func (e Event) Experimental() ExperimentalEvent {
662 if e.Kind() != EventExperimental {
663 panic("Experimental called on non-Experimental event")
664 }
665 spec := go122.Specs()[e.base.typ]
666 argNames := spec.Args[1:]
667 return ExperimentalEvent{
668 Name: spec.Name,
669 ArgNames: argNames,
670 Args: e.base.args[:len(argNames)],
671 Data: e.table.expData[spec.Experiment],
672 }
673 }
674
675 const evSync = ^event.Type(0)
676
677 var go122Type2Kind = [...]EventKind{
678 go122.EvCPUSample: EventStackSample,
679 go122.EvProcsChange: EventMetric,
680 go122.EvProcStart: EventStateTransition,
681 go122.EvProcStop: EventStateTransition,
682 go122.EvProcSteal: EventStateTransition,
683 go122.EvProcStatus: EventStateTransition,
684 go122.EvGoCreate: EventStateTransition,
685 go122.EvGoCreateSyscall: EventStateTransition,
686 go122.EvGoStart: EventStateTransition,
687 go122.EvGoDestroy: EventStateTransition,
688 go122.EvGoDestroySyscall: EventStateTransition,
689 go122.EvGoStop: EventStateTransition,
690 go122.EvGoBlock: EventStateTransition,
691 go122.EvGoUnblock: EventStateTransition,
692 go122.EvGoSyscallBegin: EventStateTransition,
693 go122.EvGoSyscallEnd: EventStateTransition,
694 go122.EvGoSyscallEndBlocked: EventStateTransition,
695 go122.EvGoStatus: EventStateTransition,
696 go122.EvSTWBegin: EventRangeBegin,
697 go122.EvSTWEnd: EventRangeEnd,
698 go122.EvGCActive: EventRangeActive,
699 go122.EvGCBegin: EventRangeBegin,
700 go122.EvGCEnd: EventRangeEnd,
701 go122.EvGCSweepActive: EventRangeActive,
702 go122.EvGCSweepBegin: EventRangeBegin,
703 go122.EvGCSweepEnd: EventRangeEnd,
704 go122.EvGCMarkAssistActive: EventRangeActive,
705 go122.EvGCMarkAssistBegin: EventRangeBegin,
706 go122.EvGCMarkAssistEnd: EventRangeEnd,
707 go122.EvHeapAlloc: EventMetric,
708 go122.EvHeapGoal: EventMetric,
709 go122.EvGoLabel: EventLabel,
710 go122.EvUserTaskBegin: EventTaskBegin,
711 go122.EvUserTaskEnd: EventTaskEnd,
712 go122.EvUserRegionBegin: EventRegionBegin,
713 go122.EvUserRegionEnd: EventRegionEnd,
714 go122.EvUserLog: EventLog,
715 go122.EvGoSwitch: EventStateTransition,
716 go122.EvGoSwitchDestroy: EventStateTransition,
717 go122.EvGoCreateBlocked: EventStateTransition,
718 go122.EvGoStatusStack: EventStateTransition,
719 go122.EvSpan: EventExperimental,
720 go122.EvSpanAlloc: EventExperimental,
721 go122.EvSpanFree: EventExperimental,
722 go122.EvHeapObject: EventExperimental,
723 go122.EvHeapObjectAlloc: EventExperimental,
724 go122.EvHeapObjectFree: EventExperimental,
725 go122.EvGoroutineStack: EventExperimental,
726 go122.EvGoroutineStackAlloc: EventExperimental,
727 go122.EvGoroutineStackFree: EventExperimental,
728 evSync: EventSync,
729 }
730
731 var go122GoStatus2GoState = [...]GoState{
732 go122.GoRunnable: GoRunnable,
733 go122.GoRunning: GoRunning,
734 go122.GoWaiting: GoWaiting,
735 go122.GoSyscall: GoSyscall,
736 }
737
738 var go122ProcStatus2ProcState = [...]ProcState{
739 go122.ProcRunning: ProcRunning,
740 go122.ProcIdle: ProcIdle,
741 go122.ProcSyscall: ProcRunning,
742 go122.ProcSyscallAbandoned: ProcIdle,
743 }
744
745
746
747
748 func (e Event) String() string {
749 var sb strings.Builder
750 fmt.Fprintf(&sb, "M=%d P=%d G=%d", e.Thread(), e.Proc(), e.Goroutine())
751 fmt.Fprintf(&sb, " %s Time=%d", e.Kind(), e.Time())
752
753 switch kind := e.Kind(); kind {
754 case EventMetric:
755 m := e.Metric()
756 fmt.Fprintf(&sb, " Name=%q Value=%s", m.Name, valueAsString(m.Value))
757 case EventLabel:
758 l := e.Label()
759 fmt.Fprintf(&sb, " Label=%q Resource=%s", l.Label, l.Resource)
760 case EventRangeBegin, EventRangeActive, EventRangeEnd:
761 r := e.Range()
762 fmt.Fprintf(&sb, " Name=%q Scope=%s", r.Name, r.Scope)
763 if kind == EventRangeEnd {
764 fmt.Fprintf(&sb, " Attributes=[")
765 for i, attr := range e.RangeAttributes() {
766 if i != 0 {
767 fmt.Fprintf(&sb, " ")
768 }
769 fmt.Fprintf(&sb, "%q=%s", attr.Name, valueAsString(attr.Value))
770 }
771 fmt.Fprintf(&sb, "]")
772 }
773 case EventTaskBegin, EventTaskEnd:
774 t := e.Task()
775 fmt.Fprintf(&sb, " ID=%d Parent=%d Type=%q", t.ID, t.Parent, t.Type)
776 case EventRegionBegin, EventRegionEnd:
777 r := e.Region()
778 fmt.Fprintf(&sb, " Task=%d Type=%q", r.Task, r.Type)
779 case EventLog:
780 l := e.Log()
781 fmt.Fprintf(&sb, " Task=%d Category=%q Message=%q", l.Task, l.Category, l.Message)
782 case EventStateTransition:
783 s := e.StateTransition()
784 fmt.Fprintf(&sb, " Resource=%s Reason=%q", s.Resource, s.Reason)
785 switch s.Resource.Kind {
786 case ResourceGoroutine:
787 id := s.Resource.Goroutine()
788 old, new := s.Goroutine()
789 fmt.Fprintf(&sb, " GoID=%d %s->%s", id, old, new)
790 case ResourceProc:
791 id := s.Resource.Proc()
792 old, new := s.Proc()
793 fmt.Fprintf(&sb, " ProcID=%d %s->%s", id, old, new)
794 }
795 if s.Stack != NoStack {
796 fmt.Fprintln(&sb)
797 fmt.Fprintln(&sb, "TransitionStack=")
798 s.Stack.Frames(func(f StackFrame) bool {
799 fmt.Fprintf(&sb, "\t%s @ 0x%x\n", f.Func, f.PC)
800 fmt.Fprintf(&sb, "\t\t%s:%d\n", f.File, f.Line)
801 return true
802 })
803 }
804 case EventExperimental:
805 r := e.Experimental()
806 fmt.Fprintf(&sb, " Name=%s ArgNames=%v Args=%v", r.Name, r.ArgNames, r.Args)
807 }
808 if stk := e.Stack(); stk != NoStack {
809 fmt.Fprintln(&sb)
810 fmt.Fprintln(&sb, "Stack=")
811 stk.Frames(func(f StackFrame) bool {
812 fmt.Fprintf(&sb, "\t%s @ 0x%x\n", f.Func, f.PC)
813 fmt.Fprintf(&sb, "\t\t%s:%d\n", f.File, f.Line)
814 return true
815 })
816 }
817 return sb.String()
818 }
819
820
821
822 func (e Event) validateTableIDs() error {
823 if e.base.typ == evSync {
824 return nil
825 }
826 spec := go122.Specs()[e.base.typ]
827
828
829 for _, i := range spec.StackIDs {
830 id := stackID(e.base.args[i-1])
831 _, ok := e.table.stacks.get(id)
832 if !ok {
833 return fmt.Errorf("found invalid stack ID %d for event %s", id, spec.Name)
834 }
835 }
836
837
838
839
840 for _, i := range spec.StringIDs {
841 id := stringID(e.base.args[i-1])
842 _, ok := e.table.strings.get(id)
843 if !ok {
844 return fmt.Errorf("found invalid string ID %d for event %s", id, spec.Name)
845 }
846 }
847 return nil
848 }
849
850 func syncEvent(table *evTable, ts Time) Event {
851 return Event{
852 table: table,
853 ctx: schedCtx{
854 G: NoGoroutine,
855 P: NoProc,
856 M: NoThread,
857 },
858 base: baseEvent{
859 typ: evSync,
860 time: ts,
861 },
862 }
863 }
864
View as plain text