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