1// Copyright 2014 Google Inc. All Rights Reserved. 2// 3// Licensed under the Apache License, Version 2.0 (the "License"); 4// you may not use this file except in compliance with the License. 5// You may obtain a copy of the License at 6// 7// http://www.apache.org/licenses/LICENSE-2.0 8// 9// Unless required by applicable law or agreed to in writing, software 10// distributed under the License is distributed on an "AS IS" BASIS, 11// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 12// See the License for the specific language governing permissions and 13// limitations under the License. 14 15// Package report summarizes a performance profile into a 16// human-readable report. 17package report 18 19import ( 20 "fmt" 21 "io" 22 "path/filepath" 23 "regexp" 24 "sort" 25 "strconv" 26 "strings" 27 "text/tabwriter" 28 "time" 29 30 "github.com/google/pprof/internal/graph" 31 "github.com/google/pprof/internal/measurement" 32 "github.com/google/pprof/internal/plugin" 33 "github.com/google/pprof/profile" 34) 35 36// Output formats. 37const ( 38 Callgrind = iota 39 Comments 40 Dis 41 Dot 42 List 43 Proto 44 Raw 45 Tags 46 Text 47 TopProto 48 Traces 49 Tree 50 WebList 51) 52 53// Options are the formatting and filtering options used to generate a 54// profile. 55type Options struct { 56 OutputFormat int 57 58 CumSort bool 59 CallTree bool 60 DropNegative bool 61 CompactLabels bool 62 Ratio float64 63 Title string 64 ProfileLabels []string 65 ActiveFilters []string 66 NumLabelUnits map[string]string 67 68 NodeCount int 69 NodeFraction float64 70 EdgeFraction float64 71 72 SampleValue func(s []int64) int64 73 SampleMeanDivisor func(s []int64) int64 74 SampleType string 75 SampleUnit string // Unit for the sample data from the profile. 76 77 OutputUnit string // Units for data formatting in report. 78 79 Symbol *regexp.Regexp // Symbols to include on disassembly report. 80 SourcePath string // Search path for source files. 81 TrimPath string // Paths to trim from source file paths. 82 83 IntelSyntax bool // Whether or not to print assembly in Intel syntax. 84} 85 86// Generate generates a report as directed by the Report. 87func Generate(w io.Writer, rpt *Report, obj plugin.ObjTool) error { 88 o := rpt.options 89 90 switch o.OutputFormat { 91 case Comments: 92 return printComments(w, rpt) 93 case Dot: 94 return printDOT(w, rpt) 95 case Tree: 96 return printTree(w, rpt) 97 case Text: 98 return printText(w, rpt) 99 case Traces: 100 return printTraces(w, rpt) 101 case Raw: 102 fmt.Fprint(w, rpt.prof.String()) 103 return nil 104 case Tags: 105 return printTags(w, rpt) 106 case Proto: 107 return printProto(w, rpt) 108 case TopProto: 109 return printTopProto(w, rpt) 110 case Dis: 111 return printAssembly(w, rpt, obj) 112 case List: 113 return printSource(w, rpt) 114 case WebList: 115 return printWebSource(w, rpt, obj) 116 case Callgrind: 117 return printCallgrind(w, rpt) 118 } 119 return fmt.Errorf("unexpected output format") 120} 121 122// newTrimmedGraph creates a graph for this report, trimmed according 123// to the report options. 124func (rpt *Report) newTrimmedGraph() (g *graph.Graph, origCount, droppedNodes, droppedEdges int) { 125 o := rpt.options 126 127 // Build a graph and refine it. On each refinement step we must rebuild the graph from the samples, 128 // as the graph itself doesn't contain enough information to preserve full precision. 129 visualMode := o.OutputFormat == Dot 130 cumSort := o.CumSort 131 132 // The call_tree option is only honored when generating visual representations of the callgraph. 133 callTree := o.CallTree && (o.OutputFormat == Dot || o.OutputFormat == Callgrind) 134 135 // First step: Build complete graph to identify low frequency nodes, based on their cum weight. 136 g = rpt.newGraph(nil) 137 totalValue, _ := g.Nodes.Sum() 138 nodeCutoff := abs64(int64(float64(totalValue) * o.NodeFraction)) 139 edgeCutoff := abs64(int64(float64(totalValue) * o.EdgeFraction)) 140 141 // Filter out nodes with cum value below nodeCutoff. 142 if nodeCutoff > 0 { 143 if callTree { 144 if nodesKept := g.DiscardLowFrequencyNodePtrs(nodeCutoff); len(g.Nodes) != len(nodesKept) { 145 droppedNodes = len(g.Nodes) - len(nodesKept) 146 g.TrimTree(nodesKept) 147 } 148 } else { 149 if nodesKept := g.DiscardLowFrequencyNodes(nodeCutoff); len(g.Nodes) != len(nodesKept) { 150 droppedNodes = len(g.Nodes) - len(nodesKept) 151 g = rpt.newGraph(nodesKept) 152 } 153 } 154 } 155 origCount = len(g.Nodes) 156 157 // Second step: Limit the total number of nodes. Apply specialized heuristics to improve 158 // visualization when generating dot output. 159 g.SortNodes(cumSort, visualMode) 160 if nodeCount := o.NodeCount; nodeCount > 0 { 161 // Remove low frequency tags and edges as they affect selection. 162 g.TrimLowFrequencyTags(nodeCutoff) 163 g.TrimLowFrequencyEdges(edgeCutoff) 164 if callTree { 165 if nodesKept := g.SelectTopNodePtrs(nodeCount, visualMode); len(g.Nodes) != len(nodesKept) { 166 g.TrimTree(nodesKept) 167 g.SortNodes(cumSort, visualMode) 168 } 169 } else { 170 if nodesKept := g.SelectTopNodes(nodeCount, visualMode); len(g.Nodes) != len(nodesKept) { 171 g = rpt.newGraph(nodesKept) 172 g.SortNodes(cumSort, visualMode) 173 } 174 } 175 } 176 177 // Final step: Filter out low frequency tags and edges, and remove redundant edges that clutter 178 // the graph. 179 g.TrimLowFrequencyTags(nodeCutoff) 180 droppedEdges = g.TrimLowFrequencyEdges(edgeCutoff) 181 if visualMode { 182 g.RemoveRedundantEdges() 183 } 184 return 185} 186 187func (rpt *Report) selectOutputUnit(g *graph.Graph) { 188 o := rpt.options 189 190 // Select best unit for profile output. 191 // Find the appropriate units for the smallest non-zero sample 192 if o.OutputUnit != "minimum" || len(g.Nodes) == 0 { 193 return 194 } 195 var minValue int64 196 197 for _, n := range g.Nodes { 198 nodeMin := abs64(n.FlatValue()) 199 if nodeMin == 0 { 200 nodeMin = abs64(n.CumValue()) 201 } 202 if nodeMin > 0 && (minValue == 0 || nodeMin < minValue) { 203 minValue = nodeMin 204 } 205 } 206 maxValue := rpt.total 207 if minValue == 0 { 208 minValue = maxValue 209 } 210 211 if r := o.Ratio; r > 0 && r != 1 { 212 minValue = int64(float64(minValue) * r) 213 maxValue = int64(float64(maxValue) * r) 214 } 215 216 _, minUnit := measurement.Scale(minValue, o.SampleUnit, "minimum") 217 _, maxUnit := measurement.Scale(maxValue, o.SampleUnit, "minimum") 218 219 unit := minUnit 220 if minUnit != maxUnit && minValue*100 < maxValue && o.OutputFormat != Callgrind { 221 // Minimum and maximum values have different units. Scale 222 // minimum by 100 to use larger units, allowing minimum value to 223 // be scaled down to 0.01, except for callgrind reports since 224 // they can only represent integer values. 225 _, unit = measurement.Scale(100*minValue, o.SampleUnit, "minimum") 226 } 227 228 if unit != "" { 229 o.OutputUnit = unit 230 } else { 231 o.OutputUnit = o.SampleUnit 232 } 233} 234 235// newGraph creates a new graph for this report. If nodes is non-nil, 236// only nodes whose info matches are included. Otherwise, all nodes 237// are included, without trimming. 238func (rpt *Report) newGraph(nodes graph.NodeSet) *graph.Graph { 239 o := rpt.options 240 241 // Clean up file paths using heuristics. 242 prof := rpt.prof 243 for _, f := range prof.Function { 244 f.Filename = trimPath(f.Filename, o.TrimPath, o.SourcePath) 245 } 246 // Removes all numeric tags except for the bytes tag prior 247 // to making graph. 248 // TODO: modify to select first numeric tag if no bytes tag 249 for _, s := range prof.Sample { 250 numLabels := make(map[string][]int64, len(s.NumLabel)) 251 numUnits := make(map[string][]string, len(s.NumLabel)) 252 for k, vs := range s.NumLabel { 253 if k == "bytes" { 254 unit := o.NumLabelUnits[k] 255 numValues := make([]int64, len(vs)) 256 numUnit := make([]string, len(vs)) 257 for i, v := range vs { 258 numValues[i] = v 259 numUnit[i] = unit 260 } 261 numLabels[k] = append(numLabels[k], numValues...) 262 numUnits[k] = append(numUnits[k], numUnit...) 263 } 264 } 265 s.NumLabel = numLabels 266 s.NumUnit = numUnits 267 } 268 269 // Remove label marking samples from the base profiles, so it does not appear 270 // as a nodelet in the graph view. 271 prof.RemoveLabel("pprof::base") 272 273 formatTag := func(v int64, key string) string { 274 return measurement.ScaledLabel(v, key, o.OutputUnit) 275 } 276 277 gopt := &graph.Options{ 278 SampleValue: o.SampleValue, 279 SampleMeanDivisor: o.SampleMeanDivisor, 280 FormatTag: formatTag, 281 CallTree: o.CallTree && (o.OutputFormat == Dot || o.OutputFormat == Callgrind), 282 DropNegative: o.DropNegative, 283 KeptNodes: nodes, 284 } 285 286 // Only keep binary names for disassembly-based reports, otherwise 287 // remove it to allow merging of functions across binaries. 288 switch o.OutputFormat { 289 case Raw, List, WebList, Dis, Callgrind: 290 gopt.ObjNames = true 291 } 292 293 return graph.New(rpt.prof, gopt) 294} 295 296// printProto writes the incoming proto via thw writer w. 297// If the divide_by option has been specified, samples are scaled appropriately. 298func printProto(w io.Writer, rpt *Report) error { 299 p, o := rpt.prof, rpt.options 300 301 // Apply the sample ratio to all samples before saving the profile. 302 if r := o.Ratio; r > 0 && r != 1 { 303 for _, sample := range p.Sample { 304 for i, v := range sample.Value { 305 sample.Value[i] = int64(float64(v) * r) 306 } 307 } 308 } 309 return p.Write(w) 310} 311 312// printTopProto writes a list of the hottest routines in a profile as a profile.proto. 313func printTopProto(w io.Writer, rpt *Report) error { 314 p := rpt.prof 315 o := rpt.options 316 g, _, _, _ := rpt.newTrimmedGraph() 317 rpt.selectOutputUnit(g) 318 319 out := profile.Profile{ 320 SampleType: []*profile.ValueType{ 321 {Type: "cum", Unit: o.OutputUnit}, 322 {Type: "flat", Unit: o.OutputUnit}, 323 }, 324 TimeNanos: p.TimeNanos, 325 DurationNanos: p.DurationNanos, 326 PeriodType: p.PeriodType, 327 Period: p.Period, 328 } 329 functionMap := make(functionMap) 330 for i, n := range g.Nodes { 331 f, added := functionMap.findOrAdd(n.Info) 332 if added { 333 out.Function = append(out.Function, f) 334 } 335 flat, cum := n.FlatValue(), n.CumValue() 336 l := &profile.Location{ 337 ID: uint64(i + 1), 338 Address: n.Info.Address, 339 Line: []profile.Line{ 340 { 341 Line: int64(n.Info.Lineno), 342 Function: f, 343 }, 344 }, 345 } 346 347 fv, _ := measurement.Scale(flat, o.SampleUnit, o.OutputUnit) 348 cv, _ := measurement.Scale(cum, o.SampleUnit, o.OutputUnit) 349 s := &profile.Sample{ 350 Location: []*profile.Location{l}, 351 Value: []int64{int64(cv), int64(fv)}, 352 } 353 out.Location = append(out.Location, l) 354 out.Sample = append(out.Sample, s) 355 } 356 357 return out.Write(w) 358} 359 360type functionMap map[string]*profile.Function 361 362// findOrAdd takes a node representing a function, adds the function 363// represented by the node to the map if the function is not already present, 364// and returns the function the node represents. This also returns a boolean, 365// which is true if the function was added and false otherwise. 366func (fm functionMap) findOrAdd(ni graph.NodeInfo) (*profile.Function, bool) { 367 fName := fmt.Sprintf("%q%q%q%d", ni.Name, ni.OrigName, ni.File, ni.StartLine) 368 369 if f := fm[fName]; f != nil { 370 return f, false 371 } 372 373 f := &profile.Function{ 374 ID: uint64(len(fm) + 1), 375 Name: ni.Name, 376 SystemName: ni.OrigName, 377 Filename: ni.File, 378 StartLine: int64(ni.StartLine), 379 } 380 fm[fName] = f 381 return f, true 382} 383 384// printAssembly prints an annotated assembly listing. 385func printAssembly(w io.Writer, rpt *Report, obj plugin.ObjTool) error { 386 return PrintAssembly(w, rpt, obj, -1) 387} 388 389// PrintAssembly prints annotated disassembly of rpt to w. 390func PrintAssembly(w io.Writer, rpt *Report, obj plugin.ObjTool, maxFuncs int) error { 391 o := rpt.options 392 prof := rpt.prof 393 394 g := rpt.newGraph(nil) 395 396 // If the regexp source can be parsed as an address, also match 397 // functions that land on that address. 398 var address *uint64 399 if hex, err := strconv.ParseUint(o.Symbol.String(), 0, 64); err == nil { 400 address = &hex 401 } 402 403 fmt.Fprintln(w, "Total:", rpt.formatValue(rpt.total)) 404 symbols := symbolsFromBinaries(prof, g, o.Symbol, address, obj) 405 symNodes := nodesPerSymbol(g.Nodes, symbols) 406 407 // Sort for printing. 408 var syms []*objSymbol 409 for s := range symNodes { 410 syms = append(syms, s) 411 } 412 byName := func(a, b *objSymbol) bool { 413 if na, nb := a.sym.Name[0], b.sym.Name[0]; na != nb { 414 return na < nb 415 } 416 return a.sym.Start < b.sym.Start 417 } 418 if maxFuncs < 0 { 419 sort.Sort(orderSyms{syms, byName}) 420 } else { 421 byFlatSum := func(a, b *objSymbol) bool { 422 suma, _ := symNodes[a].Sum() 423 sumb, _ := symNodes[b].Sum() 424 if suma != sumb { 425 return suma > sumb 426 } 427 return byName(a, b) 428 } 429 sort.Sort(orderSyms{syms, byFlatSum}) 430 if len(syms) > maxFuncs { 431 syms = syms[:maxFuncs] 432 } 433 } 434 435 // Correlate the symbols from the binary with the profile samples. 436 for _, s := range syms { 437 sns := symNodes[s] 438 439 // Gather samples for this symbol. 440 flatSum, cumSum := sns.Sum() 441 442 // Get the function assembly. 443 insts, err := obj.Disasm(s.sym.File, s.sym.Start, s.sym.End, o.IntelSyntax) 444 if err != nil { 445 return err 446 } 447 448 ns := annotateAssembly(insts, sns, s.file) 449 450 fmt.Fprintf(w, "ROUTINE ======================== %s\n", s.sym.Name[0]) 451 for _, name := range s.sym.Name[1:] { 452 fmt.Fprintf(w, " AKA ======================== %s\n", name) 453 } 454 fmt.Fprintf(w, "%10s %10s (flat, cum) %s of Total\n", 455 rpt.formatValue(flatSum), rpt.formatValue(cumSum), 456 measurement.Percentage(cumSum, rpt.total)) 457 458 function, file, line := "", "", 0 459 for _, n := range ns { 460 locStr := "" 461 // Skip loc information if it hasn't changed from previous instruction. 462 if n.function != function || n.file != file || n.line != line { 463 function, file, line = n.function, n.file, n.line 464 if n.function != "" { 465 locStr = n.function + " " 466 } 467 if n.file != "" { 468 locStr += n.file 469 if n.line != 0 { 470 locStr += fmt.Sprintf(":%d", n.line) 471 } 472 } 473 } 474 switch { 475 case locStr == "": 476 // No location info, just print the instruction. 477 fmt.Fprintf(w, "%10s %10s %10x: %s\n", 478 valueOrDot(n.flatValue(), rpt), 479 valueOrDot(n.cumValue(), rpt), 480 n.address, n.instruction, 481 ) 482 case len(n.instruction) < 40: 483 // Short instruction, print loc on the same line. 484 fmt.Fprintf(w, "%10s %10s %10x: %-40s;%s\n", 485 valueOrDot(n.flatValue(), rpt), 486 valueOrDot(n.cumValue(), rpt), 487 n.address, n.instruction, 488 locStr, 489 ) 490 default: 491 // Long instruction, print loc on a separate line. 492 fmt.Fprintf(w, "%74s;%s\n", "", locStr) 493 fmt.Fprintf(w, "%10s %10s %10x: %s\n", 494 valueOrDot(n.flatValue(), rpt), 495 valueOrDot(n.cumValue(), rpt), 496 n.address, n.instruction, 497 ) 498 } 499 } 500 } 501 return nil 502} 503 504// symbolsFromBinaries examines the binaries listed on the profile 505// that have associated samples, and identifies symbols matching rx. 506func symbolsFromBinaries(prof *profile.Profile, g *graph.Graph, rx *regexp.Regexp, address *uint64, obj plugin.ObjTool) []*objSymbol { 507 hasSamples := make(map[string]bool) 508 // Only examine mappings that have samples that match the 509 // regexp. This is an optimization to speed up pprof. 510 for _, n := range g.Nodes { 511 if name := n.Info.PrintableName(); rx.MatchString(name) && n.Info.Objfile != "" { 512 hasSamples[n.Info.Objfile] = true 513 } 514 } 515 516 // Walk all mappings looking for matching functions with samples. 517 var objSyms []*objSymbol 518 for _, m := range prof.Mapping { 519 if !hasSamples[m.File] { 520 if address == nil || !(m.Start <= *address && *address <= m.Limit) { 521 continue 522 } 523 } 524 525 f, err := obj.Open(m.File, m.Start, m.Limit, m.Offset) 526 if err != nil { 527 fmt.Printf("%v\n", err) 528 continue 529 } 530 531 // Find symbols in this binary matching the user regexp. 532 var addr uint64 533 if address != nil { 534 addr = *address 535 } 536 msyms, err := f.Symbols(rx, addr) 537 f.Close() 538 if err != nil { 539 continue 540 } 541 for _, ms := range msyms { 542 objSyms = append(objSyms, 543 &objSymbol{ 544 sym: ms, 545 file: f, 546 }, 547 ) 548 } 549 } 550 551 return objSyms 552} 553 554// objSym represents a symbol identified from a binary. It includes 555// the SymbolInfo from the disasm package and the base that must be 556// added to correspond to sample addresses 557type objSymbol struct { 558 sym *plugin.Sym 559 file plugin.ObjFile 560} 561 562// orderSyms is a wrapper type to sort []*objSymbol by a supplied comparator. 563type orderSyms struct { 564 v []*objSymbol 565 less func(a, b *objSymbol) bool 566} 567 568func (o orderSyms) Len() int { return len(o.v) } 569func (o orderSyms) Less(i, j int) bool { return o.less(o.v[i], o.v[j]) } 570func (o orderSyms) Swap(i, j int) { o.v[i], o.v[j] = o.v[j], o.v[i] } 571 572// nodesPerSymbol classifies nodes into a group of symbols. 573func nodesPerSymbol(ns graph.Nodes, symbols []*objSymbol) map[*objSymbol]graph.Nodes { 574 symNodes := make(map[*objSymbol]graph.Nodes) 575 for _, s := range symbols { 576 // Gather samples for this symbol. 577 for _, n := range ns { 578 if address, err := s.file.ObjAddr(n.Info.Address); err == nil && address >= s.sym.Start && address < s.sym.End { 579 symNodes[s] = append(symNodes[s], n) 580 } 581 } 582 } 583 return symNodes 584} 585 586type assemblyInstruction struct { 587 address uint64 588 instruction string 589 function string 590 file string 591 line int 592 flat, cum int64 593 flatDiv, cumDiv int64 594 startsBlock bool 595 inlineCalls []callID 596} 597 598type callID struct { 599 file string 600 line int 601} 602 603func (a *assemblyInstruction) flatValue() int64 { 604 if a.flatDiv != 0 { 605 return a.flat / a.flatDiv 606 } 607 return a.flat 608} 609 610func (a *assemblyInstruction) cumValue() int64 { 611 if a.cumDiv != 0 { 612 return a.cum / a.cumDiv 613 } 614 return a.cum 615} 616 617// annotateAssembly annotates a set of assembly instructions with a 618// set of samples. It returns a set of nodes to display. base is an 619// offset to adjust the sample addresses. 620func annotateAssembly(insts []plugin.Inst, samples graph.Nodes, file plugin.ObjFile) []assemblyInstruction { 621 // Add end marker to simplify printing loop. 622 insts = append(insts, plugin.Inst{ 623 Addr: ^uint64(0), 624 }) 625 626 // Ensure samples are sorted by address. 627 samples.Sort(graph.AddressOrder) 628 629 s := 0 630 asm := make([]assemblyInstruction, 0, len(insts)) 631 for ix, in := range insts[:len(insts)-1] { 632 n := assemblyInstruction{ 633 address: in.Addr, 634 instruction: in.Text, 635 function: in.Function, 636 line: in.Line, 637 } 638 if in.File != "" { 639 n.file = filepath.Base(in.File) 640 } 641 642 // Sum all the samples until the next instruction (to account 643 // for samples attributed to the middle of an instruction). 644 for next := insts[ix+1].Addr; s < len(samples); s++ { 645 if addr, err := file.ObjAddr(samples[s].Info.Address); err != nil || addr >= next { 646 break 647 } 648 sample := samples[s] 649 n.flatDiv += sample.FlatDiv 650 n.flat += sample.Flat 651 n.cumDiv += sample.CumDiv 652 n.cum += sample.Cum 653 if f := sample.Info.File; f != "" && n.file == "" { 654 n.file = filepath.Base(f) 655 } 656 if ln := sample.Info.Lineno; ln != 0 && n.line == 0 { 657 n.line = ln 658 } 659 if f := sample.Info.Name; f != "" && n.function == "" { 660 n.function = f 661 } 662 } 663 asm = append(asm, n) 664 } 665 666 return asm 667} 668 669// valueOrDot formats a value according to a report, intercepting zero 670// values. 671func valueOrDot(value int64, rpt *Report) string { 672 if value == 0 { 673 return "." 674 } 675 return rpt.formatValue(value) 676} 677 678// printTags collects all tags referenced in the profile and prints 679// them in a sorted table. 680func printTags(w io.Writer, rpt *Report) error { 681 p := rpt.prof 682 683 o := rpt.options 684 formatTag := func(v int64, key string) string { 685 return measurement.ScaledLabel(v, key, o.OutputUnit) 686 } 687 688 // Hashtable to keep accumulate tags as key,value,count. 689 tagMap := make(map[string]map[string]int64) 690 for _, s := range p.Sample { 691 for key, vals := range s.Label { 692 for _, val := range vals { 693 valueMap, ok := tagMap[key] 694 if !ok { 695 valueMap = make(map[string]int64) 696 tagMap[key] = valueMap 697 } 698 valueMap[val] += o.SampleValue(s.Value) 699 } 700 } 701 for key, vals := range s.NumLabel { 702 unit := o.NumLabelUnits[key] 703 for _, nval := range vals { 704 val := formatTag(nval, unit) 705 valueMap, ok := tagMap[key] 706 if !ok { 707 valueMap = make(map[string]int64) 708 tagMap[key] = valueMap 709 } 710 valueMap[val] += o.SampleValue(s.Value) 711 } 712 } 713 } 714 715 tagKeys := make([]*graph.Tag, 0, len(tagMap)) 716 for key := range tagMap { 717 tagKeys = append(tagKeys, &graph.Tag{Name: key}) 718 } 719 tabw := tabwriter.NewWriter(w, 0, 0, 1, ' ', tabwriter.AlignRight) 720 for _, tagKey := range graph.SortTags(tagKeys, true) { 721 var total int64 722 key := tagKey.Name 723 tags := make([]*graph.Tag, 0, len(tagMap[key])) 724 for t, c := range tagMap[key] { 725 total += c 726 tags = append(tags, &graph.Tag{Name: t, Flat: c}) 727 } 728 729 f, u := measurement.Scale(total, o.SampleUnit, o.OutputUnit) 730 fmt.Fprintf(tabw, "%s:\t Total %.1f%s\n", key, f, u) 731 for _, t := range graph.SortTags(tags, true) { 732 f, u := measurement.Scale(t.FlatValue(), o.SampleUnit, o.OutputUnit) 733 if total > 0 { 734 fmt.Fprintf(tabw, " \t%.1f%s (%s):\t %s\n", f, u, measurement.Percentage(t.FlatValue(), total), t.Name) 735 } else { 736 fmt.Fprintf(tabw, " \t%.1f%s:\t %s\n", f, u, t.Name) 737 } 738 } 739 fmt.Fprintln(tabw) 740 } 741 return tabw.Flush() 742} 743 744// printComments prints all freeform comments in the profile. 745func printComments(w io.Writer, rpt *Report) error { 746 p := rpt.prof 747 748 for _, c := range p.Comments { 749 fmt.Fprintln(w, c) 750 } 751 return nil 752} 753 754// TextItem holds a single text report entry. 755type TextItem struct { 756 Name string 757 InlineLabel string // Not empty if inlined 758 Flat, Cum int64 // Raw values 759 FlatFormat, CumFormat string // Formatted values 760} 761 762// TextItems returns a list of text items from the report and a list 763// of labels that describe the report. 764func TextItems(rpt *Report) ([]TextItem, []string) { 765 g, origCount, droppedNodes, _ := rpt.newTrimmedGraph() 766 rpt.selectOutputUnit(g) 767 labels := reportLabels(rpt, g, origCount, droppedNodes, 0, false) 768 769 var items []TextItem 770 var flatSum int64 771 for _, n := range g.Nodes { 772 name, flat, cum := n.Info.PrintableName(), n.FlatValue(), n.CumValue() 773 774 var inline, noinline bool 775 for _, e := range n.In { 776 if e.Inline { 777 inline = true 778 } else { 779 noinline = true 780 } 781 } 782 783 var inl string 784 if inline { 785 if noinline { 786 inl = "(partial-inline)" 787 } else { 788 inl = "(inline)" 789 } 790 } 791 792 flatSum += flat 793 items = append(items, TextItem{ 794 Name: name, 795 InlineLabel: inl, 796 Flat: flat, 797 Cum: cum, 798 FlatFormat: rpt.formatValue(flat), 799 CumFormat: rpt.formatValue(cum), 800 }) 801 } 802 return items, labels 803} 804 805// printText prints a flat text report for a profile. 806func printText(w io.Writer, rpt *Report) error { 807 items, labels := TextItems(rpt) 808 fmt.Fprintln(w, strings.Join(labels, "\n")) 809 fmt.Fprintf(w, "%10s %5s%% %5s%% %10s %5s%%\n", 810 "flat", "flat", "sum", "cum", "cum") 811 var flatSum int64 812 for _, item := range items { 813 inl := item.InlineLabel 814 if inl != "" { 815 inl = " " + inl 816 } 817 flatSum += item.Flat 818 fmt.Fprintf(w, "%10s %s %s %10s %s %s%s\n", 819 item.FlatFormat, measurement.Percentage(item.Flat, rpt.total), 820 measurement.Percentage(flatSum, rpt.total), 821 item.CumFormat, measurement.Percentage(item.Cum, rpt.total), 822 item.Name, inl) 823 } 824 return nil 825} 826 827// printTraces prints all traces from a profile. 828func printTraces(w io.Writer, rpt *Report) error { 829 fmt.Fprintln(w, strings.Join(ProfileLabels(rpt), "\n")) 830 831 prof := rpt.prof 832 o := rpt.options 833 834 const separator = "-----------+-------------------------------------------------------" 835 836 _, locations := graph.CreateNodes(prof, &graph.Options{}) 837 for _, sample := range prof.Sample { 838 type stk struct { 839 *graph.NodeInfo 840 inline bool 841 } 842 var stack []stk 843 for _, loc := range sample.Location { 844 nodes := locations[loc.ID] 845 for i, n := range nodes { 846 // The inline flag may be inaccurate if 'show' or 'hide' filter is 847 // used. See https://github.com/google/pprof/issues/511. 848 inline := i != len(nodes)-1 849 stack = append(stack, stk{&n.Info, inline}) 850 } 851 } 852 853 if len(stack) == 0 { 854 continue 855 } 856 857 fmt.Fprintln(w, separator) 858 // Print any text labels for the sample. 859 var labels []string 860 for s, vs := range sample.Label { 861 labels = append(labels, fmt.Sprintf("%10s: %s\n", s, strings.Join(vs, " "))) 862 } 863 sort.Strings(labels) 864 fmt.Fprint(w, strings.Join(labels, "")) 865 866 // Print any numeric labels for the sample 867 var numLabels []string 868 for key, vals := range sample.NumLabel { 869 unit := o.NumLabelUnits[key] 870 numValues := make([]string, len(vals)) 871 for i, vv := range vals { 872 numValues[i] = measurement.Label(vv, unit) 873 } 874 numLabels = append(numLabels, fmt.Sprintf("%10s: %s\n", key, strings.Join(numValues, " "))) 875 } 876 sort.Strings(numLabels) 877 fmt.Fprint(w, strings.Join(numLabels, "")) 878 879 var d, v int64 880 v = o.SampleValue(sample.Value) 881 if o.SampleMeanDivisor != nil { 882 d = o.SampleMeanDivisor(sample.Value) 883 } 884 // Print call stack. 885 if d != 0 { 886 v = v / d 887 } 888 for i, s := range stack { 889 var vs, inline string 890 if i == 0 { 891 vs = rpt.formatValue(v) 892 } 893 if s.inline { 894 inline = " (inline)" 895 } 896 fmt.Fprintf(w, "%10s %s%s\n", vs, s.PrintableName(), inline) 897 } 898 } 899 fmt.Fprintln(w, separator) 900 return nil 901} 902 903// printCallgrind prints a graph for a profile on callgrind format. 904func printCallgrind(w io.Writer, rpt *Report) error { 905 o := rpt.options 906 rpt.options.NodeFraction = 0 907 rpt.options.EdgeFraction = 0 908 rpt.options.NodeCount = 0 909 910 g, _, _, _ := rpt.newTrimmedGraph() 911 rpt.selectOutputUnit(g) 912 913 nodeNames := getDisambiguatedNames(g) 914 915 fmt.Fprintln(w, "positions: instr line") 916 fmt.Fprintln(w, "events:", o.SampleType+"("+o.OutputUnit+")") 917 918 objfiles := make(map[string]int) 919 files := make(map[string]int) 920 names := make(map[string]int) 921 922 // prevInfo points to the previous NodeInfo. 923 // It is used to group cost lines together as much as possible. 924 var prevInfo *graph.NodeInfo 925 for _, n := range g.Nodes { 926 if prevInfo == nil || n.Info.Objfile != prevInfo.Objfile || n.Info.File != prevInfo.File || n.Info.Name != prevInfo.Name { 927 fmt.Fprintln(w) 928 fmt.Fprintln(w, "ob="+callgrindName(objfiles, n.Info.Objfile)) 929 fmt.Fprintln(w, "fl="+callgrindName(files, n.Info.File)) 930 fmt.Fprintln(w, "fn="+callgrindName(names, n.Info.Name)) 931 } 932 933 addr := callgrindAddress(prevInfo, n.Info.Address) 934 sv, _ := measurement.Scale(n.FlatValue(), o.SampleUnit, o.OutputUnit) 935 fmt.Fprintf(w, "%s %d %d\n", addr, n.Info.Lineno, int64(sv)) 936 937 // Print outgoing edges. 938 for _, out := range n.Out.Sort() { 939 c, _ := measurement.Scale(out.Weight, o.SampleUnit, o.OutputUnit) 940 callee := out.Dest 941 fmt.Fprintln(w, "cfl="+callgrindName(files, callee.Info.File)) 942 fmt.Fprintln(w, "cfn="+callgrindName(names, nodeNames[callee])) 943 // pprof doesn't have a flat weight for a call, leave as 0. 944 fmt.Fprintf(w, "calls=0 %s %d\n", callgrindAddress(prevInfo, callee.Info.Address), callee.Info.Lineno) 945 // TODO: This address may be in the middle of a call 946 // instruction. It would be best to find the beginning 947 // of the instruction, but the tools seem to handle 948 // this OK. 949 fmt.Fprintf(w, "* * %d\n", int64(c)) 950 } 951 952 prevInfo = &n.Info 953 } 954 955 return nil 956} 957 958// getDisambiguatedNames returns a map from each node in the graph to 959// the name to use in the callgrind output. Callgrind merges all 960// functions with the same [file name, function name]. Add a [%d/n] 961// suffix to disambiguate nodes with different values of 962// node.Function, which we want to keep separate. In particular, this 963// affects graphs created with --call_tree, where nodes from different 964// contexts are associated to different Functions. 965func getDisambiguatedNames(g *graph.Graph) map[*graph.Node]string { 966 nodeName := make(map[*graph.Node]string, len(g.Nodes)) 967 968 type names struct { 969 file, function string 970 } 971 972 // nameFunctionIndex maps the callgrind names (filename, function) 973 // to the node.Function values found for that name, and each 974 // node.Function value to a sequential index to be used on the 975 // disambiguated name. 976 nameFunctionIndex := make(map[names]map[*graph.Node]int) 977 for _, n := range g.Nodes { 978 nm := names{n.Info.File, n.Info.Name} 979 p, ok := nameFunctionIndex[nm] 980 if !ok { 981 p = make(map[*graph.Node]int) 982 nameFunctionIndex[nm] = p 983 } 984 if _, ok := p[n.Function]; !ok { 985 p[n.Function] = len(p) 986 } 987 } 988 989 for _, n := range g.Nodes { 990 nm := names{n.Info.File, n.Info.Name} 991 nodeName[n] = n.Info.Name 992 if p := nameFunctionIndex[nm]; len(p) > 1 { 993 // If there is more than one function, add suffix to disambiguate. 994 nodeName[n] += fmt.Sprintf(" [%d/%d]", p[n.Function]+1, len(p)) 995 } 996 } 997 return nodeName 998} 999 1000// callgrindName implements the callgrind naming compression scheme. 1001// For names not previously seen returns "(N) name", where N is a 1002// unique index. For names previously seen returns "(N)" where N is 1003// the index returned the first time. 1004func callgrindName(names map[string]int, name string) string { 1005 if name == "" { 1006 return "" 1007 } 1008 if id, ok := names[name]; ok { 1009 return fmt.Sprintf("(%d)", id) 1010 } 1011 id := len(names) + 1 1012 names[name] = id 1013 return fmt.Sprintf("(%d) %s", id, name) 1014} 1015 1016// callgrindAddress implements the callgrind subposition compression scheme if 1017// possible. If prevInfo != nil, it contains the previous address. The current 1018// address can be given relative to the previous address, with an explicit +/- 1019// to indicate it is relative, or * for the same address. 1020func callgrindAddress(prevInfo *graph.NodeInfo, curr uint64) string { 1021 abs := fmt.Sprintf("%#x", curr) 1022 if prevInfo == nil { 1023 return abs 1024 } 1025 1026 prev := prevInfo.Address 1027 if prev == curr { 1028 return "*" 1029 } 1030 1031 diff := int64(curr - prev) 1032 relative := fmt.Sprintf("%+d", diff) 1033 1034 // Only bother to use the relative address if it is actually shorter. 1035 if len(relative) < len(abs) { 1036 return relative 1037 } 1038 1039 return abs 1040} 1041 1042// printTree prints a tree-based report in text form. 1043func printTree(w io.Writer, rpt *Report) error { 1044 const separator = "----------------------------------------------------------+-------------" 1045 const legend = " flat flat% sum% cum cum% calls calls% + context " 1046 1047 g, origCount, droppedNodes, _ := rpt.newTrimmedGraph() 1048 rpt.selectOutputUnit(g) 1049 1050 fmt.Fprintln(w, strings.Join(reportLabels(rpt, g, origCount, droppedNodes, 0, false), "\n")) 1051 1052 fmt.Fprintln(w, separator) 1053 fmt.Fprintln(w, legend) 1054 var flatSum int64 1055 1056 rx := rpt.options.Symbol 1057 for _, n := range g.Nodes { 1058 name, flat, cum := n.Info.PrintableName(), n.FlatValue(), n.CumValue() 1059 1060 // Skip any entries that do not match the regexp (for the "peek" command). 1061 if rx != nil && !rx.MatchString(name) { 1062 continue 1063 } 1064 1065 fmt.Fprintln(w, separator) 1066 // Print incoming edges. 1067 inEdges := n.In.Sort() 1068 for _, in := range inEdges { 1069 var inline string 1070 if in.Inline { 1071 inline = " (inline)" 1072 } 1073 fmt.Fprintf(w, "%50s %s | %s%s\n", rpt.formatValue(in.Weight), 1074 measurement.Percentage(in.Weight, cum), in.Src.Info.PrintableName(), inline) 1075 } 1076 1077 // Print current node. 1078 flatSum += flat 1079 fmt.Fprintf(w, "%10s %s %s %10s %s | %s\n", 1080 rpt.formatValue(flat), 1081 measurement.Percentage(flat, rpt.total), 1082 measurement.Percentage(flatSum, rpt.total), 1083 rpt.formatValue(cum), 1084 measurement.Percentage(cum, rpt.total), 1085 name) 1086 1087 // Print outgoing edges. 1088 outEdges := n.Out.Sort() 1089 for _, out := range outEdges { 1090 var inline string 1091 if out.Inline { 1092 inline = " (inline)" 1093 } 1094 fmt.Fprintf(w, "%50s %s | %s%s\n", rpt.formatValue(out.Weight), 1095 measurement.Percentage(out.Weight, cum), out.Dest.Info.PrintableName(), inline) 1096 } 1097 } 1098 if len(g.Nodes) > 0 { 1099 fmt.Fprintln(w, separator) 1100 } 1101 return nil 1102} 1103 1104// GetDOT returns a graph suitable for dot processing along with some 1105// configuration information. 1106func GetDOT(rpt *Report) (*graph.Graph, *graph.DotConfig) { 1107 g, origCount, droppedNodes, droppedEdges := rpt.newTrimmedGraph() 1108 rpt.selectOutputUnit(g) 1109 labels := reportLabels(rpt, g, origCount, droppedNodes, droppedEdges, true) 1110 1111 c := &graph.DotConfig{ 1112 Title: rpt.options.Title, 1113 Labels: labels, 1114 FormatValue: rpt.formatValue, 1115 Total: rpt.total, 1116 } 1117 return g, c 1118} 1119 1120// printDOT prints an annotated callgraph in DOT format. 1121func printDOT(w io.Writer, rpt *Report) error { 1122 g, c := GetDOT(rpt) 1123 graph.ComposeDot(w, g, &graph.DotAttributes{}, c) 1124 return nil 1125} 1126 1127// ProfileLabels returns printable labels for a profile. 1128func ProfileLabels(rpt *Report) []string { 1129 label := []string{} 1130 prof := rpt.prof 1131 o := rpt.options 1132 if len(prof.Mapping) > 0 { 1133 if prof.Mapping[0].File != "" { 1134 label = append(label, "File: "+filepath.Base(prof.Mapping[0].File)) 1135 } 1136 if prof.Mapping[0].BuildID != "" { 1137 label = append(label, "Build ID: "+prof.Mapping[0].BuildID) 1138 } 1139 } 1140 // Only include comments that do not start with '#'. 1141 for _, c := range prof.Comments { 1142 if !strings.HasPrefix(c, "#") { 1143 label = append(label, c) 1144 } 1145 } 1146 if o.SampleType != "" { 1147 label = append(label, "Type: "+o.SampleType) 1148 } 1149 if prof.TimeNanos != 0 { 1150 const layout = "Jan 2, 2006 at 3:04pm (MST)" 1151 label = append(label, "Time: "+time.Unix(0, prof.TimeNanos).Format(layout)) 1152 } 1153 if prof.DurationNanos != 0 { 1154 duration := measurement.Label(prof.DurationNanos, "nanoseconds") 1155 totalNanos, totalUnit := measurement.Scale(rpt.total, o.SampleUnit, "nanoseconds") 1156 var ratio string 1157 if totalUnit == "ns" && totalNanos != 0 { 1158 ratio = "(" + measurement.Percentage(int64(totalNanos), prof.DurationNanos) + ")" 1159 } 1160 label = append(label, fmt.Sprintf("Duration: %s, Total samples = %s %s", duration, rpt.formatValue(rpt.total), ratio)) 1161 } 1162 return label 1163} 1164 1165// reportLabels returns printable labels for a report. Includes 1166// profileLabels. 1167func reportLabels(rpt *Report, g *graph.Graph, origCount, droppedNodes, droppedEdges int, fullHeaders bool) []string { 1168 nodeFraction := rpt.options.NodeFraction 1169 edgeFraction := rpt.options.EdgeFraction 1170 nodeCount := len(g.Nodes) 1171 1172 var label []string 1173 if len(rpt.options.ProfileLabels) > 0 { 1174 label = append(label, rpt.options.ProfileLabels...) 1175 } else if fullHeaders || !rpt.options.CompactLabels { 1176 label = ProfileLabels(rpt) 1177 } 1178 1179 var flatSum int64 1180 for _, n := range g.Nodes { 1181 flatSum = flatSum + n.FlatValue() 1182 } 1183 1184 if len(rpt.options.ActiveFilters) > 0 { 1185 activeFilters := legendActiveFilters(rpt.options.ActiveFilters) 1186 label = append(label, activeFilters...) 1187 } 1188 1189 label = append(label, fmt.Sprintf("Showing nodes accounting for %s, %s of %s total", rpt.formatValue(flatSum), strings.TrimSpace(measurement.Percentage(flatSum, rpt.total)), rpt.formatValue(rpt.total))) 1190 1191 if rpt.total != 0 { 1192 if droppedNodes > 0 { 1193 label = append(label, genLabel(droppedNodes, "node", "cum", 1194 rpt.formatValue(abs64(int64(float64(rpt.total)*nodeFraction))))) 1195 } 1196 if droppedEdges > 0 { 1197 label = append(label, genLabel(droppedEdges, "edge", "freq", 1198 rpt.formatValue(abs64(int64(float64(rpt.total)*edgeFraction))))) 1199 } 1200 if nodeCount > 0 && nodeCount < origCount { 1201 label = append(label, fmt.Sprintf("Showing top %d nodes out of %d", 1202 nodeCount, origCount)) 1203 } 1204 } 1205 1206 // Help new users understand the graph. 1207 // A new line is intentionally added here to better show this message. 1208 if fullHeaders { 1209 label = append(label, "\nSee https://git.io/JfYMW for how to read the graph") 1210 } 1211 1212 return label 1213} 1214 1215func legendActiveFilters(activeFilters []string) []string { 1216 legendActiveFilters := make([]string, len(activeFilters)+1) 1217 legendActiveFilters[0] = "Active filters:" 1218 for i, s := range activeFilters { 1219 if len(s) > 80 { 1220 s = s[:80] + "…" 1221 } 1222 legendActiveFilters[i+1] = " " + s 1223 } 1224 return legendActiveFilters 1225} 1226 1227func genLabel(d int, n, l, f string) string { 1228 if d > 1 { 1229 n = n + "s" 1230 } 1231 return fmt.Sprintf("Dropped %d %s (%s <= %s)", d, n, l, f) 1232} 1233 1234// New builds a new report indexing the sample values interpreting the 1235// samples with the provided function. 1236func New(prof *profile.Profile, o *Options) *Report { 1237 format := func(v int64) string { 1238 if r := o.Ratio; r > 0 && r != 1 { 1239 fv := float64(v) * r 1240 v = int64(fv) 1241 } 1242 return measurement.ScaledLabel(v, o.SampleUnit, o.OutputUnit) 1243 } 1244 return &Report{prof, computeTotal(prof, o.SampleValue, o.SampleMeanDivisor), 1245 o, format} 1246} 1247 1248// NewDefault builds a new report indexing the last sample value 1249// available. 1250func NewDefault(prof *profile.Profile, options Options) *Report { 1251 index := len(prof.SampleType) - 1 1252 o := &options 1253 if o.Title == "" && len(prof.Mapping) > 0 && prof.Mapping[0].File != "" { 1254 o.Title = filepath.Base(prof.Mapping[0].File) 1255 } 1256 o.SampleType = prof.SampleType[index].Type 1257 o.SampleUnit = strings.ToLower(prof.SampleType[index].Unit) 1258 o.SampleValue = func(v []int64) int64 { 1259 return v[index] 1260 } 1261 return New(prof, o) 1262} 1263 1264// computeTotal computes the sum of the absolute value of all sample values. 1265// If any samples have label indicating they belong to the diff base, then the 1266// total will only include samples with that label. 1267func computeTotal(prof *profile.Profile, value, meanDiv func(v []int64) int64) int64 { 1268 var div, total, diffDiv, diffTotal int64 1269 for _, sample := range prof.Sample { 1270 var d, v int64 1271 v = value(sample.Value) 1272 if meanDiv != nil { 1273 d = meanDiv(sample.Value) 1274 } 1275 if v < 0 { 1276 v = -v 1277 } 1278 total += v 1279 div += d 1280 if sample.DiffBaseSample() { 1281 diffTotal += v 1282 diffDiv += d 1283 } 1284 } 1285 if diffTotal > 0 { 1286 total = diffTotal 1287 div = diffDiv 1288 } 1289 if div != 0 { 1290 return total / div 1291 } 1292 return total 1293} 1294 1295// Report contains the data and associated routines to extract a 1296// report from a profile. 1297type Report struct { 1298 prof *profile.Profile 1299 total int64 1300 options *Options 1301 formatValue func(int64) string 1302} 1303 1304// Total returns the total number of samples in a report. 1305func (rpt *Report) Total() int64 { return rpt.total } 1306 1307func abs64(i int64) int64 { 1308 if i < 0 { 1309 return -i 1310 } 1311 return i 1312} 1313