src/internal/trace/goroutinesv2_test.go

   1 // Copyright 2023 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
   6
   7 import (
   8         tracev2 "internal/trace/v2"
   9         "internal/trace/v2/testtrace"
  10         "testing"
  11 )
  12
  13 func TestSummarizeGoroutinesTrace(t *testing.T) {
  14         summaries := summarizeTraceTest(t, "v2/testdata/tests/go122-gc-stress.test")
  15         var (
  16                 hasSchedWaitTime    bool
  17                 hasSyncBlockTime    bool
  18                 hasGCMarkAssistTime bool
  19         )
  20         for _, summary := range summaries {
  21                 basicSummaryChecks(t, summary)
  22                 hasSchedWaitTime = hasSchedWaitTime || summary.SchedWaitTime > 0
  23                 if dt, ok := summary.BlockTimeByReason["sync"]; ok && dt > 0 {
  24                         hasSyncBlockTime = true
  25                 }
  26                 if dt, ok := summary.RangeTime["GC mark assist"]; ok && dt > 0 {
  27                         hasGCMarkAssistTime = true
  28                 }
  29         }
  30         if !hasSchedWaitTime {
  31                 t.Error("missing sched wait time")
  32         }
  33         if !hasSyncBlockTime {
  34                 t.Error("missing sync block time")
  35         }
  36         if !hasGCMarkAssistTime {
  37                 t.Error("missing GC mark assist time")
  38         }
  39 }
  40
  41 func TestSummarizeGoroutinesRegionsTrace(t *testing.T) {
  42         summaries := summarizeTraceTest(t, "v2/testdata/tests/go122-annotations.test")
  43         type region struct {
  44                 startKind tracev2.EventKind
  45                 endKind   tracev2.EventKind
  46         }
  47         wantRegions := map[string]region{
  48                 // N.B. "pre-existing region" never even makes it into the trace.
  49                 //
  50                 // TODO(mknyszek): Add test case for end-without-a-start, which can happen at
  51                 // a generation split only.
  52                 "":                     {tracev2.EventStateTransition, tracev2.EventStateTransition}, // Task inheritance marker.
  53                 "task0 region":         {tracev2.EventRegionBegin, tracev2.EventBad},
  54                 "region0":              {tracev2.EventRegionBegin, tracev2.EventRegionEnd},
  55                 "region1":              {tracev2.EventRegionBegin, tracev2.EventRegionEnd},
  56                 "unended region":       {tracev2.EventRegionBegin, tracev2.EventStateTransition},
  57                 "post-existing region": {tracev2.EventRegionBegin, tracev2.EventBad},
  58         }
  59         for _, summary := range summaries {
  60                 basicSummaryChecks(t, summary)
  61                 for _, region := range summary.Regions {
  62                         want, ok := wantRegions[region.Name]
  63                         if !ok {
  64                                 continue
  65                         }
  66                         checkRegionEvents(t, want.startKind, want.endKind, summary.ID, region)
  67                         delete(wantRegions, region.Name)
  68                 }
  69         }
  70         if len(wantRegions) != 0 {
  71                 t.Errorf("failed to find regions: %#v", wantRegions)
  72         }
  73 }
  74
  75 func basicSummaryChecks(t *testing.T, summary *GoroutineSummary) {
  76         if summary.ID == tracev2.NoGoroutine {
  77                 t.Error("summary found for no goroutine")
  78                 return
  79         }
  80         if (summary.StartTime != 0 && summary.CreationTime > summary.StartTime) ||
  81                 (summary.StartTime != 0 && summary.EndTime != 0 && summary.StartTime > summary.EndTime) {
  82                 t.Errorf("bad summary creation/start/end times for G %d: creation=%d start=%d end=%d", summary.ID, summary.CreationTime, summary.StartTime, summary.EndTime)
  83         }
  84         if (summary.PC != 0 && summary.Name == "") || (summary.PC == 0 && summary.Name != "") {
  85                 t.Errorf("bad name and/or PC for G %d: pc=0x%x name=%q", summary.ID, summary.PC, summary.Name)
  86         }
  87         basicGoroutineExecStatsChecks(t, &summary.GoroutineExecStats)
  88         for _, region := range summary.Regions {
  89                 basicGoroutineExecStatsChecks(t, &region.GoroutineExecStats)
  90         }
  91 }
  92
  93 func summarizeTraceTest(t *testing.T, testPath string) map[tracev2.GoID]*GoroutineSummary {
  94         r, _, err := testtrace.ParseFile(testPath)
  95         if err != nil {
  96                 t.Fatalf("malformed test %s: bad trace file: %v", testPath, err)
  97         }
  98         summaries, err := SummarizeGoroutines(r)
  99         if err != nil {
 100                 t.Fatalf("failed to process trace %s: %v", testPath, err)
 101         }
 102         return summaries
 103 }
 104
 105 func checkRegionEvents(t *testing.T, wantStart, wantEnd tracev2.EventKind, goid tracev2.GoID, region *UserRegionSummary) {
 106         switch wantStart {
 107         case tracev2.EventBad:
 108                 if region.Start != nil {
 109                         t.Errorf("expected nil region start event, got\n%s", region.Start.String())
 110                 }
 111         case tracev2.EventStateTransition, tracev2.EventRegionBegin:
 112                 if region.Start == nil {
 113                         t.Error("expected non-nil region start event, got nil")
 114                 }
 115                 kind := region.Start.Kind()
 116                 if kind != wantStart {
 117                         t.Errorf("wanted region start event %s, got %s", wantStart, kind)
 118                 }
 119                 if kind == tracev2.EventRegionBegin {
 120                         if region.Start.Region().Type != region.Name {
 121                                 t.Errorf("region name mismatch: event has %s, summary has %s", region.Start.Region().Type, region.Name)
 122                         }
 123                 } else {
 124                         st := region.Start.StateTransition()
 125                         if st.Resource.Kind != tracev2.ResourceGoroutine {
 126                                 t.Errorf("found region start event for the wrong resource: %s", st.Resource)
 127                         }
 128                         if st.Resource.Goroutine() != goid {
 129                                 t.Errorf("found region start event for the wrong resource: wanted goroutine %d, got %s", goid, st.Resource)
 130                         }
 131                         if old, _ := st.Goroutine(); old != tracev2.GoNotExist && old != tracev2.GoUndetermined {
 132                                 t.Errorf("expected transition from GoNotExist or GoUndetermined, got transition from %s instead", old)
 133                         }
 134                 }
 135         default:
 136                 t.Errorf("unexpected want start event type: %s", wantStart)
 137         }
 138
 139         switch wantEnd {
 140         case tracev2.EventBad:
 141                 if region.End != nil {
 142                         t.Errorf("expected nil region end event, got\n%s", region.End.String())
 143                 }
 144         case tracev2.EventStateTransition, tracev2.EventRegionEnd:
 145                 if region.End == nil {
 146                         t.Error("expected non-nil region end event, got nil")
 147                 }
 148                 kind := region.End.Kind()
 149                 if kind != wantEnd {
 150                         t.Errorf("wanted region end event %s, got %s", wantEnd, kind)
 151                 }
 152                 if kind == tracev2.EventRegionEnd {
 153                         if region.End.Region().Type != region.Name {
 154                                 t.Errorf("region name mismatch: event has %s, summary has %s", region.End.Region().Type, region.Name)
 155                         }
 156                 } else {
 157                         st := region.End.StateTransition()
 158                         if st.Resource.Kind != tracev2.ResourceGoroutine {
 159                                 t.Errorf("found region end event for the wrong resource: %s", st.Resource)
 160                         }
 161                         if st.Resource.Goroutine() != goid {
 162                                 t.Errorf("found region end event for the wrong resource: wanted goroutine %d, got %s", goid, st.Resource)
 163                         }
 164                         if _, new := st.Goroutine(); new != tracev2.GoNotExist {
 165                                 t.Errorf("expected transition to GoNotExist, got transition to %s instead", new)
 166                         }
 167                 }
 168         default:
 169                 t.Errorf("unexpected want end event type: %s", wantEnd)
 170         }
 171 }
 172
 173 func basicGoroutineExecStatsChecks(t *testing.T, stats *GoroutineExecStats) {
 174         if stats.ExecTime < 0 {
 175                 t.Error("found negative ExecTime")
 176         }
 177         if stats.SchedWaitTime < 0 {
 178                 t.Error("found negative SchedWaitTime")
 179         }
 180         if stats.SyscallTime < 0 {
 181                 t.Error("found negative SyscallTime")
 182         }
 183         if stats.SyscallBlockTime < 0 {
 184                 t.Error("found negative SyscallBlockTime")
 185         }
 186         if stats.TotalTime < 0 {
 187                 t.Error("found negative TotalTime")
 188         }
 189         for reason, dt := range stats.BlockTimeByReason {
 190                 if dt < 0 {
 191                         t.Errorf("found negative BlockTimeByReason for %s", reason)
 192                 }
 193         }
 194         for name, dt := range stats.RangeTime {
 195                 if dt < 0 {
 196                         t.Errorf("found negative RangeTime for range %s", name)
 197                 }
 198         }
 199 }
 200
 201 func TestRelatedGoroutinesV2Trace(t *testing.T) {
 202         testPath := "v2/testdata/tests/go122-gc-stress.test"
 203         r, _, err := testtrace.ParseFile(testPath)
 204         if err != nil {
 205                 t.Fatalf("malformed test %s: bad trace file: %v", testPath, err)
 206         }
 207         targetg := tracev2.GoID(86)
 208         got, err := RelatedGoroutinesV2(r, targetg)
 209         if err != nil {
 210                 t.Fatalf("failed to find related goroutines for %s: %v", testPath, err)
 211         }
 212         want := map[tracev2.GoID]struct{}{
 213                 tracev2.GoID(86):  struct{}{}, // N.B. Result includes target.
 214                 tracev2.GoID(71):  struct{}{},
 215                 tracev2.GoID(25):  struct{}{},
 216                 tracev2.GoID(122): struct{}{},
 217         }
 218         for goid := range got {
 219                 if _, ok := want[goid]; ok {
 220                         delete(want, goid)
 221                 } else {
 222                         t.Errorf("unexpected goroutine %d found in related goroutines for %d in test %s", goid, targetg, testPath)
 223                 }
 224         }
 225         if len(want) != 0 {
 226                 for goid := range want {
 227                         t.Errorf("failed to find related goroutine %d for goroutine %d in test %s", goid, targetg, testPath)
 228                 }
 229         }
 230 }