diff options
author | Daniel Baumann <daniel.baumann@progress-linux.org> | 2024-04-16 19:23:18 +0000 |
---|---|---|
committer | Daniel Baumann <daniel.baumann@progress-linux.org> | 2024-04-16 19:23:18 +0000 |
commit | 43a123c1ae6613b3efeed291fa552ecd909d3acf (patch) | |
tree | fd92518b7024bc74031f78a1cf9e454b65e73665 /src/cmd/trace/main.go | |
parent | Initial commit. (diff) | |
download | golang-1.20-43a123c1ae6613b3efeed291fa552ecd909d3acf.tar.xz golang-1.20-43a123c1ae6613b3efeed291fa552ecd909d3acf.zip |
Adding upstream version 1.20.14.upstream/1.20.14upstream
Signed-off-by: Daniel Baumann <daniel.baumann@progress-linux.org>
Diffstat (limited to 'src/cmd/trace/main.go')
-rw-r--r-- | src/cmd/trace/main.go | 410 |
1 files changed, 410 insertions, 0 deletions
diff --git a/src/cmd/trace/main.go b/src/cmd/trace/main.go new file mode 100644 index 0000000..0e4d882 --- /dev/null +++ b/src/cmd/trace/main.go @@ -0,0 +1,410 @@ +// Copyright 2014 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 ( + "bufio" + "cmd/internal/browser" + "flag" + "fmt" + "html/template" + "internal/trace" + "io" + "log" + "net" + "net/http" + "os" + "runtime" + "runtime/debug" + "sync" + + _ "net/http/pprof" // Required to use pprof +) + +const usageMessage = "" + + `Usage of 'go tool trace': +Given a trace file produced by 'go test': + go test -trace=trace.out pkg + +Open a web browser displaying trace: + go tool trace [flags] [pkg.test] trace.out + +Generate a pprof-like profile from the trace: + go tool trace -pprof=TYPE [pkg.test] trace.out + +[pkg.test] argument is required for traces produced by Go 1.6 and below. +Go 1.7 does not require the binary argument. + +Supported profile types are: + - net: network blocking profile + - sync: synchronization blocking profile + - syscall: syscall blocking profile + - sched: scheduler latency profile + +Flags: + -http=addr: HTTP service address (e.g., ':6060') + -pprof=type: print a pprof-like profile instead + -d: print debug info such as parsed events + +Note that while the various profiles available when launching +'go tool trace' work on every browser, the trace viewer itself +(the 'view trace' page) comes from the Chrome/Chromium project +and is only actively tested on that browser. +` + +var ( + httpFlag = flag.String("http", "localhost:0", "HTTP service address (e.g., ':6060')") + pprofFlag = flag.String("pprof", "", "print a pprof-like profile instead") + debugFlag = flag.Bool("d", false, "print debug information such as parsed events list") + + // The binary file name, left here for serveSVGProfile. + programBinary string + traceFile string +) + +func main() { + flag.Usage = func() { + fmt.Fprint(os.Stderr, usageMessage) + os.Exit(2) + } + flag.Parse() + + // Go 1.7 traces embed symbol info and does not require the binary. + // But we optionally accept binary as first arg for Go 1.5 traces. + switch flag.NArg() { + case 1: + traceFile = flag.Arg(0) + case 2: + programBinary = flag.Arg(0) + traceFile = flag.Arg(1) + default: + flag.Usage() + } + + var pprofFunc func(io.Writer, *http.Request) error + switch *pprofFlag { + case "net": + pprofFunc = pprofByGoroutine(computePprofIO) + case "sync": + pprofFunc = pprofByGoroutine(computePprofBlock) + case "syscall": + pprofFunc = pprofByGoroutine(computePprofSyscall) + case "sched": + pprofFunc = pprofByGoroutine(computePprofSched) + } + if pprofFunc != nil { + if err := pprofFunc(os.Stdout, &http.Request{}); err != nil { + dief("failed to generate pprof: %v\n", err) + } + os.Exit(0) + } + if *pprofFlag != "" { + dief("unknown pprof type %s\n", *pprofFlag) + } + + ln, err := net.Listen("tcp", *httpFlag) + if err != nil { + dief("failed to create server socket: %v\n", err) + } + + log.Print("Parsing trace...") + res, err := parseTrace() + if err != nil { + dief("%v\n", err) + } + + if *debugFlag { + trace.Print(res.Events) + os.Exit(0) + } + reportMemoryUsage("after parsing trace") + debug.FreeOSMemory() + + log.Print("Splitting trace...") + ranges = splitTrace(res) + reportMemoryUsage("after spliting trace") + debug.FreeOSMemory() + + addr := "http://" + ln.Addr().String() + log.Printf("Opening browser. Trace viewer is listening on %s", addr) + browser.Open(addr) + + // Start http server. + http.HandleFunc("/", httpMain) + err = http.Serve(ln, nil) + dief("failed to start http server: %v\n", err) +} + +var ranges []Range + +var loader struct { + once sync.Once + res trace.ParseResult + err error +} + +// parseEvents is a compatibility wrapper that returns only +// the Events part of trace.ParseResult returned by parseTrace. +func parseEvents() ([]*trace.Event, error) { + res, err := parseTrace() + if err != nil { + return nil, err + } + return res.Events, err +} + +func parseTrace() (trace.ParseResult, error) { + loader.once.Do(func() { + tracef, err := os.Open(traceFile) + if err != nil { + loader.err = fmt.Errorf("failed to open trace file: %v", err) + return + } + defer tracef.Close() + + // Parse and symbolize. + res, err := trace.Parse(bufio.NewReader(tracef), programBinary) + if err != nil { + loader.err = fmt.Errorf("failed to parse trace: %v", err) + return + } + loader.res = res + }) + return loader.res, loader.err +} + +// httpMain serves the starting page. +func httpMain(w http.ResponseWriter, r *http.Request) { + if err := templMain.Execute(w, ranges); err != nil { + http.Error(w, err.Error(), http.StatusInternalServerError) + return + } +} + +var templMain = template.Must(template.New("").Parse(` +<html> +<style> +/* See https://github.com/golang/pkgsite/blob/master/static/shared/typography/typography.css */ +body { + font-family: -apple-system, BlinkMacSystemFont, 'Segoe UI', Helvetica, Arial, sans-serif, 'Apple Color Emoji', 'Segoe UI Emoji'; + font-size: 1rem; + line-height: normal; + max-width: 9in; + margin: 1em; +} +h1 { font-size: 1.5rem; } +h2 { font-size: 1.375rem; } +h1,h2 { + font-weight: 600; + line-height: 1.25em; + word-break: break-word; +} +p { color: grey85; font-size:85%; } +</style> +<body> +<h1>cmd/trace: the Go trace event viewer</h1> +<p> + This web server provides various visualizations of an event log gathered during + the execution of a Go program that uses the <a href='https://pkg.go.dev/runtime/trace'>runtime/trace</a> package. +</p> + +<h2>Event timelines for running goroutines</h2> +{{if $}} +<p> + Large traces are split into multiple sections of equal data size + (not duration) to avoid overwhelming the visualizer. +</p> +<ul> + {{range $e := $}} + <li><a href="{{$e.URL}}">View trace ({{$e.Name}})</a></li> + {{end}} +</ul> +{{else}} +<ul> + <li><a href="/trace">View trace</a></li> +</ul> +{{end}} +<p> + This view displays a timeline for each of the GOMAXPROCS logical + processors, showing which goroutine (if any) was running on that + logical processor at each moment. + + Each goroutine has an identifying number (e.g. G123), main function, + and color. + + A colored bar represents an uninterrupted span of execution. + + Execution of a goroutine may migrate from one logical processor to another, + causing a single colored bar to be horizontally continuous but + vertically displaced. +</p> +<p> + Clicking on a span reveals information about it, such as its + duration, its causal predecessors and successors, and the stack trace + at the final moment when it yielded the logical processor, for example + because it made a system call or tried to acquire a mutex. + + Directly underneath each bar, a smaller bar or more commonly a fine + vertical line indicates an event occurring during its execution. + Some of these are related to garbage collection; most indicate that + a goroutine yielded its logical processor but then immediately resumed execution + on the same logical processor. Clicking on the event displays the stack trace + at the moment it occurred. +</p> +<p> + The causal relationships between spans of goroutine execution + can be displayed by clicking the Flow Events button at the top. +</p> +<p> + At the top ("STATS"), there are three additional timelines that + display statistical information. + + "Goroutines" is a time series of the count of existing goroutines; + clicking on it displays their breakdown by state at that moment: + running, runnable, or waiting. + + "Heap" is a time series of the amount of heap memory allocated (in orange) + and (in green) the allocation limit at which the next GC cycle will begin. + + "Threads" shows the number of kernel threads in existence: there is + always one kernel thread per logical processor, and additional threads + are created for calls to non-Go code such as a system call or a + function written in C. +</p> +<p> + Above the event trace for the first logical processor are + traces for various runtime-internal events. + + The "GC" bar shows when the garbage collector is running, and in which stage. + Garbage collection may temporarily affect all the logical processors + and the other metrics. + + The "Network", "Timers", and "Syscalls" traces indicate events in + the runtime that cause goroutines to wake up. +</p> +<p> + The visualization allows you to navigate events at scales ranging from several + seconds to a handful of nanoseconds. + + Consult the documentation for the Chromium <a href='https://www.chromium.org/developers/how-tos/trace-event-profiling-tool/'>Trace Event Profiling Tool<a/> + for help navigating the view. +</p> + +<ul> +<li><a href="/goroutines">Goroutine analysis</a></li> +</ul> +<p> + This view displays information about each set of goroutines that + shares the same main function. + + Clicking on a main function shows links to the four types of + blocking profile (see below) applied to that subset of goroutines. + + It also shows a table of specific goroutine instances, with various + execution statistics and a link to the event timeline for each one. + + The timeline displays only the selected goroutine and any others it + interacts with via block/unblock events. (The timeline is + goroutine-oriented rather than logical processor-oriented.) +</p> + +<h2>Profiles</h2> +<p> + Each link below displays a global profile in zoomable graph form as + produced by <a href='https://go.dev/blog/pprof'>pprof</a>'s "web" command. + + In addition there is a link to download the profile for offline + analysis with pprof. + + All four profiles represent causes of delay that prevent a goroutine + from running on a logical processor: because it was waiting for the network, + for a synchronization operation on a mutex or channel, for a system call, + or for a logical processor to become available. +</p> +<ul> +<li><a href="/io">Network blocking profile</a> (<a href="/io?raw=1" download="io.profile">⬇</a>)</li> +<li><a href="/block">Synchronization blocking profile</a> (<a href="/block?raw=1" download="block.profile">⬇</a>)</li> +<li><a href="/syscall">Syscall blocking profile</a> (<a href="/syscall?raw=1" download="syscall.profile">⬇</a>)</li> +<li><a href="/sched">Scheduler latency profile</a> (<a href="/sche?raw=1" download="sched.profile">⬇</a>)</li> +</ul> + +<h2>User-defined tasks and regions</h2> +<p> + The trace API allows a target program to annotate a <a + href='https://pkg.go.dev/runtime/trace#Region'>region</a> of code + within a goroutine, such as a key function, so that its performance + can be analyzed. + + <a href='https://pkg.go.dev/runtime/trace#Log'>Log events</a> may be + associated with a region to record progress and relevant values. + + The API also allows annotation of higher-level + <a href='https://pkg.go.dev/runtime/trace#Task'>tasks</a>, + which may involve work across many goroutines. +</p> +<p> + The links below display, for each region and task, a histogram of its execution times. + + Each histogram bucket contains a sample trace that records the + sequence of events such as goroutine creations, log events, and + subregion start/end times. + + For each task, you can click through to a logical-processor or + goroutine-oriented view showing the tasks and regions on the + timeline. + + Such information may help uncover which steps in a region are + unexpectedly slow, or reveal relationships between the data values + logged in a request and its running time. +</p> +<ul> +<li><a href="/usertasks">User-defined tasks</a></li> +<li><a href="/userregions">User-defined regions</a></li> +</ul> + +<h2>Garbage collection metrics</h2> +<ul> +<li><a href="/mmu">Minimum mutator utilization</a></li> +</ul> +<p> + This chart indicates the maximum GC pause time (the largest x value + for which y is zero), and more generally, the fraction of time that + the processors are available to application goroutines ("mutators"), + for any time window of a specified size, in the worst case. +</p> +</body> +</html> +`)) + +func dief(msg string, args ...any) { + fmt.Fprintf(os.Stderr, msg, args...) + os.Exit(1) +} + +var debugMemoryUsage bool + +func init() { + v := os.Getenv("DEBUG_MEMORY_USAGE") + debugMemoryUsage = v != "" +} + +func reportMemoryUsage(msg string) { + if !debugMemoryUsage { + return + } + var s runtime.MemStats + runtime.ReadMemStats(&s) + w := os.Stderr + fmt.Fprintf(w, "%s\n", msg) + fmt.Fprintf(w, " Alloc:\t%d Bytes\n", s.Alloc) + fmt.Fprintf(w, " Sys:\t%d Bytes\n", s.Sys) + fmt.Fprintf(w, " HeapReleased:\t%d Bytes\n", s.HeapReleased) + fmt.Fprintf(w, " HeapSys:\t%d Bytes\n", s.HeapSys) + fmt.Fprintf(w, " HeapInUse:\t%d Bytes\n", s.HeapInuse) + fmt.Fprintf(w, " HeapAlloc:\t%d Bytes\n", s.HeapAlloc) + var dummy string + fmt.Printf("Enter to continue...") + fmt.Scanf("%s", &dummy) +} |