annotation_test.go

     1  // Copyright 2018 The Go Authors. All rights reserved.
     2  // Use of this source code is governed by a BSD-style
     3  // license that can be found in the LICENSE file.
     4  
     5  package trace_test
     6  
     7  import (
     8  	"bytes"
     9  	"context"
    10  	"fmt"
    11  	"internal/goexperiment"
    12  	"internal/trace"
    13  	"reflect"
    14  	. "runtime/trace"
    15  	"strings"
    16  	"sync"
    17  	"testing"
    18  )
    19  
    20  func BenchmarkStartRegion(b *testing.B) {
    21  	b.ReportAllocs()
    22  	ctx, task := NewTask(context.Background(), "benchmark")
    23  	defer task.End()
    24  
    25  	b.RunParallel(func(pb *testing.PB) {
    26  		for pb.Next() {
    27  			StartRegion(ctx, "region").End()
    28  		}
    29  	})
    30  }
    31  
    32  func BenchmarkNewTask(b *testing.B) {
    33  	b.ReportAllocs()
    34  	pctx, task := NewTask(context.Background(), "benchmark")
    35  	defer task.End()
    36  
    37  	b.RunParallel(func(pb *testing.PB) {
    38  		for pb.Next() {
    39  			_, task := NewTask(pctx, "task")
    40  			task.End()
    41  		}
    42  	})
    43  }
    44  
    45  func TestUserTaskRegion(t *testing.T) {
    46  	if goexperiment.ExecTracer2 {
    47  		// An equivalent test exists in internal/trace/v2.
    48  		t.Skip("skipping because this test is incompatible with the new tracer")
    49  	}
    50  	if IsEnabled() {
    51  		t.Skip("skipping because -test.trace is set")
    52  	}
    53  	bgctx, cancel := context.WithCancel(context.Background())
    54  	defer cancel()
    55  
    56  	preExistingRegion := StartRegion(bgctx, "pre-existing region")
    57  
    58  	buf := new(bytes.Buffer)
    59  	if err := Start(buf); err != nil {
    60  		t.Fatalf("failed to start tracing: %v", err)
    61  	}
    62  
    63  	// Beginning of traced execution
    64  	var wg sync.WaitGroup
    65  	ctx, task := NewTask(bgctx, "task0") // EvUserTaskCreate("task0")
    66  	wg.Add(1)
    67  	go func() {
    68  		defer wg.Done()
    69  		defer task.End() // EvUserTaskEnd("task0")
    70  
    71  		WithRegion(ctx, "region0", func() {
    72  			// EvUserRegionCreate("region0", start)
    73  			WithRegion(ctx, "region1", func() {
    74  				Log(ctx, "key0", "0123456789abcdef") // EvUserLog("task0", "key0", "0....f")
    75  			})
    76  			// EvUserRegion("region0", end)
    77  		})
    78  	}()
    79  
    80  	wg.Wait()
    81  
    82  	preExistingRegion.End()
    83  	postExistingRegion := StartRegion(bgctx, "post-existing region")
    84  
    85  	// End of traced execution
    86  	Stop()
    87  
    88  	postExistingRegion.End()
    89  
    90  	saveTrace(t, buf, "TestUserTaskRegion")
    91  	res, err := trace.Parse(buf, "")
    92  	if err == trace.ErrTimeOrder {
    93  		// golang.org/issues/16755
    94  		t.Skipf("skipping trace: %v", err)
    95  	}
    96  	if err != nil {
    97  		t.Fatalf("Parse failed: %v", err)
    98  	}
    99  
   100  	// Check whether we see all user annotation related records in order
   101  	type testData struct {
   102  		typ     byte
   103  		strs    []string
   104  		args    []uint64
   105  		setLink bool
   106  	}
   107  
   108  	var got []testData
   109  	tasks := map[uint64]string{}
   110  	for _, e := range res.Events {
   111  		t.Logf("%s", e)
   112  		switch e.Type {
   113  		case trace.EvUserTaskCreate:
   114  			taskName := e.SArgs[0]
   115  			got = append(got, testData{trace.EvUserTaskCreate, []string{taskName}, nil, e.Link != nil})
   116  			if e.Link != nil && e.Link.Type != trace.EvUserTaskEnd {
   117  				t.Errorf("Unexpected linked event %q->%q", e, e.Link)
   118  			}
   119  			tasks[e.Args[0]] = taskName
   120  		case trace.EvUserLog:
   121  			key, val := e.SArgs[0], e.SArgs[1]
   122  			taskName := tasks[e.Args[0]]
   123  			got = append(got, testData{trace.EvUserLog, []string{taskName, key, val}, nil, e.Link != nil})
   124  		case trace.EvUserTaskEnd:
   125  			taskName := tasks[e.Args[0]]
   126  			got = append(got, testData{trace.EvUserTaskEnd, []string{taskName}, nil, e.Link != nil})
   127  			if e.Link != nil && e.Link.Type != trace.EvUserTaskCreate {
   128  				t.Errorf("Unexpected linked event %q->%q", e, e.Link)
   129  			}
   130  		case trace.EvUserRegion:
   131  			taskName := tasks[e.Args[0]]
   132  			regionName := e.SArgs[0]
   133  			got = append(got, testData{trace.EvUserRegion, []string{taskName, regionName}, []uint64{e.Args[1]}, e.Link != nil})
   134  			if e.Link != nil && (e.Link.Type != trace.EvUserRegion || e.Link.SArgs[0] != regionName) {
   135  				t.Errorf("Unexpected linked event %q->%q", e, e.Link)
   136  			}
   137  		}
   138  	}
   139  	want := []testData{
   140  		{trace.EvUserTaskCreate, []string{"task0"}, nil, true},
   141  		{trace.EvUserRegion, []string{"task0", "region0"}, []uint64{0}, true},
   142  		{trace.EvUserRegion, []string{"task0", "region1"}, []uint64{0}, true},
   143  		{trace.EvUserLog, []string{"task0", "key0", "0123456789abcdef"}, nil, false},
   144  		{trace.EvUserRegion, []string{"task0", "region1"}, []uint64{1}, false},
   145  		{trace.EvUserRegion, []string{"task0", "region0"}, []uint64{1}, false},
   146  		{trace.EvUserTaskEnd, []string{"task0"}, nil, false},
   147  		//  Currently, pre-existing region is not recorded to avoid allocations.
   148  		//  {trace.EvUserRegion, []string{"", "pre-existing region"}, []uint64{1}, false},
   149  		{trace.EvUserRegion, []string{"", "post-existing region"}, []uint64{0}, false},
   150  	}
   151  	if !reflect.DeepEqual(got, want) {
   152  		pretty := func(data []testData) string {
   153  			var s strings.Builder
   154  			for _, d := range data {
   155  				fmt.Fprintf(&s, "\t%+v\n", d)
   156  			}
   157  			return s.String()
   158  		}
   159  		t.Errorf("Got user region related events\n%+v\nwant:\n%+v", pretty(got), pretty(want))
   160  	}
   161  }
   162
View as plain text