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

View as plain text