blob: 5f89b275dca197b5d70867c459b2528cecf69b9f [file] [log] [blame] [edit]
// Copyright 2023 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.
package main
import (
"bytes"
"encoding/json"
"internal/trace"
"io"
"net/http/httptest"
"os"
"path/filepath"
"slices"
"strconv"
"strings"
"testing"
"time"
"internal/trace/raw"
"internal/trace/traceviewer/format"
)
func TestJSONTraceHandler(t *testing.T) {
testPaths, err := filepath.Glob("./testdata/*.test")
if err != nil {
t.Fatalf("discovering tests: %v", err)
}
for _, testPath := range testPaths {
t.Run(filepath.Base(testPath), func(t *testing.T) {
parsed := getTestTrace(t, testPath)
data := recordJSONTraceHandlerResponse(t, parsed)
// TODO(mknyszek): Check that there's one at most goroutine per proc at any given time.
checkExecutionTimes(t, data)
checkPlausibleHeapMetrics(t, data)
// TODO(mknyszek): Check for plausible thread and goroutine metrics.
checkMetaNamesEmitted(t, data, "process_name", []string{"STATS", "PROCS"})
checkMetaNamesEmitted(t, data, "thread_name", []string{"GC", "Network", "Timers", "Syscalls", "Proc 0"})
checkProcStartStop(t, data)
checkSyscalls(t, data)
checkNetworkUnblock(t, data)
// TODO(mknyszek): Check for flow events.
})
}
}
func checkSyscalls(t *testing.T, data format.Data) {
data = filterViewerTrace(data,
filterEventName("syscall"),
filterStackRootFunc("main.blockingSyscall"))
if len(data.Events) <= 1 {
t.Errorf("got %d events, want > 1", len(data.Events))
}
data = filterViewerTrace(data, filterBlocked("yes"))
if len(data.Events) != 1 {
t.Errorf("got %d events, want 1", len(data.Events))
}
}
type eventFilterFn func(*format.Event, *format.Data) bool
func filterEventName(name string) eventFilterFn {
return func(e *format.Event, _ *format.Data) bool {
return e.Name == name
}
}
// filterGoRoutineName returns an event filter that returns true if the event's
// goroutine name is equal to name.
func filterGoRoutineName(name string) eventFilterFn {
return func(e *format.Event, _ *format.Data) bool {
return parseGoroutineName(e) == name
}
}
// parseGoroutineName returns the goroutine name from the event's name field.
// E.g. if e.Name is "G42 main.cpu10", this returns "main.cpu10".
func parseGoroutineName(e *format.Event) string {
parts := strings.SplitN(e.Name, " ", 2)
if len(parts) != 2 || !strings.HasPrefix(parts[0], "G") {
return ""
}
return parts[1]
}
// filterBlocked returns an event filter that returns true if the event's
// "blocked" argument is equal to blocked.
func filterBlocked(blocked string) eventFilterFn {
return func(e *format.Event, _ *format.Data) bool {
m, ok := e.Arg.(map[string]any)
if !ok {
return false
}
return m["blocked"] == blocked
}
}
// filterStackRootFunc returns an event filter that returns true if the function
// at the root of the stack trace is named name.
func filterStackRootFunc(name string) eventFilterFn {
return func(e *format.Event, data *format.Data) bool {
frames := stackFrames(data, e.Stack)
rootFrame := frames[len(frames)-1]
return strings.HasPrefix(rootFrame, name+":")
}
}
// filterViewerTrace returns a copy of data with only the events that pass all
// of the given filters.
func filterViewerTrace(data format.Data, fns ...eventFilterFn) (filtered format.Data) {
filtered = data
filtered.Events = nil
for _, e := range data.Events {
keep := true
for _, fn := range fns {
keep = keep && fn(e, &filtered)
}
if keep {
filtered.Events = append(filtered.Events, e)
}
}
return
}
func stackFrames(data *format.Data, stackID int) (frames []string) {
for {
frame, ok := data.Frames[strconv.Itoa(stackID)]
if !ok {
return
}
frames = append(frames, frame.Name)
stackID = frame.Parent
}
}
func checkProcStartStop(t *testing.T, data format.Data) {
procStarted := map[uint64]bool{}
for _, e := range data.Events {
if e.Name == "proc start" {
if procStarted[e.TID] == true {
t.Errorf("proc started twice: %d", e.TID)
}
procStarted[e.TID] = true
}
if e.Name == "proc stop" {
if procStarted[e.TID] == false {
t.Errorf("proc stopped twice: %d", e.TID)
}
procStarted[e.TID] = false
}
}
if got, want := len(procStarted), 8; got != want {
t.Errorf("wrong number of procs started/stopped got=%d want=%d", got, want)
}
}
func checkNetworkUnblock(t *testing.T, data format.Data) {
count := 0
var netBlockEv *format.Event
for _, e := range data.Events {
if e.TID == trace.NetpollP && e.Name == "unblock (network)" && e.Phase == "I" && e.Scope == "t" {
count++
netBlockEv = e
}
}
if netBlockEv == nil {
t.Error("failed to find a network unblock")
}
if count == 0 {
t.Errorf("found zero network block events, want at least one")
}
// TODO(mknyszek): Check for the flow of this event to some slice event of a goroutine running.
}
func checkExecutionTimes(t *testing.T, data format.Data) {
cpu10 := sumExecutionTime(filterViewerTrace(data, filterGoRoutineName("main.cpu10")))
cpu20 := sumExecutionTime(filterViewerTrace(data, filterGoRoutineName("main.cpu20")))
if cpu10 <= 0 || cpu20 <= 0 || cpu10 >= cpu20 {
t.Errorf("bad execution times: cpu10=%v, cpu20=%v", cpu10, cpu20)
}
}
func checkMetaNamesEmitted(t *testing.T, data format.Data, category string, want []string) {
t.Helper()
names := metaEventNameArgs(category, data)
for _, wantName := range want {
if !slices.Contains(names, wantName) {
t.Errorf("%s: names=%v, want %q", category, names, wantName)
}
}
}
func metaEventNameArgs(category string, data format.Data) (names []string) {
for _, e := range data.Events {
if e.Name == category && e.Phase == "M" {
names = append(names, e.Arg.(map[string]any)["name"].(string))
}
}
return
}
func checkPlausibleHeapMetrics(t *testing.T, data format.Data) {
hms := heapMetrics(data)
var nonZeroAllocated, nonZeroNextGC bool
for _, hm := range hms {
if hm.Allocated > 0 {
nonZeroAllocated = true
}
if hm.NextGC > 0 {
nonZeroNextGC = true
}
}
if !nonZeroAllocated {
t.Errorf("nonZeroAllocated=%v, want true", nonZeroAllocated)
}
if !nonZeroNextGC {
t.Errorf("nonZeroNextGC=%v, want true", nonZeroNextGC)
}
}
func heapMetrics(data format.Data) (metrics []format.HeapCountersArg) {
for _, e := range data.Events {
if e.Phase == "C" && e.Name == "Heap" {
j, _ := json.Marshal(e.Arg)
var metric format.HeapCountersArg
json.Unmarshal(j, &metric)
metrics = append(metrics, metric)
}
}
return
}
func recordJSONTraceHandlerResponse(t *testing.T, parsed *parsedTrace) format.Data {
h := JSONTraceHandler(parsed)
recorder := httptest.NewRecorder()
r := httptest.NewRequest("GET", "/jsontrace", nil)
h.ServeHTTP(recorder, r)
var data format.Data
if err := json.Unmarshal(recorder.Body.Bytes(), &data); err != nil {
t.Fatal(err)
}
return data
}
func sumExecutionTime(data format.Data) (sum time.Duration) {
for _, e := range data.Events {
sum += time.Duration(e.Dur) * time.Microsecond
}
return
}
func getTestTrace(t *testing.T, testPath string) *parsedTrace {
t.Helper()
// First read in the text trace and write it out as bytes.
f, err := os.Open(testPath)
if err != nil {
t.Fatalf("failed to open test %s: %v", testPath, err)
}
r, err := raw.NewTextReader(f)
if err != nil {
t.Fatalf("failed to read test %s: %v", testPath, err)
}
var trace bytes.Buffer
w, err := raw.NewWriter(&trace, r.Version())
if err != nil {
t.Fatalf("failed to write out test %s: %v", testPath, err)
}
for {
ev, err := r.ReadEvent()
if err == io.EOF {
break
}
if err != nil {
t.Fatalf("failed to read test %s: %v", testPath, err)
}
if err := w.WriteEvent(ev); err != nil {
t.Fatalf("failed to write out test %s: %v", testPath, err)
}
}
// Parse the test trace.
parsed, err := parseTrace(&trace, int64(trace.Len()))
if err != nil {
t.Fatalf("failed to parse trace: %v", err)
}
return parsed
}