go annotations_test 源码
golang annotations_test 代码
文件路径：/src/cmd/trace/annotations_test.go
// Copyright 2018 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.
//go:build !js
package main
import (
"bytes"
"context"
"flag"
"fmt"
traceparser "internal/trace"
"os"
"reflect"
"runtime/debug"
"runtime/trace"
"sort"
"sync"
"testing"
"time"
)
var saveTraces = flag.Bool("savetraces", false, "save traces collected by tests")
func TestOverlappingDuration(t *testing.T) {
cases := []struct {
start0, end0, start1, end1 int64
want time.Duration
}{
{
1, 10, 11, 20, 0,
},
{
1, 10, 5, 20, 5 * time.Nanosecond,
},
{
1, 10, 2, 8, 6 * time.Nanosecond,
},
}
for _, tc := range cases {
s0, e0, s1, e1 := tc.start0, tc.end0, tc.start1, tc.end1
if got := overlappingDuration(s0, e0, s1, e1); got != tc.want {
t.Errorf("overlappingDuration(%d, %d, %d, %d)=%v; want %v", s0, e0, s1, e1, got, tc.want)
}
if got := overlappingDuration(s1, e1, s0, e0); got != tc.want {
t.Errorf("overlappingDuration(%d, %d, %d, %d)=%v; want %v", s1, e1, s0, e0, got, tc.want)
}
}
}
// prog0 starts three goroutines.
//
// goroutine 1: taskless region
// goroutine 2: starts task0, do work in task0.region0, starts task1 which ends immediately.
// goroutine 3: do work in task0.region1 and task0.region2, ends task0
func prog0() {
ctx := context.Background()
var wg sync.WaitGroup
wg.Add(1)
go func() { // goroutine 1
defer wg.Done()
trace.WithRegion(ctx, "taskless.region", func() {
trace.Log(ctx, "key0", "val0")
})
}()
wg.Add(1)
go func() { // goroutine 2
defer wg.Done()
ctx, task := trace.NewTask(ctx, "task0")
trace.WithRegion(ctx, "task0.region0", func() {
wg.Add(1)
go func() { // goroutine 3
defer wg.Done()
defer task.End()
trace.WithRegion(ctx, "task0.region1", func() {
trace.WithRegion(ctx, "task0.region2", func() {
trace.Log(ctx, "key2", "val2")
})
trace.Log(ctx, "key1", "val1")
})
}()
})
ctx2, task2 := trace.NewTask(ctx, "task1")
trace.Log(ctx2, "key3", "val3")
task2.End()
}()
wg.Wait()
}
func TestAnalyzeAnnotations(t *testing.T) {
// TODO: classify taskless regions
// Run prog0 and capture the execution trace.
if err := traceProgram(t, prog0, "TestAnalyzeAnnotations"); err != nil {
t.Fatalf("failed to trace the program: %v", err)
}
res, err := analyzeAnnotations()
if err != nil {
t.Fatalf("failed to analyzeAnnotations: %v", err)
}
// For prog0, we expect
// - task with name = "task0", with three regions.
// - task with name = "task1", with no region.
wantTasks := map[string]struct {
complete bool
goroutines int
regions []string
}{
"task0": {
complete: true,
goroutines: 2,
regions: []string{"task0.region0", "", "task0.region1", "task0.region2"},
},
"task1": {
complete: true,
goroutines: 1,
},
}
for _, task := range res.tasks {
want, ok := wantTasks[task.name]
if !ok {
t.Errorf("unexpected task: %s", task)
continue
}
if task.complete() != want.complete || len(task.goroutines) != want.goroutines || !reflect.DeepEqual(regionNames(task), want.regions) {
t.Errorf("got task %v; want %+v", task, want)
}
delete(wantTasks, task.name)
}
if len(wantTasks) > 0 {
t.Errorf("no more tasks; want %+v", wantTasks)
}
wantRegions := []string{
"", // an auto-created region for the goroutine 3
"taskless.region",
"task0.region0",
"task0.region1",
"task0.region2",
}
var gotRegions []string
for regionID := range res.regions {
gotRegions = append(gotRegions, regionID.Type)
}
sort.Strings(wantRegions)
sort.Strings(gotRegions)
if !reflect.DeepEqual(gotRegions, wantRegions) {
t.Errorf("got regions %q, want regions %q", gotRegions, wantRegions)
}
}
// prog1 creates a task hierarchy consisting of three tasks.
func prog1() {
ctx := context.Background()
ctx1, task1 := trace.NewTask(ctx, "task1")
defer task1.End()
trace.WithRegion(ctx1, "task1.region", func() {
ctx2, task2 := trace.NewTask(ctx1, "task2")
defer task2.End()
trace.WithRegion(ctx2, "task2.region", func() {
ctx3, task3 := trace.NewTask(ctx2, "task3")
defer task3.End()
trace.WithRegion(ctx3, "task3.region", func() {
})
})
})
}
func TestAnalyzeAnnotationTaskTree(t *testing.T) {
// Run prog1 and capture the execution trace.
if err := traceProgram(t, prog1, "TestAnalyzeAnnotationTaskTree"); err != nil {
t.Fatalf("failed to trace the program: %v", err)
}
res, err := analyzeAnnotations()
if err != nil {
t.Fatalf("failed to analyzeAnnotations: %v", err)
}
tasks := res.tasks
// For prog0, we expect
// - task with name = "", with taskless.region in regions.
// - task with name = "task0", with three regions.
wantTasks := map[string]struct {
parent string
children []string
regions []string
}{
"task1": {
parent: "",
children: []string{"task2"},
regions: []string{"task1.region"},
},
"task2": {
parent: "task1",
children: []string{"task3"},
regions: []string{"task2.region"},
},
"task3": {
parent: "task2",
children: nil,
regions: []string{"task3.region"},
},
}
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(regionNames(task), want.regions) {
t.Errorf("got %v; want %+v", task, want)
}
}
if len(wantTasks) > 0 {
t.Errorf("no more tasks; want %+v", wantTasks)
}
}
// prog2 starts two tasks; "taskWithGC" that overlaps with GC
// and "taskWithoutGC" that doesn't. In order to run this reliably,
// the caller needs to set up to prevent GC from running automatically.
// prog2 returns the upper-bound gc time that overlaps with the first task.
func prog2() (gcTime time.Duration) {
ch := make(chan bool)
ctx1, task := trace.NewTask(context.Background(), "taskWithGC")
trace.WithRegion(ctx1, "taskWithGC.region1", func() {
go func() {
defer trace.StartRegion(ctx1, "taskWithGC.region2").End()
<-ch
}()
s := time.Now()
debug.FreeOSMemory() // task1 affected by gc
gcTime = time.Since(s)
close(ch)
})
task.End()
ctx2, task2 := trace.NewTask(context.Background(), "taskWithoutGC")
trace.WithRegion(ctx2, "taskWithoutGC.region1", func() {
// do nothing.
})
task2.End()
return gcTime
}
func TestAnalyzeAnnotationGC(t *testing.T) {
err := traceProgram(t, func() {
oldGC := debug.SetGCPercent(10000) // gc, and effectively disable GC
defer debug.SetGCPercent(oldGC)
prog2()
}, "TestAnalyzeAnnotationGC")
if err != nil {
t.Fatalf("failed to trace the program: %v", err)
}
res, err := analyzeAnnotations()
if err != nil {
t.Fatalf("failed to analyzeAnnotations: %v", err)
}
// Check collected GC Start events are all sorted and non-overlapping.
lastTS := int64(0)
for i, ev := range res.gcEvents {
if ev.Type != traceparser.EvGCStart {
t.Errorf("unwanted event in gcEvents: %v", ev)
}
if i > 0 && lastTS > ev.Ts {
t.Errorf("overlapping GC events:\n%d: %v\n%d: %v", i-1, res.gcEvents[i-1], i, res.gcEvents[i])
}
if ev.Link != nil {
lastTS = ev.Link.Ts
}
}
// Check whether only taskWithGC reports overlapping duration.
for _, task := range res.tasks {
got := task.overlappingGCDuration(res.gcEvents)
switch task.name {
case "taskWithoutGC":
if got != 0 {
t.Errorf("%s reported %v as overlapping GC time; want 0: %v", task.name, got, task)
}
case "taskWithGC":
upperBound := task.duration()
// TODO(hyangah): a tighter upper bound is gcTime, but
// use of it will make the test flaky due to the issue
// described in golang.org/issue/16755. Tighten the upper
// bound when the issue with the timestamp computed
// based on clockticks is resolved.
if got <= 0 || got > upperBound {
t.Errorf("%s reported %v as overlapping GC time; want (0, %v):\n%v", task.name, got, upperBound, task)
buf := new(bytes.Buffer)
fmt.Fprintln(buf, "GC Events")
for _, ev := range res.gcEvents {
fmt.Fprintf(buf, " %s -> %s\n", ev, ev.Link)
}
fmt.Fprintln(buf, "Events in Task")
for i, ev := range task.events {
fmt.Fprintf(buf, " %d: %s\n", i, ev)
}
t.Logf("\n%s", buf)
}
}
}
}
// 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.
//
// If savetraces flag is set, the captured trace will be saved in the named file.
func traceProgram(t *testing.T, f func(), name string) error {
t.Helper()
buf := new(bytes.Buffer)
if err := trace.Start(buf); err != nil {
return err
}
f()
trace.Stop()
saveTrace(buf, name)
res, err := traceparser.Parse(buf, name+".faketrace")
if err == traceparser.ErrTimeOrder {
t.Skipf("skipping due to golang.org/issue/16755: %v", err)
} else if err != nil {
return err
}
swapLoaderData(res, err)
return nil
}
func regionNames(task *taskDesc) (ret []string) {
for _, s := range task.regions {
ret = append(ret, s.Name)
}
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.
loader.res = res
loader.err = err
analyzeGoroutines(nil) // fool gsInit once.
gs = traceparser.GoroutineStats(res.Events)
}
func saveTrace(buf *bytes.Buffer, name string) {
if !*saveTraces {
return
}
if err := os.WriteFile(name+".trace", buf.Bytes(), 0600); err != nil {
panic(fmt.Errorf("failed to write trace file: %v", err))
}
}
相关信息
相关文章
0
赞
热门推荐
-
2、 - 优质文章
-
3、 gate.io
-
6、 golang
-
7、 openharmony