Merge pull request #30 from prattmic/callgrind

Instruction-level granularity in callgrind output

internal/driver/driver.go

@@ -130,12 +130,15 @@ func applyCommandOverrides(cmd []string, v variables) variables {
 	case "proto", "raw":
 		trim, focus, tagfocus, hide = false, false, false, false
 		v.set("addresses", "t")
+	case "callgrind", "kcachegrind":
+		trim = false
+		v.set("addresses", "t")
 	case "disasm", "weblist":
 		trim = false
 		v.set("addressnoinlines", "t")
 	case "peek":
 		trim, focus, hide = false, false, false
-	case "kcachegrind", "callgrind", "list":
+	case "list":
 		v.set("nodecount", "0")
 		v.set("lines", "t")
 	case "text", "top", "topproto":

internal/driver/driver_test.go

@@ -18,6 +18,7 @@ import (
 	"bytes"
 	"fmt"
 	"io/ioutil"
+	"os"
 	"regexp"
 	"strconv"
 	"strings"
@@ -34,6 +35,14 @@ func TestParse(t *testing.T) {
 	// Override weblist command to collect output in buffer
 	pprofCommands["weblist"].postProcess = nil
 
+	// Our mockObjTool.Open will always return success, causing
+	// driver.locateBinaries to "find" the binaries below in a non-existant
+	// directory. As a workaround, point the search path to the fake
+	// directory containing out fake binaries.
+	savePath := os.Getenv("PPROF_BINARY_PATH")
+	os.Setenv("PPROF_BINARY_PATH", "/path/to")
+	defer os.Setenv("PPROF_BINARY_PATH", savePath)
+
 	testcase := []struct {
 		flags, source string
 	}{
@@ -445,7 +454,7 @@ func cpuProfile() *profile.Profile {
 			ID:              1,
 			Start:           0x1000,
 			Limit:           0x4000,
-			File:            "testbinary",
+			File:            "/path/to/testbinary",
 			HasFunctions:    true,
 			HasFilenames:    true,
 			HasLineNumbers:  true,
@@ -564,7 +573,7 @@ func cpuProfileSmall() *profile.Profile {
 			ID:              1,
 			Start:           0x1000,
 			Limit:           0x4000,
-			File:            "testbinary",
+			File:            "/path/to/testbinary",
 			HasFunctions:    true,
 			HasFilenames:    true,
 			HasLineNumbers:  true,
@@ -865,7 +874,7 @@ func symzProfile() *profile.Profile {
 			ID:    1,
 			Start: testStart,
 			Limit: 0x4000,
-			File:  "testbinary",
+			File:  "/path/to/testbinary",
 		},
 	}
 

internal/driver/interactive_test.go

@@ -266,7 +266,8 @@ func TestInteractiveCommands(t *testing.T) {
 				"tagignore": "ignore1|ignore2",
 			},
 		},
-		{"weblist  find -test",
+		{
+			"weblist  find -test",
 			map[string]string{
 				"functions":        "false",
 				"addressnoinlines": "true",
@@ -280,7 +281,7 @@ func TestInteractiveCommands(t *testing.T) {
 			"callgrind   fun -ignore  >out",
 			map[string]string{
 				"functions": "false",
-				"lines":     "true",
+				"addresses": "true",
 				"nodecount": "0",
 				"cum":       "false",
 				"flat":      "true",

internal/driver/testdata/pprof.cpu.callgrind

@@ -1,77 +1,88 @@
+positions: instr line
 events: cpu(ms)
+
+ob=(1) /path/to/testbinary
 fl=(1) testdata/file1000.src
 fn=(1) line1000
-1 1100
+0x1000 1 1100
 
+ob=(1)
 fl=(2) testdata/file2000.src
 fn=(2) line2001
-9 10
++4096 9 10
 cfl=(1)
 cfn=(1)
-calls=0 1
-9 1000
+calls=0 * 1
+* * 1000
 
+ob=(1)
 fl=(3) testdata/file3000.src
 fn=(3) line3002
-2 10
++4096 2 10
 cfl=(2)
 cfn=(4) line2000
-calls=0 4
-2 1000
+calls=0 * 4
+* * 1000
 
+ob=(1)
 fl=(2)
 fn=(4)
-4 0
+-4096 4 0
 cfl=(2)
 cfn=(2)
-calls=0 9
-4 1010
+calls=0 -4096 9
+* * 1010
 
+ob=(1)
 fl=(3)
 fn=(5) line3000
-6 0
++4096 6 0
 cfl=(3)
 cfn=(6) line3001
-calls=0 5
-6 1010
+calls=0 +4096 5
+* * 1010
 
+ob=(1)
 fl=(3)
-fn=(5)
-7 0
+fn=(6)
+* 5 0
 cfl=(3)
 cfn=(3)
-calls=0 5
-7 10
+calls=0 * 2
+* * 1010
 
+ob=(1)
 fl=(3)
 fn=(5)
-9 0
++1 9 0
 cfl=(3)
 cfn=(6)
-calls=0 8
-9 100
-
-fl=(3)
-fn=(6)
-5 0
-cfl=(3)
-cfn=(3)
-calls=0 2
-5 1010
+calls=0 +1 8
+* * 100
 
+ob=(1)
 fl=(3)
 fn=(6)
-8 0
+* 8 0
 cfl=(1)
 cfn=(1)
-calls=0 1
-8 100
+calls=0 -8193 1
+* * 100
 
+ob=(1)
+fl=(3)
+fn=(5)
++1 7 0
+cfl=(3)
+cfn=(3)
+calls=0 +1 5
+* * 10
+
+ob=(1)
 fl=(3)
 fn=(3)
-5 0
+* 5 0
 cfl=(2)
 cfn=(4)
-calls=0 4
-5 10
-
+calls=0 -4098 4
+* * 10

internal/driver/testdata/pprof.heap.callgrind

@@ -1,53 +1,88 @@
+positions: instr line
 events: inuse_space(MB)
+
+ob=
 fl=(1) testdata/file2000.src
 fn=(1) line2001
-2 62
+0x2000 2 62
 cfl=(2) testdata/file1000.src
 cfn=(2) line1000
-calls=0 1
-2 0
+calls=0 0x1000 1
+* * 0
 
+ob=
 fl=(3) testdata/file3000.src
 fn=(3) line3002
-3 31
++4096 3 31
 cfl=(1)
 cfn=(4) line2000
-calls=0 3
-3 63
+calls=0 * 3
+* * 0
 
+ob=
 fl=(2)
 fn=(2)
-1 4
+-8192 1 4
 
+ob=
 fl=(1)
 fn=(4)
-3 0
++4096 3 0
 cfl=(1)
 cfn=(1)
-calls=0 2
-3 63
+calls=0 +4096 2
+* * 63
 
+ob=
 fl=(3)
 fn=(5) line3000
-4 0
-cfl=(3)
-cfn=(3)
-calls=0 3
-4 62
++4096 4 0
 cfl=(3)
 cfn=(6) line3001
-calls=0 2
-4 36
+calls=0 +4096 2
+* * 32
 
+ob=
 fl=(3)
 fn=(6)
-2 0
+* 2 0
 cfl=(3)
 cfn=(3)
-calls=0 3
-2 32
+calls=0 * 3
+* * 32
+
+ob=
+fl=(3)
+fn=(5)
++1 4 0
+cfl=(3)
+cfn=(6)
+calls=0 +1 2
+* * 3
+
+ob=
+fl=(3)
+fn=(6)
+* 2 0
 cfl=(2)
 cfn=(2)
-calls=0 1
-2 3
+calls=0 -8193 1
+* * 3
 
+ob=
+fl=(3)
+fn=(5)
++1 4 0
+cfl=(3)
+cfn=(3)
+calls=0 +1 3
+* * 62
+
+ob=
+fl=(3)
+fn=(3)
+* 3 0
+cfl=(1)
+cfn=(4)
+calls=0 -4098 3
+* * 62

internal/graph/graph.go

@@ -138,7 +138,7 @@ func (i *NodeInfo) NameComponents() []string {
 		// User requested function name. It was already included.
 	case i.Objfile != "":
 		// Only binary name is available
-		name = append(name, "["+i.Objfile+"]")
+		name = append(name, "["+filepath.Base(i.Objfile)+"]")
 	default:
 		// Do not leave it empty if there is no information at all.
 		name = append(name, "<unknown>")
@@ -481,7 +481,7 @@ func (nm NodeMap) nodes() Nodes {
 func (nm NodeMap) findOrInsertLine(l *profile.Location, li profile.Line, o *Options) *Node {
 	var objfile string
 	if m := l.Mapping; m != nil && m.File != "" {
-		objfile = filepath.Base(m.File)
+		objfile = m.File
 	}
 
 	if ni := nodeInfo(l, li, objfile, o); ni != nil {

internal/report/report.go

@@ -211,7 +211,7 @@ func (rpt *Report) newGraph(nodes graph.NodeSet) *graph.Graph {
 	// Only keep binary names for disassembly-based reports, otherwise
 	// remove it to allow merging of functions across binaries.
 	switch o.OutputFormat {
-	case Raw, List, WebList, Dis:
+	case Raw, List, WebList, Dis, Callgrind:
 		gopt.ObjNames = true
 	}
 
@@ -340,7 +340,7 @@ func symbolsFromBinaries(prof *profile.Profile, g *graph.Graph, rx *regexp.Regex
 	// Walk all mappings looking for matching functions with samples.
 	var objSyms []*objSymbol
 	for _, m := range prof.Mapping {
-		if !hasSamples[filepath.Base(m.File)] {
+		if !hasSamples[m.File] {
 			if address == nil || !(m.Start <= *address && *address <= m.Limit) {
 				continue
 			}
@@ -628,15 +628,28 @@ func printCallgrind(w io.Writer, rpt *Report) error {
 	rpt.selectOutputUnit(g)
 
 	nodeNames := getDisambiguatedNames(g)
+
+	fmt.Fprintln(w, "positions: instr line")
 	fmt.Fprintln(w, "events:", o.SampleType+"("+o.OutputUnit+")")
 
+	objfiles := make(map[string]int)
 	files := make(map[string]int)
 	names := make(map[string]int)
+
+	// prevInfo points to the previous NodeInfo.
+	// It is used to group cost lines together as much as possible.
+	var prevInfo *graph.NodeInfo
 	for _, n := range g.Nodes {
-		fmt.Fprintln(w, "fl="+callgrindName(files, n.Info.File))
-		fmt.Fprintln(w, "fn="+callgrindName(names, nodeNames[n]))
+		if prevInfo == nil || n.Info.Objfile != prevInfo.Objfile || n.Info.File != prevInfo.File || n.Info.Name != prevInfo.Name {
+			fmt.Fprintln(w)
+			fmt.Fprintln(w, "ob="+callgrindName(objfiles, n.Info.Objfile))
+			fmt.Fprintln(w, "fl="+callgrindName(files, n.Info.File))
+			fmt.Fprintln(w, "fn="+callgrindName(names, n.Info.Name))
+		}
+
+		addr := callgrindAddress(prevInfo, n.Info.Address)
 		sv, _ := measurement.Scale(n.Flat, o.SampleUnit, o.OutputUnit)
-		fmt.Fprintf(w, "%d %d\n", n.Info.Lineno, int64(sv))
+		fmt.Fprintf(w, "%s %d %d\n", addr, n.Info.Lineno, int64(sv))
 
 		// Print outgoing edges.
 		for _, out := range n.Out.Sort() {
@@ -645,10 +658,15 @@ func printCallgrind(w io.Writer, rpt *Report) error {
 			fmt.Fprintln(w, "cfl="+callgrindName(files, callee.Info.File))
 			fmt.Fprintln(w, "cfn="+callgrindName(names, nodeNames[callee]))
 			// pprof doesn't have a flat weight for a call, leave as 0.
-			fmt.Fprintln(w, "calls=0", callee.Info.Lineno)
-			fmt.Fprintln(w, n.Info.Lineno, int64(c))
+			fmt.Fprintf(w, "calls=0 %s %d\n", callgrindAddress(prevInfo, callee.Info.Address), callee.Info.Lineno)
+			// TODO: This address may be in the middle of a call
+			// instruction. It would be best to find the beginning
+			// of the instruction, but the tools seem to handle
+			// this OK.
+			fmt.Fprintf(w, "* * %d\n", int64(c))
 		}
-		fmt.Fprintln(w)
+
+		prevInfo = &n.Info
 	}
 
 	return nil
@@ -712,6 +730,32 @@ func callgrindName(names map[string]int, name string) string {
 	return fmt.Sprintf("(%d) %s", id, name)
 }
 
+// callgrindAddress implements the callgrind subposition compression scheme if
+// possible. If prevInfo != nil, it contains the previous address. The current
+// address can be given relative to the previous address, with an explicit +/-
+// to indicate it is relative, or * for the same address.
+func callgrindAddress(prevInfo *graph.NodeInfo, curr uint64) string {
+	abs := fmt.Sprintf("%#x", curr)
+	if prevInfo == nil {
+		return abs
+	}
+
+	prev := prevInfo.Address
+	if prev == curr {
+		return "*"
+	}
+
+	diff := int64(curr - prev)
+	relative := fmt.Sprintf("%+d", diff)
+
+	// Only bother to use the relative address if it is actually shorter.
+	if len(relative) < len(abs) {
+		return relative
+	}
+
+	return abs
+}
+
 // printTree prints a tree-based report in text form.
 func printTree(w io.Writer, rpt *Report) error {
 	const separator = "----------------------------------------------------------+-------------"

internal/report/source.go

@@ -253,7 +253,7 @@ func assemblyPerSourceLine(objSyms []*objSymbol, rs graph.Nodes, src string, obj
 func findMatchingSymbol(objSyms []*objSymbol, ns graph.Nodes) *objSymbol {
 	for _, n := range ns {
 		for _, o := range objSyms {
-			if filepath.Base(o.sym.File) == n.Info.Objfile &&
+			if filepath.Base(o.sym.File) == filepath.Base(n.Info.Objfile) &&
 				o.sym.Start <= n.Info.Address-o.base &&
 				n.Info.Address-o.base <= o.sym.End {
 				return o