reader_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_test
     6  
     7  import (
     8  	"bytes"
     9  	"flag"
    10  	"io"
    11  	"path/filepath"
    12  	"runtime"
    13  	"testing"
    14  	"time"
    15  
    16  	"internal/trace"
    17  	"internal/trace/testtrace"
    18  )
    19  
    20  var (
    21  	logEvents  = flag.Bool("log-events", false, "whether to log high-level events; significantly slows down tests")
    22  	dumpTraces = flag.Bool("dump-traces", false, "dump traces even on success")
    23  	allocFree  = flag.Bool("alloc-free", false, "run alloc/free trace experiment tests")
    24  )
    25  
    26  func TestReaderGolden(t *testing.T) {
    27  	matches, err := filepath.Glob("./testdata/tests/*.test")
    28  	if err != nil {
    29  		t.Fatalf("failed to glob for tests: %v", err)
    30  	}
    31  	for _, testPath := range matches {
    32  		testName, err := filepath.Rel("./testdata", testPath)
    33  		if err != nil {
    34  			t.Fatalf("failed to relativize testdata path: %v", err)
    35  		}
    36  		t.Run(testName, func(t *testing.T) {
    37  			tr, ver, exp, err := testtrace.ParseFile(testPath)
    38  			if err != nil {
    39  				t.Fatalf("failed to parse test file at %s: %v", testPath, err)
    40  			}
    41  			v := testtrace.NewValidator()
    42  			v.GoVersion = ver
    43  			testReader(t, tr, v, exp)
    44  		})
    45  	}
    46  }
    47  
    48  func FuzzReader(f *testing.F) {
    49  	// Currently disabled because the parser doesn't do much validation and most
    50  	// getters can be made to panic. Turn this on once the parser is meant to
    51  	// reject invalid traces.
    52  	const testGetters = false
    53  
    54  	f.Fuzz(func(t *testing.T, b []byte) {
    55  		r, err := trace.NewReader(bytes.NewReader(b))
    56  		if err != nil {
    57  			return
    58  		}
    59  		for {
    60  			ev, err := r.ReadEvent()
    61  			if err != nil {
    62  				break
    63  			}
    64  
    65  			if !testGetters {
    66  				continue
    67  			}
    68  			// Make sure getters don't do anything that panics
    69  			switch ev.Kind() {
    70  			case trace.EventLabel:
    71  				ev.Label()
    72  			case trace.EventLog:
    73  				ev.Log()
    74  			case trace.EventMetric:
    75  				ev.Metric()
    76  			case trace.EventRangeActive, trace.EventRangeBegin:
    77  				ev.Range()
    78  			case trace.EventRangeEnd:
    79  				ev.Range()
    80  				ev.RangeAttributes()
    81  			case trace.EventStateTransition:
    82  				ev.StateTransition()
    83  			case trace.EventRegionBegin, trace.EventRegionEnd:
    84  				ev.Region()
    85  			case trace.EventTaskBegin, trace.EventTaskEnd:
    86  				ev.Task()
    87  			case trace.EventSync:
    88  			case trace.EventStackSample:
    89  			case trace.EventBad:
    90  			}
    91  		}
    92  	})
    93  }
    94  
    95  func testReader(t *testing.T, tr io.Reader, v *testtrace.Validator, exp *testtrace.Expectation) {
    96  	r, err := trace.NewReader(tr)
    97  	if err != nil {
    98  		if err := exp.Check(err); err != nil {
    99  			t.Error(err)
   100  		}
   101  		return
   102  	}
   103  	for {
   104  		ev, err := r.ReadEvent()
   105  		if err == io.EOF {
   106  			break
   107  		}
   108  		v.GoVersion = r.GoVersion()
   109  		if runtime.GOOS == "windows" || runtime.GOARCH == "wasm" {
   110  			v.SkipClockSnapshotChecks()
   111  		}
   112  		if err != nil {
   113  			if err := exp.Check(err); err != nil {
   114  				t.Error(err)
   115  			}
   116  			return
   117  		}
   118  		if *logEvents {
   119  			t.Log(ev.String())
   120  		}
   121  		if err := v.Event(ev); err != nil {
   122  			t.Error(err)
   123  		}
   124  	}
   125  	if err := exp.Check(nil); err != nil {
   126  		t.Error(err)
   127  	}
   128  }
   129  
   130  func TestTraceGenSync(t *testing.T) {
   131  	type sync struct {
   132  		Time          trace.Time
   133  		ClockSnapshot *trace.ClockSnapshot
   134  	}
   135  	runTest := func(testName string, wantSyncs []sync) {
   136  		t.Run(testName, func(t *testing.T) {
   137  			testPath := "testdata/tests/" + testName
   138  			r, _, _, err := testtrace.ParseFile(testPath)
   139  			if err != nil {
   140  				t.Fatalf("malformed test %s: bad trace file: %v", testPath, err)
   141  			}
   142  			tr, err := trace.NewReader(r)
   143  			if err != nil {
   144  				t.Fatalf("malformed test %s: bad trace file: %v", testPath, err)
   145  			}
   146  			var syncEvents []trace.Event
   147  			for {
   148  				ev, err := tr.ReadEvent()
   149  				if err == io.EOF {
   150  					break
   151  				}
   152  				if err != nil {
   153  					t.Fatalf("malformed test %s: bad trace file: %v", testPath, err)
   154  				}
   155  				if ev.Kind() == trace.EventSync {
   156  					syncEvents = append(syncEvents, ev)
   157  				}
   158  			}
   159  
   160  			if got, want := len(syncEvents), len(wantSyncs); got != want {
   161  				t.Errorf("got %d sync events, want %d", got, want)
   162  			}
   163  
   164  			for i, want := range wantSyncs {
   165  				got := syncEvents[i]
   166  				gotSync := syncEvents[i].Sync()
   167  				if got.Time() != want.Time {
   168  					t.Errorf("sync=%d got time %d, want %d", i+1, got.Time(), want.Time)
   169  				}
   170  				if gotSync.ClockSnapshot == nil && want.ClockSnapshot == nil {
   171  					continue
   172  				}
   173  				if gotSync.ClockSnapshot.Trace != want.ClockSnapshot.Trace {
   174  					t.Errorf("sync=%d got trace time %d, want %d", i+1, gotSync.ClockSnapshot.Trace, want.ClockSnapshot.Trace)
   175  				}
   176  				if !gotSync.ClockSnapshot.Wall.Equal(want.ClockSnapshot.Wall) {
   177  					t.Errorf("sync=%d got wall time %s, want %s", i+1, gotSync.ClockSnapshot.Wall, want.ClockSnapshot.Wall)
   178  				}
   179  				if gotSync.ClockSnapshot.Mono != want.ClockSnapshot.Mono {
   180  					t.Errorf("sync=%d got mono time %d, want %d", i+1, gotSync.ClockSnapshot.Mono, want.ClockSnapshot.Mono)
   181  				}
   182  			}
   183  		})
   184  	}
   185  
   186  	runTest("go123-sync.test", []sync{
   187  		{10, nil},
   188  		{40, nil},
   189  		// The EvFrequency batch for generation 3 is emitted at trace.Time(80),
   190  		// but 60 is the minTs of the generation, see b30 in the go generator.
   191  		{60, nil},
   192  		{63, nil},
   193  	})
   194  
   195  	runTest("go125-sync.test", []sync{
   196  		{9, &trace.ClockSnapshot{Trace: 10, Mono: 99, Wall: time.Date(2025, 2, 28, 15, 4, 9, 123, time.UTC)}},
   197  		{38, &trace.ClockSnapshot{Trace: 40, Mono: 199, Wall: time.Date(2025, 2, 28, 15, 4, 10, 123, time.UTC)}},
   198  		{58, &trace.ClockSnapshot{Trace: 60, Mono: 299, Wall: time.Date(2025, 2, 28, 15, 4, 11, 123, time.UTC)}},
   199  		{83, nil},
   200  	})
   201  }
   202
View as plain text