codekingpro/portable-devtools

1// Copyright 2014 The Go Authors. All rights reserved.2// Use of this source code is governed by a BSD-style3// license that can be found in the LICENSE file.4 5package main6 7import (8	"cmd/internal/browser"9	"cmd/internal/telemetry/counter"10	"cmp"11	"flag"12	"fmt"13	"internal/trace"14	"internal/trace/raw"15	"internal/trace/tracev2"16	"internal/trace/traceviewer"17	"io"18	"log"19	"net"20	"net/http"21	_ "net/http/pprof" // Required to use pprof22	"os"23	"slices"24	"sync/atomic"25	"text/tabwriter"26	"time"27)28 29const usageMessage = "" +30	`Usage of 'go tool trace':31Given a trace file produced by 'go test':32	go test -trace=trace.out pkg33 34Open a web browser displaying trace:35	go tool trace [flags] [pkg.test] trace.out36 37Generate a pprof-like profile from the trace:38    go tool trace -pprof=TYPE [pkg.test] trace.out39 40[pkg.test] argument is required for traces produced by Go 1.6 and below.41Go 1.7 does not require the binary argument.42 43Supported profile types are:44    - net: network blocking profile45    - sync: synchronization blocking profile46    - syscall: syscall blocking profile47    - sched: scheduler latency profile48 49Flags:50	-http=addr: HTTP service address (e.g., ':6060')51	-pprof=type: print a pprof-like profile instead52	-d=mode: print debug info and exit (modes: wire, parsed, footprint)53 54Note that while the various profiles available when launching55'go tool trace' work on every browser, the trace viewer itself56(the 'view trace' page) comes from the Chrome/Chromium project57and is only actively tested on that browser.58`59 60var (61	httpFlag  = flag.String("http", "localhost:0", "HTTP service address (e.g., ':6060')")62	pprofFlag = flag.String("pprof", "", "print a pprof-like profile instead")63	debugFlag = flag.String("d", "", "print debug info and exit (modes: wire, parsed, footprint)")64 65	// The binary file name, left here for serveSVGProfile.66	programBinary string67	traceFile     string68)69 70func main() {71	counter.Open()72	flag.Usage = func() {73		fmt.Fprint(os.Stderr, usageMessage)74		os.Exit(2)75	}76	flag.Parse()77	counter.Inc("trace/invocations")78	counter.CountFlags("trace/flag:", *flag.CommandLine)79 80	// Go 1.7 traces embed symbol info and does not require the binary.81	// But we optionally accept binary as first arg for Go 1.5 traces.82	switch flag.NArg() {83	case 1:84		traceFile = flag.Arg(0)85	case 2:86		programBinary = flag.Arg(0)87		traceFile = flag.Arg(1)88	default:89		flag.Usage()90	}91 92	tracef, err := os.Open(traceFile)93	if err != nil {94		logAndDie(fmt.Errorf("failed to read trace file: %w", err))95	}96	defer tracef.Close()97 98	// Get the size of the trace file.99	fi, err := tracef.Stat()100	if err != nil {101		logAndDie(fmt.Errorf("failed to stat trace file: %v", err))102	}103	traceSize := fi.Size()104 105	// Handle requests for profiles.106	if *pprofFlag != "" {107		parsed, err := parseTrace(tracef, traceSize)108		if err != nil {109			logAndDie(err)110		}111		var f traceviewer.ProfileFunc112		switch *pprofFlag {113		case "net":114			f = pprofByGoroutine(computePprofIO(), parsed)115		case "sync":116			f = pprofByGoroutine(computePprofBlock(), parsed)117		case "syscall":118			f = pprofByGoroutine(computePprofSyscall(), parsed)119		case "sched":120			f = pprofByGoroutine(computePprofSched(), parsed)121		default:122			logAndDie(fmt.Errorf("unknown pprof type %s\n", *pprofFlag))123		}124		records, err := f(&http.Request{})125		if err != nil {126			logAndDie(fmt.Errorf("failed to generate pprof: %v\n", err))127		}128		if err := traceviewer.BuildProfile(records).Write(os.Stdout); err != nil {129			logAndDie(fmt.Errorf("failed to generate pprof: %v\n", err))130		}131		logAndDie(nil)132	}133 134	// Debug flags.135	if *debugFlag != "" {136		switch *debugFlag {137		case "parsed":138			logAndDie(debugProcessedEvents(tracef))139		case "wire":140			logAndDie(debugRawEvents(tracef))141		case "footprint":142			logAndDie(debugEventsFootprint(tracef))143		default:144			logAndDie(fmt.Errorf("invalid debug mode %s, want one of: parsed, wire, footprint", *debugFlag))145		}146	}147 148	ln, err := net.Listen("tcp", *httpFlag)149	if err != nil {150		logAndDie(fmt.Errorf("failed to create server socket: %w", err))151	}152	addr := "http://" + ln.Addr().String()153 154	log.Print("Preparing trace for viewer...")155	parsed, err := parseTraceInteractive(tracef, traceSize)156	if err != nil {157		logAndDie(err)158	}159	// N.B. tracef not needed after this point.160	// We might double-close, but that's fine; we ignore the error.161	tracef.Close()162 163	// Print a nice message for a partial trace.164	if parsed.err != nil {165		log.Printf("Encountered error, but able to proceed. Error: %v", parsed.err)166 167		lost := parsed.size - parsed.valid168		pct := float64(lost) / float64(parsed.size) * 100169		log.Printf("Lost %.2f%% of the latest trace data due to error (%s of %s)", pct, byteCount(lost), byteCount(parsed.size))170	}171 172	log.Print("Splitting trace for viewer...")173	ranges, err := splitTrace(parsed)174	if err != nil {175		logAndDie(err)176	}177 178	log.Printf("Opening browser. Trace viewer is listening on %s", addr)179	browser.Open(addr)180 181	mutatorUtil := func(flags trace.UtilFlags) ([][]trace.MutatorUtil, error) {182		return trace.MutatorUtilizationV2(parsed.events, flags), nil183	}184 185	mux := http.NewServeMux()186 187	// Main endpoint.188	mux.Handle("/", traceviewer.MainHandler([]traceviewer.View{189		{Type: traceviewer.ViewProc, Ranges: ranges},190		// N.B. Use the same ranges for threads. It takes a long time to compute191		// the split a second time, but the makeup of the events are similar enough192		// that this is still a good split.193		{Type: traceviewer.ViewThread, Ranges: ranges},194	}))195 196	// Catapult handlers.197	mux.Handle("/trace", traceviewer.TraceHandler())198	mux.Handle("/jsontrace", JSONTraceHandler(parsed))199	mux.Handle("/static/", traceviewer.StaticHandler())200 201	// Goroutines handlers.202	mux.HandleFunc("/goroutines", GoroutinesHandlerFunc(parsed.summary.Goroutines))203	mux.HandleFunc("/goroutine", GoroutineHandler(parsed.summary.Goroutines))204 205	// MMU handler.206	mux.HandleFunc("/mmu", traceviewer.MMUHandlerFunc(ranges, mutatorUtil))207 208	// Basic pprof endpoints.209	mux.HandleFunc("/io", traceviewer.SVGProfileHandlerFunc(pprofByGoroutine(computePprofIO(), parsed)))210	mux.HandleFunc("/block", traceviewer.SVGProfileHandlerFunc(pprofByGoroutine(computePprofBlock(), parsed)))211	mux.HandleFunc("/syscall", traceviewer.SVGProfileHandlerFunc(pprofByGoroutine(computePprofSyscall(), parsed)))212	mux.HandleFunc("/sched", traceviewer.SVGProfileHandlerFunc(pprofByGoroutine(computePprofSched(), parsed)))213 214	// Region-based pprof endpoints.215	mux.HandleFunc("/regionio", traceviewer.SVGProfileHandlerFunc(pprofByRegion(computePprofIO(), parsed)))216	mux.HandleFunc("/regionblock", traceviewer.SVGProfileHandlerFunc(pprofByRegion(computePprofBlock(), parsed)))217	mux.HandleFunc("/regionsyscall", traceviewer.SVGProfileHandlerFunc(pprofByRegion(computePprofSyscall(), parsed)))218	mux.HandleFunc("/regionsched", traceviewer.SVGProfileHandlerFunc(pprofByRegion(computePprofSched(), parsed)))219 220	// Region endpoints.221	mux.HandleFunc("/userregions", UserRegionsHandlerFunc(parsed))222	mux.HandleFunc("/userregion", UserRegionHandlerFunc(parsed))223 224	// Task endpoints.225	mux.HandleFunc("/usertasks", UserTasksHandlerFunc(parsed))226	mux.HandleFunc("/usertask", UserTaskHandlerFunc(parsed))227 228	err = http.Serve(ln, mux)229	logAndDie(fmt.Errorf("failed to start http server: %w", err))230}231 232func logAndDie(err error) {233	if err == nil {234		os.Exit(0)235	}236	fmt.Fprintf(os.Stderr, "%s\n", err)237	os.Exit(1)238}239 240func parseTraceInteractive(tr io.Reader, size int64) (parsed *parsedTrace, err error) {241	done := make(chan struct{})242	cr := countingReader{r: tr}243	go func() {244		parsed, err = parseTrace(&cr, size)245		done <- struct{}{}246	}()247	ticker := time.NewTicker(5 * time.Second)248progressLoop:249	for {250		select {251		case <-ticker.C:252		case <-done:253			ticker.Stop()254			break progressLoop255		}256		progress := cr.bytesRead.Load()257		pct := float64(progress) / float64(size) * 100258		log.Printf("%s of %s (%.1f%%) processed...", byteCount(progress), byteCount(size), pct)259	}260	return261}262 263type parsedTrace struct {264	events      []trace.Event265	summary     *trace.Summary266	size, valid int64267	err         error268}269 270func parseTrace(rr io.Reader, size int64) (*parsedTrace, error) {271	// Set up the reader.272	cr := countingReader{r: rr}273	r, err := trace.NewReader(&cr)274	if err != nil {275		return nil, fmt.Errorf("failed to create trace reader: %w", err)276	}277 278	// Set up state.279	s := trace.NewSummarizer()280	t := new(parsedTrace)281	var validBytes int64282	var validEvents int283	for {284		ev, err := r.ReadEvent()285		if err == io.EOF {286			validBytes = cr.bytesRead.Load()287			validEvents = len(t.events)288			break289		}290		if err != nil {291			t.err = err292			break293		}294		t.events = append(t.events, ev)295		s.Event(&t.events[len(t.events)-1])296 297		if ev.Kind() == trace.EventSync {298			validBytes = cr.bytesRead.Load()299			validEvents = len(t.events)300		}301	}302 303	// Check to make sure we got at least one good generation.304	if validEvents == 0 {305		return nil, fmt.Errorf("failed to parse any useful part of the trace: %v", t.err)306	}307 308	// Finish off the parsedTrace.309	t.summary = s.Finalize()310	t.valid = validBytes311	t.size = size312	t.events = t.events[:validEvents]313	return t, nil314}315 316func (t *parsedTrace) startTime() trace.Time {317	return t.events[0].Time()318}319 320func (t *parsedTrace) endTime() trace.Time {321	return t.events[len(t.events)-1].Time()322}323 324// splitTrace splits the trace into a number of ranges, each resulting in approx 100 MiB of325// json output (the trace viewer can hardly handle more).326func splitTrace(parsed *parsedTrace) ([]traceviewer.Range, error) {327	// TODO(mknyszek): Split traces by generation by doing a quick first pass over the328	// trace to identify all the generation boundaries.329	s, c := traceviewer.SplittingTraceConsumer(100 << 20) // 100 MiB330	if err := generateTrace(parsed, defaultGenOpts(), c); err != nil {331		return nil, err332	}333	return s.Ranges, nil334}335 336func debugProcessedEvents(trc io.Reader) error {337	tr, err := trace.NewReader(trc)338	if err != nil {339		return err340	}341	for {342		ev, err := tr.ReadEvent()343		if err == io.EOF {344			return nil345		} else if err != nil {346			return err347		}348		fmt.Println(ev.String())349	}350}351 352func debugRawEvents(trc io.Reader) error {353	rr, err := raw.NewReader(trc)354	if err != nil {355		return err356	}357	for {358		ev, err := rr.ReadEvent()359		if err == io.EOF {360			return nil361		} else if err != nil {362			return err363		}364		fmt.Println(ev.String())365	}366}367 368func debugEventsFootprint(trc io.Reader) error {369	cr := countingReader{r: trc}370	tr, err := raw.NewReader(&cr)371	if err != nil {372		return err373	}374	type eventStats struct {375		typ   tracev2.EventType376		count int377		bytes int378	}379	var stats [256]eventStats380	for i := range stats {381		stats[i].typ = tracev2.EventType(i)382	}383	eventsRead := 0384	for {385		e, err := tr.ReadEvent()386		if err == io.EOF {387			break388		}389		if err != nil {390			return err391		}392		s := &stats[e.Ev]393		s.count++394		s.bytes += e.EncodedSize()395		eventsRead++396	}397	slices.SortFunc(stats[:], func(a, b eventStats) int {398		return cmp.Compare(b.bytes, a.bytes)399	})400	specs := tr.Version().Specs()401	w := tabwriter.NewWriter(os.Stdout, 3, 8, 2, ' ', 0)402	fmt.Fprintf(w, "Event\tBytes\t%%\tCount\t%%\n")403	fmt.Fprintf(w, "-\t-\t-\t-\t-\n")404	for i := range stats {405		stat := &stats[i]406		name := ""407		if int(stat.typ) >= len(specs) {408			name = fmt.Sprintf("<unknown (%d)>", stat.typ)409		} else {410			name = specs[stat.typ].Name411		}412		bytesPct := float64(stat.bytes) / float64(cr.bytesRead.Load()) * 100413		countPct := float64(stat.count) / float64(eventsRead) * 100414		fmt.Fprintf(w, "%s\t%d\t%.2f%%\t%d\t%.2f%%\n", name, stat.bytes, bytesPct, stat.count, countPct)415	}416	w.Flush()417	return nil418}419 420type countingReader struct {421	r         io.Reader422	bytesRead atomic.Int64423}424 425func (c *countingReader) Read(buf []byte) (n int, err error) {426	n, err = c.r.Read(buf)427	c.bytesRead.Add(int64(n))428	return n, err429}430 431type byteCount int64432 433func (b byteCount) String() string {434	var suffix string435	var divisor int64436	switch {437	case b < 1<<10:438		suffix = "B"439		divisor = 1440	case b < 1<<20:441		suffix = "KiB"442		divisor = 1 << 10443	case b < 1<<30:444		suffix = "MiB"445		divisor = 1 << 20446	case b < 1<<40:447		suffix = "GiB"448		divisor = 1 << 30449	}450	if divisor == 1 {451		return fmt.Sprintf("%d %s", b, suffix)452	}453	return fmt.Sprintf("%.1f %s", float64(b)/float64(divisor), suffix)454}455