// httpUserTasks reports all tasks found in the trace.
func httpUserTasks(w http.ResponseWriter, r *http.Request) {
- tasks, err := analyzeAnnotations()
+ res, err := analyzeAnnotations()
if err != nil {
http.Error(w, err.Error(), http.StatusInternalServerError)
return
}
+ tasks := res.tasks
summary := make(map[string]taskStats)
for _, task := range tasks {
stats, ok := summary[task.name]
return
}
- tasks, err := analyzeAnnotations()
+ res, err := analyzeAnnotations()
if err != nil {
http.Error(w, err.Error(), http.StatusInternalServerError)
return
}
+ tasks := res.tasks
type event struct {
WhenString string
}
}
+type annotationAnalysisResult struct {
+ tasks map[uint64]*taskDesc // tasks
+ gcEvents []*trace.Event // GCStartevents, sorted
+}
+
// analyzeAnnotations analyzes user annotation events and
// returns the task descriptors keyed by internal task id.
-func analyzeAnnotations() (map[uint64]*taskDesc, error) {
+func analyzeAnnotations() (annotationAnalysisResult, error) {
res, err := parseTrace()
if err != nil {
- return nil, fmt.Errorf("failed to parse trace: %v", err)
+ return annotationAnalysisResult{}, fmt.Errorf("failed to parse trace: %v", err)
}
events := res.Events
if len(events) == 0 {
- return nil, fmt.Errorf("empty trace")
+ return annotationAnalysisResult{}, fmt.Errorf("empty trace")
}
tasks := allTasks{}
activeSpans := map[uint64][]*trace.Event{} // goid to active span start events
+ var gcEvents []*trace.Event
for _, ev := range events {
goid := ev.G
task := tasks.task(taskid)
task.addEvent(ev)
+ // retrieve parent task information
+ if typ == trace.EvUserTaskCreate {
+ if parentID := ev.Args[1]; parentID != 0 {
+ parentTask := tasks.task(parentID)
+ task.parent = parentTask
+ if parentTask != nil {
+ parentTask.children = append(parentTask.children, task)
+ }
+ }
+ }
+
if typ == trace.EvUserSpan {
mode := ev.Args[1]
spans := activeSpans[goid]
taskid := spans[len(spans)-1].Args[0]
task := tasks.task(taskid)
task.addEvent(ev)
+
+ case trace.EvGCStart:
+ gcEvents = append(gcEvents, ev)
}
}
- return tasks, nil
+ return annotationAnalysisResult{tasks: tasks, gcEvents: gcEvents}, nil
}
// taskDesc represents a task.
create *trace.Event // Task create event
end *trace.Event // Task end event
+
+ parent *taskDesc
+ children []*taskDesc
+}
+
+func newTaskDesc(id uint64) *taskDesc {
+ return &taskDesc{
+ id: id,
+ goroutines: make(map[uint64][]*trace.Event),
+ }
}
func (task *taskDesc) String() string {
for _, s := range task.spans {
fmt.Fprintf(wb, "\t\t%s(goid=%d)\n", s.name, s.goid)
}
+ if task.parent != nil {
+ fmt.Fprintf(wb, "\tparent: %s\n", task.parent.name)
+ }
+ fmt.Fprintf(wb, "\t%d children:\n", len(task.children))
+ for _, c := range task.children {
+ fmt.Fprintf(wb, "\t\t%s\n", c.name)
+ }
+
return wb.String()
}
return task.create != nil && task.end != nil
}
+// descendents returns all the task nodes in the subtree rooted from this task.
+func (task *taskDesc) decendents() []*taskDesc {
+ if task == nil {
+ return nil
+ }
+ res := []*taskDesc{task}
+ for i := 0; len(res[i:]) > 0; i++ {
+ t := res[i]
+ for _, c := range t.children {
+ res = append(res, c)
+ }
+ }
+ return res
+}
+
// firstTimestamp returns the first timestamp of this task found in
// this trace. If the trace does not contain the task creation event,
// the first timestamp of the trace will be returned.
case trace.EvGoEnd, trace.EvGoStop:
return "goroutine stopped"
case trace.EvUserLog:
- return fmt.Sprintf("%v=%v", ev.SArgs[0], ev.SArgs[1])
+ if k, v := ev.SArgs[0], ev.SArgs[1]; k == "" {
+ return v
+ } else {
+ return fmt.Sprintf("%v=%v", k, v)
+ }
case trace.EvUserSpan:
if ev.Args[1] == 0 {
duration := "unknown"
// Run prog0 and capture the execution trace.
traceProgram(prog0, "TestAnalyzeAnnotations")
- tasks, err := analyzeAnnotations()
+ res, err := analyzeAnnotations()
if err != nil {
t.Fatalf("failed to analyzeAnnotations: %v", err)
}
+ tasks := res.tasks
+
// For prog0, we expect
// - task with name = "task0", with three spans.
// - task with name = "task1", with no span.
}
}
+// prog1 creates a task hierarchy consisting of three tasks.
+func prog1() {
+ ctx := context.Background()
+ ctx1, done1 := trace.NewContext(ctx, "task1")
+ defer done1()
+ trace.WithSpan(ctx1, "task1.span", func(ctx context.Context) {
+ ctx2, done2 := trace.NewContext(ctx, "task2")
+ defer done2()
+ trace.WithSpan(ctx2, "task2.span", func(ctx context.Context) {
+ ctx3, done3 := trace.NewContext(ctx, "task3")
+ defer done3()
+ trace.WithSpan(ctx3, "task3.span", func(ctx context.Context) {
+ })
+ })
+ })
+}
+
+func TestAnalyzeAnnotationTaskTree(t *testing.T) {
+ // Run prog1 and capture the execution trace.
+ traceProgram(prog1, "TestAnalyzeAnnotationTaskTree")
+
+ res, err := analyzeAnnotations()
+ if err != nil {
+ t.Fatalf("failed to analyzeAnnotation: %v", err)
+ }
+ tasks := res.tasks
+
+ // For prog0, we expect
+ // - task with name = "", with taskless.span in spans.
+ // - task with name = "task0", with three spans.
+ wantTasks := map[string]struct {
+ parent string
+ children []string
+ spans []string
+ }{
+ "task1": {
+ parent: "",
+ children: []string{"task2"},
+ spans: []string{"task1.span"},
+ },
+ "task2": {
+ parent: "task1",
+ children: []string{"task3"},
+ spans: []string{"task2.span"},
+ },
+ "task3": {
+ parent: "task2",
+ children: nil,
+ spans: []string{"task3.span"},
+ },
+ }
+
+ for _, task := range tasks {
+ want, ok := wantTasks[task.name]
+ if !ok {
+ t.Errorf("unexpected task: %s", task)
+ continue
+ }
+ delete(wantTasks, task.name)
+
+ if parentName(task) != want.parent ||
+ !reflect.DeepEqual(childrenNames(task), want.children) ||
+ !reflect.DeepEqual(spanNames(task), want.spans) {
+ t.Errorf("got %v; want %+v", task, want)
+ }
+ }
+
+ if len(wantTasks) > 0 {
+ t.Errorf("no more tasks; want %+v", wantTasks)
+ }
+}
+
// traceProgram runs the provided function while tracing is enabled,
// parses the captured trace, and sets the global trace loader to
// point to the parsed trace.
return ret
}
+func parentName(task *taskDesc) string {
+ if task.parent != nil {
+ return task.parent.name
+ }
+ return ""
+}
+
+func childrenNames(task *taskDesc) (ret []string) {
+ for _, s := range task.children {
+ ret = append(ret, s.name)
+ }
+ return ret
+}
+
func swapLoaderData(res traceparser.ParseResult, err error) {
// swap loader's data.
parseTrace() // fool loader.once.
log.Printf("failed to parse taskid parameter %q: %v", taskids, err)
return
}
- tasks, _ := analyzeAnnotations()
- task, ok := tasks[taskid]
+ annotRes, _ := analyzeAnnotations()
+ task, ok := annotRes.tasks[taskid]
if !ok {
log.Printf("failed to find task with id %d", taskid)
return
params.startTime = task.firstTimestamp() - 1
params.endTime = task.lastTimestamp() + 1
params.maing = goid
- params.gs = task.RelatedGoroutines(res.Events, 0) // find only directly involved goroutines
- params.showTask = task
+ params.tasks = task.decendents()
+ gs := map[uint64]bool{}
+ for _, t := range params.tasks {
+ // find only directly involved goroutines
+ for k, v := range t.RelatedGoroutines(res.Events, 0) {
+ gs[k] = v
+ }
+ }
+ params.gs = gs
}
data, err := generateTrace(params)
endTime int64
maing uint64 // for goroutine-oriented view, place this goroutine on the top row
gs map[uint64]bool // Goroutines to be displayed for goroutine-oriented or task-oriented view
- showTask *taskDesc // Task to be displayed
+ tasks []*taskDesc // Tasks to be displayed. tasks[0] is the top-most task
}
type traceviewMode int
ctx.emit(&ViewerEvent{Name: "thread_name", Phase: "M", Pid: 0, Tid: trace.SyscallP, Arg: &NameArg{"Syscalls"}})
ctx.emit(&ViewerEvent{Name: "thread_sort_index", Phase: "M", Pid: 0, Tid: trace.SyscallP, Arg: &SortIndexArg{-3}})
+ // Display rows for Ps if we are in the default trace view mode.
if ctx.mode == defaultTraceview {
for i := 0; i <= maxProc; i++ {
ctx.emit(&ViewerEvent{Name: "thread_name", Phase: "M", Pid: 0, Tid: uint64(i), Arg: &NameArg{fmt.Sprintf("Proc %v", i)}})
}
}
- // Display task and its spans
- taskRow := uint64(trace.GCP + 1)
- if task := ctx.showTask; task != nil {
- taskName := fmt.Sprintf("Task %s(%d)", task.name, task.id)
- ctx.emit(&ViewerEvent{Name: "thread_name", Phase: "M", Pid: 0, Tid: taskRow, Arg: &NameArg{"Tasks"}})
- ctx.emit(&ViewerEvent{Name: "thread_sort_index", Phase: "M", Pid: 0, Tid: taskRow, Arg: &SortIndexArg{-3}})
- ctx.emit(&ViewerEvent{Category: "task", Name: taskName, Phase: "b", Time: float64(task.firstTimestamp()) / 1e3, Tid: taskRow, ID: task.id, Cname: "bad"})
- ctx.emit(&ViewerEvent{Category: "task", Name: taskName, Phase: "e", Time: float64(task.lastTimestamp()) / 1e3, Tid: taskRow, ID: task.id, Cname: "bad"})
- // Spans
- for _, s := range task.spans {
- ctx.emitSpan(s)
+ // Display task and its spans if we are in the taskTrace view mode.
+ if ctx.mode == taskTraceview {
+ taskRow := uint64(trace.GCP + 1)
+ for _, task := range ctx.tasks {
+ taskName := fmt.Sprintf("Task %s(%d)", task.name, task.id)
+ ctx.emit(&ViewerEvent{Name: "thread_name", Phase: "M", Pid: 0, Tid: taskRow, Arg: &NameArg{"Tasks"}})
+ ctx.emit(&ViewerEvent{Name: "thread_sort_index", Phase: "M", Pid: 0, Tid: taskRow, Arg: &SortIndexArg{-3}})
+ ctx.emit(&ViewerEvent{Category: "task", Name: taskName, Phase: "b", Time: float64(task.firstTimestamp()) / 1e3, Tid: taskRow, ID: task.id, Cname: "bad"})
+ ctx.emit(&ViewerEvent{Category: "task", Name: taskName, Phase: "e", Time: float64(task.lastTimestamp()) / 1e3, Tid: taskRow, ID: task.id, Cname: "bad"})
+ // Spans
+ for _, s := range task.spans {
+ ctx.emitSpan(s)
+ }
}
}
+ // Display goroutine rows if we are either in gtrace or taskTrace view mode.
if ctx.mode != defaultTraceview && ctx.gs != nil {
for k, v := range ginfos {
if !ctx.gs[k] {