blob: c91c743a7bfb6c83141a576fe74724a61ef51b1c [file] [log] [blame]
// Copyright 2023 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.
package traceviewer
import (
"encoding/json"
"fmt"
"internal/trace"
"internal/trace/traceviewer/format"
"io"
"strconv"
"time"
)
type TraceConsumer struct {
ConsumeTimeUnit func(unit string)
ConsumeViewerEvent func(v *format.Event, required bool)
ConsumeViewerFrame func(key string, f format.Frame)
Flush func()
}
// ViewerDataTraceConsumer returns a TraceConsumer that writes to w. The
// startIdx and endIdx are used for splitting large traces. They refer to
// indexes in the traceEvents output array, not the events in the trace input.
func ViewerDataTraceConsumer(w io.Writer, startIdx, endIdx int64) TraceConsumer {
allFrames := make(map[string]format.Frame)
requiredFrames := make(map[string]format.Frame)
enc := json.NewEncoder(w)
written := 0
index := int64(-1)
io.WriteString(w, "{")
return TraceConsumer{
ConsumeTimeUnit: func(unit string) {
io.WriteString(w, `"displayTimeUnit":`)
enc.Encode(unit)
io.WriteString(w, ",")
},
ConsumeViewerEvent: func(v *format.Event, required bool) {
index++
if !required && (index < startIdx || index > endIdx) {
// not in the range. Skip!
return
}
WalkStackFrames(allFrames, v.Stack, func(id int) {
s := strconv.Itoa(id)
requiredFrames[s] = allFrames[s]
})
WalkStackFrames(allFrames, v.EndStack, func(id int) {
s := strconv.Itoa(id)
requiredFrames[s] = allFrames[s]
})
if written == 0 {
io.WriteString(w, `"traceEvents": [`)
}
if written > 0 {
io.WriteString(w, ",")
}
enc.Encode(v)
// TODO(mknyszek): get rid of the extra \n inserted by enc.Encode.
// Same should be applied to splittingTraceConsumer.
written++
},
ConsumeViewerFrame: func(k string, v format.Frame) {
allFrames[k] = v
},
Flush: func() {
io.WriteString(w, `], "stackFrames":`)
enc.Encode(requiredFrames)
io.WriteString(w, `}`)
},
}
}
func SplittingTraceConsumer(max int) (*splitter, TraceConsumer) {
type eventSz struct {
Time float64
Sz int
Frames []int
}
var (
// data.Frames contains only the frames for required events.
data = format.Data{Frames: make(map[string]format.Frame)}
allFrames = make(map[string]format.Frame)
sizes []eventSz
cw countingWriter
)
s := new(splitter)
return s, TraceConsumer{
ConsumeTimeUnit: func(unit string) {
data.TimeUnit = unit
},
ConsumeViewerEvent: func(v *format.Event, required bool) {
if required {
// Store required events inside data so flush
// can include them in the required part of the
// trace.
data.Events = append(data.Events, v)
WalkStackFrames(allFrames, v.Stack, func(id int) {
s := strconv.Itoa(id)
data.Frames[s] = allFrames[s]
})
WalkStackFrames(allFrames, v.EndStack, func(id int) {
s := strconv.Itoa(id)
data.Frames[s] = allFrames[s]
})
return
}
enc := json.NewEncoder(&cw)
enc.Encode(v)
size := eventSz{Time: v.Time, Sz: cw.size + 1} // +1 for ",".
// Add referenced stack frames. Their size is computed
// in flush, where we can dedup across events.
WalkStackFrames(allFrames, v.Stack, func(id int) {
size.Frames = append(size.Frames, id)
})
WalkStackFrames(allFrames, v.EndStack, func(id int) {
size.Frames = append(size.Frames, id) // This may add duplicates. We'll dedup later.
})
sizes = append(sizes, size)
cw.size = 0
},
ConsumeViewerFrame: func(k string, v format.Frame) {
allFrames[k] = v
},
Flush: func() {
// Calculate size of the mandatory part of the trace.
// This includes thread names and stack frames for
// required events.
cw.size = 0
enc := json.NewEncoder(&cw)
enc.Encode(data)
requiredSize := cw.size
// Then calculate size of each individual event and
// their stack frames, grouping them into ranges. We
// only include stack frames relevant to the events in
// the range to reduce overhead.
var (
start = 0
eventsSize = 0
frames = make(map[string]format.Frame)
framesSize = 0
)
for i, ev := range sizes {
eventsSize += ev.Sz
// Add required stack frames. Note that they
// may already be in the map.
for _, id := range ev.Frames {
s := strconv.Itoa(id)
_, ok := frames[s]
if ok {
continue
}
f := allFrames[s]
frames[s] = f
framesSize += stackFrameEncodedSize(uint(id), f)
}
total := requiredSize + framesSize + eventsSize
if total < max {
continue
}
// Reached max size, commit this range and
// start a new range.
startTime := time.Duration(sizes[start].Time * 1000)
endTime := time.Duration(ev.Time * 1000)
s.Ranges = append(s.Ranges, Range{
Name: fmt.Sprintf("%v-%v", startTime, endTime),
Start: start,
End: i + 1,
StartTime: int64(startTime),
EndTime: int64(endTime),
})
start = i + 1
frames = make(map[string]format.Frame)
framesSize = 0
eventsSize = 0
}
if len(s.Ranges) <= 1 {
s.Ranges = nil
return
}
if end := len(sizes) - 1; start < end {
s.Ranges = append(s.Ranges, Range{
Name: fmt.Sprintf("%v-%v", time.Duration(sizes[start].Time*1000), time.Duration(sizes[end].Time*1000)),
Start: start,
End: end,
StartTime: int64(sizes[start].Time * 1000),
EndTime: int64(sizes[end].Time * 1000),
})
}
},
}
}
type splitter struct {
Ranges []Range
}
type countingWriter struct {
size int
}
func (cw *countingWriter) Write(data []byte) (int, error) {
cw.size += len(data)
return len(data), nil
}
func stackFrameEncodedSize(id uint, f format.Frame) int {
// We want to know the marginal size of traceviewer.Data.Frames for
// each event. Running full JSON encoding of the map for each event is
// far too slow.
//
// Since the format is fixed, we can easily compute the size without
// encoding.
//
// A single entry looks like one of the following:
//
// "1":{"name":"main.main:30"},
// "10":{"name":"pkg.NewSession:173","parent":9},
//
// The parent is omitted if 0. The trailing comma is omitted from the
// last entry, but we don't need that much precision.
const (
baseSize = len(`"`) + len(`":{"name":"`) + len(`"},`)
// Don't count the trailing quote on the name, as that is
// counted in baseSize.
parentBaseSize = len(`,"parent":`)
)
size := baseSize
size += len(f.Name)
// Bytes for id (always positive).
for id > 0 {
size += 1
id /= 10
}
if f.Parent > 0 {
size += parentBaseSize
// Bytes for parent (always positive).
for f.Parent > 0 {
size += 1
f.Parent /= 10
}
}
return size
}
// WalkStackFrames calls fn for id and all of its parent frames from allFrames.
func WalkStackFrames(allFrames map[string]format.Frame, id int, fn func(id int)) {
for id != 0 {
f, ok := allFrames[strconv.Itoa(id)]
if !ok {
break
}
fn(id)
id = f.Parent
}
}
type Mode int
const (
ModeGoroutineOriented Mode = 1 << iota
ModeTaskOriented
ModeThreadOriented // Mutually exclusive with ModeGoroutineOriented.
)
// NewEmitter returns a new Emitter that writes to c. The rangeStart and
// rangeEnd args are used for splitting large traces.
func NewEmitter(c TraceConsumer, rangeStart, rangeEnd time.Duration) *Emitter {
c.ConsumeTimeUnit("ns")
return &Emitter{
c: c,
rangeStart: rangeStart,
rangeEnd: rangeEnd,
frameTree: frameNode{children: make(map[uint64]frameNode)},
resources: make(map[uint64]string),
tasks: make(map[uint64]task),
}
}
type Emitter struct {
c TraceConsumer
rangeStart time.Duration
rangeEnd time.Duration
heapStats, prevHeapStats heapStats
gstates, prevGstates [gStateCount]int64
threadStats, prevThreadStats [threadStateCount]int64
gomaxprocs uint64
frameTree frameNode
frameSeq int
arrowSeq uint64
filter func(uint64) bool
resourceType string
resources map[uint64]string
focusResource uint64
tasks map[uint64]task
asyncSliceSeq uint64
}
type task struct {
name string
sortIndex int
}
func (e *Emitter) Gomaxprocs(v uint64) {
if v > e.gomaxprocs {
e.gomaxprocs = v
}
}
func (e *Emitter) Resource(id uint64, name string) {
if e.filter != nil && !e.filter(id) {
return
}
e.resources[id] = name
}
func (e *Emitter) SetResourceType(name string) {
e.resourceType = name
}
func (e *Emitter) SetResourceFilter(filter func(uint64) bool) {
e.filter = filter
}
func (e *Emitter) Task(id uint64, name string, sortIndex int) {
e.tasks[id] = task{name, sortIndex}
}
func (e *Emitter) Slice(s SliceEvent) {
if e.filter != nil && !e.filter(s.Resource) {
return
}
e.slice(s, format.ProcsSection, "")
}
func (e *Emitter) TaskSlice(s SliceEvent) {
e.slice(s, format.TasksSection, pickTaskColor(s.Resource))
}
func (e *Emitter) slice(s SliceEvent, sectionID uint64, cname string) {
if !e.tsWithinRange(s.Ts) && !e.tsWithinRange(s.Ts+s.Dur) {
return
}
e.OptionalEvent(&format.Event{
Name: s.Name,
Phase: "X",
Time: viewerTime(s.Ts),
Dur: viewerTime(s.Dur),
PID: sectionID,
TID: s.Resource,
Stack: s.Stack,
EndStack: s.EndStack,
Arg: s.Arg,
Cname: cname,
})
}
type SliceEvent struct {
Name string
Ts time.Duration
Dur time.Duration
Resource uint64
Stack int
EndStack int
Arg any
}
func (e *Emitter) AsyncSlice(s AsyncSliceEvent) {
if !e.tsWithinRange(s.Ts) && !e.tsWithinRange(s.Ts+s.Dur) {
return
}
if e.filter != nil && !e.filter(s.Resource) {
return
}
cname := ""
if s.TaskColorIndex != 0 {
cname = pickTaskColor(s.TaskColorIndex)
}
e.asyncSliceSeq++
e.OptionalEvent(&format.Event{
Category: s.Category,
Name: s.Name,
Phase: "b",
Time: viewerTime(s.Ts),
TID: s.Resource,
ID: e.asyncSliceSeq,
Scope: s.Scope,
Stack: s.Stack,
Cname: cname,
})
e.OptionalEvent(&format.Event{
Category: s.Category,
Name: s.Name,
Phase: "e",
Time: viewerTime(s.Ts + s.Dur),
TID: s.Resource,
ID: e.asyncSliceSeq,
Scope: s.Scope,
Stack: s.EndStack,
Arg: s.Arg,
Cname: cname,
})
}
type AsyncSliceEvent struct {
SliceEvent
Category string
Scope string
TaskColorIndex uint64 // Take on the same color as the task with this ID.
}
func (e *Emitter) Instant(i InstantEvent) {
if !e.tsWithinRange(i.Ts) {
return
}
if e.filter != nil && !e.filter(i.Resource) {
return
}
cname := ""
e.OptionalEvent(&format.Event{
Name: i.Name,
Category: i.Category,
Phase: "I",
Scope: "t",
Time: viewerTime(i.Ts),
PID: format.ProcsSection,
TID: i.Resource,
Stack: i.Stack,
Cname: cname,
Arg: i.Arg,
})
}
type InstantEvent struct {
Ts time.Duration
Name string
Category string
Resource uint64
Stack int
Arg any
}
func (e *Emitter) Arrow(a ArrowEvent) {
if e.filter != nil && (!e.filter(a.FromResource) || !e.filter(a.ToResource)) {
return
}
e.arrow(a, format.ProcsSection)
}
func (e *Emitter) TaskArrow(a ArrowEvent) {
e.arrow(a, format.TasksSection)
}
func (e *Emitter) arrow(a ArrowEvent, sectionID uint64) {
if !e.tsWithinRange(a.Start) || !e.tsWithinRange(a.End) {
return
}
e.arrowSeq++
e.OptionalEvent(&format.Event{
Name: a.Name,
Phase: "s",
TID: a.FromResource,
PID: sectionID,
ID: e.arrowSeq,
Time: viewerTime(a.Start),
Stack: a.FromStack,
})
e.OptionalEvent(&format.Event{
Name: a.Name,
Phase: "t",
TID: a.ToResource,
PID: sectionID,
ID: e.arrowSeq,
Time: viewerTime(a.End),
})
}
type ArrowEvent struct {
Name string
Start time.Duration
End time.Duration
FromResource uint64
FromStack int
ToResource uint64
}
func (e *Emitter) Event(ev *format.Event) {
e.c.ConsumeViewerEvent(ev, true)
}
func (e *Emitter) HeapAlloc(ts time.Duration, v uint64) {
e.heapStats.heapAlloc = v
e.emitHeapCounters(ts)
}
func (e *Emitter) Focus(id uint64) {
e.focusResource = id
}
func (e *Emitter) GoroutineTransition(ts time.Duration, from, to GState) {
e.gstates[from]--
e.gstates[to]++
if e.prevGstates == e.gstates {
return
}
if e.tsWithinRange(ts) {
e.OptionalEvent(&format.Event{
Name: "Goroutines",
Phase: "C",
Time: viewerTime(ts),
PID: 1,
Arg: &format.GoroutineCountersArg{
Running: uint64(e.gstates[GRunning]),
Runnable: uint64(e.gstates[GRunnable]),
GCWaiting: uint64(e.gstates[GWaitingGC]),
},
})
}
e.prevGstates = e.gstates
}
func (e *Emitter) IncThreadStateCount(ts time.Duration, state ThreadState, delta int64) {
e.threadStats[state] += delta
if e.prevThreadStats == e.threadStats {
return
}
if e.tsWithinRange(ts) {
e.OptionalEvent(&format.Event{
Name: "Threads",
Phase: "C",
Time: viewerTime(ts),
PID: 1,
Arg: &format.ThreadCountersArg{
Running: int64(e.threadStats[ThreadStateRunning]),
InSyscall: int64(e.threadStats[ThreadStateInSyscall]),
// TODO(mknyszek): Why is InSyscallRuntime not included here?
},
})
}
e.prevThreadStats = e.threadStats
}
func (e *Emitter) HeapGoal(ts time.Duration, v uint64) {
// This cutoff at 1 PiB is a Workaround for https://github.com/golang/go/issues/63864.
//
// TODO(mknyszek): Remove this once the problem has been fixed.
const PB = 1 << 50
if v > PB {
v = 0
}
e.heapStats.nextGC = v
e.emitHeapCounters(ts)
}
func (e *Emitter) emitHeapCounters(ts time.Duration) {
if e.prevHeapStats == e.heapStats {
return
}
diff := uint64(0)
if e.heapStats.nextGC > e.heapStats.heapAlloc {
diff = e.heapStats.nextGC - e.heapStats.heapAlloc
}
if e.tsWithinRange(ts) {
e.OptionalEvent(&format.Event{
Name: "Heap",
Phase: "C",
Time: viewerTime(ts),
PID: 1,
Arg: &format.HeapCountersArg{Allocated: e.heapStats.heapAlloc, NextGC: diff},
})
}
e.prevHeapStats = e.heapStats
}
// Err returns an error if the emitter is in an invalid state.
func (e *Emitter) Err() error {
if e.gstates[GRunnable] < 0 || e.gstates[GRunning] < 0 || e.threadStats[ThreadStateInSyscall] < 0 || e.threadStats[ThreadStateInSyscallRuntime] < 0 {
return fmt.Errorf(
"runnable=%d running=%d insyscall=%d insyscallRuntime=%d",
e.gstates[GRunnable],
e.gstates[GRunning],
e.threadStats[ThreadStateInSyscall],
e.threadStats[ThreadStateInSyscallRuntime],
)
}
return nil
}
func (e *Emitter) tsWithinRange(ts time.Duration) bool {
return e.rangeStart <= ts && ts <= e.rangeEnd
}
// OptionalEvent emits ev if it's within the time range of of the consumer, i.e.
// the selected trace split range.
func (e *Emitter) OptionalEvent(ev *format.Event) {
e.c.ConsumeViewerEvent(ev, false)
}
func (e *Emitter) Flush() {
e.processMeta(format.StatsSection, "STATS", 0)
if len(e.tasks) != 0 {
e.processMeta(format.TasksSection, "TASKS", 1)
}
for id, task := range e.tasks {
e.threadMeta(format.TasksSection, id, task.name, task.sortIndex)
}
e.processMeta(format.ProcsSection, e.resourceType, 2)
e.threadMeta(format.ProcsSection, trace.GCP, "GC", -6)
e.threadMeta(format.ProcsSection, trace.NetpollP, "Network", -5)
e.threadMeta(format.ProcsSection, trace.TimerP, "Timers", -4)
e.threadMeta(format.ProcsSection, trace.SyscallP, "Syscalls", -3)
for id, name := range e.resources {
priority := int(id)
if e.focusResource != 0 && id == e.focusResource {
// Put the focus goroutine on top.
priority = -2
}
e.threadMeta(format.ProcsSection, id, name, priority)
}
e.c.Flush()
}
func (e *Emitter) threadMeta(sectionID, tid uint64, name string, priority int) {
e.Event(&format.Event{
Name: "thread_name",
Phase: "M",
PID: sectionID,
TID: tid,
Arg: &format.NameArg{Name: name},
})
e.Event(&format.Event{
Name: "thread_sort_index",
Phase: "M",
PID: sectionID,
TID: tid,
Arg: &format.SortIndexArg{Index: priority},
})
}
func (e *Emitter) processMeta(sectionID uint64, name string, priority int) {
e.Event(&format.Event{
Name: "process_name",
Phase: "M",
PID: sectionID,
Arg: &format.NameArg{Name: name},
})
e.Event(&format.Event{
Name: "process_sort_index",
Phase: "M",
PID: sectionID,
Arg: &format.SortIndexArg{Index: priority},
})
}
// Stack emits the given frames and returns a unique id for the stack. No
// pointers to the given data are being retained beyond the call to Stack.
func (e *Emitter) Stack(stk []*trace.Frame) int {
return e.buildBranch(e.frameTree, stk)
}
// buildBranch builds one branch in the prefix tree rooted at ctx.frameTree.
func (e *Emitter) buildBranch(parent frameNode, stk []*trace.Frame) int {
if len(stk) == 0 {
return parent.id
}
last := len(stk) - 1
frame := stk[last]
stk = stk[:last]
node, ok := parent.children[frame.PC]
if !ok {
e.frameSeq++
node.id = e.frameSeq
node.children = make(map[uint64]frameNode)
parent.children[frame.PC] = node
e.c.ConsumeViewerFrame(strconv.Itoa(node.id), format.Frame{Name: fmt.Sprintf("%v:%v", frame.Fn, frame.Line), Parent: parent.id})
}
return e.buildBranch(node, stk)
}
type heapStats struct {
heapAlloc uint64
nextGC uint64
}
func viewerTime(t time.Duration) float64 {
return float64(t) / float64(time.Microsecond)
}
type GState int
const (
GDead GState = iota
GRunnable
GRunning
GWaiting
GWaitingGC
gStateCount
)
type ThreadState int
const (
ThreadStateInSyscall ThreadState = iota
ThreadStateInSyscallRuntime
ThreadStateRunning
threadStateCount
)
type frameNode struct {
id int
children map[uint64]frameNode
}
// Mapping from more reasonable color names to the reserved color names in
// https://github.com/catapult-project/catapult/blob/master/tracing/tracing/base/color_scheme.html#L50
// The chrome trace viewer allows only those as cname values.
const (
colorLightMauve = "thread_state_uninterruptible" // 182, 125, 143
colorOrange = "thread_state_iowait" // 255, 140, 0
colorSeafoamGreen = "thread_state_running" // 126, 200, 148
colorVistaBlue = "thread_state_runnable" // 133, 160, 210
colorTan = "thread_state_unknown" // 199, 155, 125
colorIrisBlue = "background_memory_dump" // 0, 180, 180
colorMidnightBlue = "light_memory_dump" // 0, 0, 180
colorDeepMagenta = "detailed_memory_dump" // 180, 0, 180
colorBlue = "vsync_highlight_color" // 0, 0, 255
colorGrey = "generic_work" // 125, 125, 125
colorGreen = "good" // 0, 125, 0
colorDarkGoldenrod = "bad" // 180, 125, 0
colorPeach = "terrible" // 180, 0, 0
colorBlack = "black" // 0, 0, 0
colorLightGrey = "grey" // 221, 221, 221
colorWhite = "white" // 255, 255, 255
colorYellow = "yellow" // 255, 255, 0
colorOlive = "olive" // 100, 100, 0
colorCornflowerBlue = "rail_response" // 67, 135, 253
colorSunsetOrange = "rail_animation" // 244, 74, 63
colorTangerine = "rail_idle" // 238, 142, 0
colorShamrockGreen = "rail_load" // 13, 168, 97
colorGreenishYellow = "startup" // 230, 230, 0
colorDarkGrey = "heap_dump_stack_frame" // 128, 128, 128
colorTawny = "heap_dump_child_node_arrow" // 204, 102, 0
colorLemon = "cq_build_running" // 255, 255, 119
colorLime = "cq_build_passed" // 153, 238, 102
colorPink = "cq_build_failed" // 238, 136, 136
colorSilver = "cq_build_abandoned" // 187, 187, 187
colorManzGreen = "cq_build_attempt_runnig" // 222, 222, 75
colorKellyGreen = "cq_build_attempt_passed" // 108, 218, 35
colorAnotherGrey = "cq_build_attempt_failed" // 187, 187, 187
)
var colorForTask = []string{
colorLightMauve,
colorOrange,
colorSeafoamGreen,
colorVistaBlue,
colorTan,
colorMidnightBlue,
colorIrisBlue,
colorDeepMagenta,
colorGreen,
colorDarkGoldenrod,
colorPeach,
colorOlive,
colorCornflowerBlue,
colorSunsetOrange,
colorTangerine,
colorShamrockGreen,
colorTawny,
colorLemon,
colorLime,
colorPink,
colorSilver,
colorManzGreen,
colorKellyGreen,
}
func pickTaskColor(id uint64) string {
idx := id % uint64(len(colorForTask))
return colorForTask[idx]
}