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