trace_cgo_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  //go:build cgo
     6  
     7  package runtime_test
     8  
     9  import (
    10  	"bytes"
    11  	"fmt"
    12  	"internal/goexperiment"
    13  	"internal/testenv"
    14  	"internal/trace"
    15  	tracev2 "internal/trace/v2"
    16  	"io"
    17  	"os"
    18  	"runtime"
    19  	"strings"
    20  	"testing"
    21  )
    22  
    23  // TestTraceUnwindCGO verifies that trace events emitted in cgo callbacks
    24  // produce the same stack traces and don't cause any crashes regardless of
    25  // tracefpunwindoff being set to 0 or 1.
    26  func TestTraceUnwindCGO(t *testing.T) {
    27  	if *flagQuick {
    28  		t.Skip("-quick")
    29  	}
    30  	testenv.MustHaveGoBuild(t)
    31  	t.Parallel()
    32  
    33  	exe, err := buildTestProg(t, "testprogcgo")
    34  	if err != nil {
    35  		t.Fatal(err)
    36  	}
    37  
    38  	wantLogs := []string{
    39  		"goCalledFromC",
    40  		"goCalledFromCThread",
    41  	}
    42  	logs := make(map[string]*trace.Event)
    43  	for _, category := range wantLogs {
    44  		logs[category] = nil
    45  	}
    46  	logsV2 := make(map[string]*tracev2.Event)
    47  	for _, category := range wantLogs {
    48  		logsV2[category] = nil
    49  	}
    50  	for _, tracefpunwindoff := range []int{1, 0} {
    51  		env := fmt.Sprintf("GODEBUG=tracefpunwindoff=%d", tracefpunwindoff)
    52  		got := runBuiltTestProg(t, exe, "Trace", env)
    53  		prefix, tracePath, found := strings.Cut(got, ":")
    54  		if !found || prefix != "trace path" {
    55  			t.Fatalf("unexpected output:\n%s\n", got)
    56  		}
    57  		defer os.Remove(tracePath)
    58  
    59  		traceData, err := os.ReadFile(tracePath)
    60  		if err != nil {
    61  			t.Fatalf("failed to read trace: %s", err)
    62  		}
    63  		if goexperiment.ExecTracer2 {
    64  			for category := range logs {
    65  				event := mustFindLogV2(t, bytes.NewReader(traceData), category)
    66  				if wantEvent := logsV2[category]; wantEvent == nil {
    67  					logsV2[category] = &event
    68  				} else if got, want := dumpStackV2(&event), dumpStackV2(wantEvent); got != want {
    69  					t.Errorf("%q: got stack:\n%s\nwant stack:\n%s\n", category, got, want)
    70  				}
    71  			}
    72  		} else {
    73  			events := parseTrace(t, bytes.NewReader(traceData))
    74  
    75  			for category := range logs {
    76  				event := mustFindLog(t, events, category)
    77  				if wantEvent := logs[category]; wantEvent == nil {
    78  					logs[category] = event
    79  				} else if got, want := dumpStack(event), dumpStack(wantEvent); got != want {
    80  					t.Errorf("%q: got stack:\n%s\nwant stack:\n%s\n", category, got, want)
    81  				}
    82  			}
    83  		}
    84  	}
    85  }
    86  
    87  // mustFindLog returns the EvUserLog event with the given category in events. It
    88  // fails if no event or multiple events match the category.
    89  func mustFindLog(t *testing.T, events []*trace.Event, category string) *trace.Event {
    90  	t.Helper()
    91  	var candidates []*trace.Event
    92  	for _, e := range events {
    93  		if e.Type == trace.EvUserLog && len(e.SArgs) >= 1 && e.SArgs[0] == category {
    94  			candidates = append(candidates, e)
    95  		}
    96  	}
    97  	if len(candidates) == 0 {
    98  		t.Errorf("could not find log with category: %q", category)
    99  	} else if len(candidates) > 1 {
   100  		t.Errorf("found more than one log with category: %q", category)
   101  	}
   102  	return candidates[0]
   103  }
   104  
   105  // dumpStack returns e.Stk as a string.
   106  func dumpStack(e *trace.Event) string {
   107  	var buf bytes.Buffer
   108  	for _, f := range e.Stk {
   109  		file := strings.TrimPrefix(f.File, runtime.GOROOT())
   110  		fmt.Fprintf(&buf, "%s\n\t%s:%d\n", f.Fn, file, f.Line)
   111  	}
   112  	return buf.String()
   113  }
   114  
   115  // parseTrace parses the given trace or skips the test if the trace is broken
   116  // due to known issues. Partially copied from runtime/trace/trace_test.go.
   117  func parseTrace(t *testing.T, r io.Reader) []*trace.Event {
   118  	res, err := trace.Parse(r, "")
   119  	if err == trace.ErrTimeOrder {
   120  		t.Skipf("skipping trace: %v", err)
   121  	}
   122  	if err != nil {
   123  		t.Fatalf("failed to parse trace: %v", err)
   124  	}
   125  	return res.Events
   126  }
   127  
   128  func mustFindLogV2(t *testing.T, trace io.Reader, category string) tracev2.Event {
   129  	r, err := tracev2.NewReader(trace)
   130  	if err != nil {
   131  		t.Fatalf("bad trace: %v", err)
   132  	}
   133  	var candidates []tracev2.Event
   134  	for {
   135  		ev, err := r.ReadEvent()
   136  		if err == io.EOF {
   137  			break
   138  		}
   139  		if err != nil {
   140  			t.Fatalf("failed to parse trace: %v", err)
   141  		}
   142  		if ev.Kind() == tracev2.EventLog && ev.Log().Category == category {
   143  			candidates = append(candidates, ev)
   144  		}
   145  	}
   146  	if len(candidates) == 0 {
   147  		t.Fatalf("could not find log with category: %q", category)
   148  	} else if len(candidates) > 1 {
   149  		t.Fatalf("found more than one log with category: %q", category)
   150  	}
   151  	return candidates[0]
   152  }
   153  
   154  // dumpStack returns e.Stack() as a string.
   155  func dumpStackV2(e *tracev2.Event) string {
   156  	var buf bytes.Buffer
   157  	e.Stack().Frames(func(f tracev2.StackFrame) bool {
   158  		file := strings.TrimPrefix(f.File, runtime.GOROOT())
   159  		fmt.Fprintf(&buf, "%s\n\t%s:%d\n", f.Func, file, f.Line)
   160  		return true
   161  	})
   162  	return buf.String()
   163  }
   164
View as plain text