Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Source listing handles missing binaries and addresses. #628

Merged
merged 2 commits into from
May 6, 2021
Merged

Source listing handles missing binaries and addresses. #628

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
3178125
Source listing handles missing binaries and addresses.
ghemawat Apr 13, 2021
125d5b5
Panic on attempt to synthesize address for Loc with non-zero addr.
ghemawat May 6, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
15 changes: 4 additions & 11 deletions internal/driver/testdata/pprof.cpu.flat.addresses.weblist
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,14 +20,7 @@ h1 {
.inlinesrc {
color: #000066;
}
.deadsrc {
cursor: pointer;
}
.deadsrc:hover {
background-color: #eeeeee;
}
.livesrc {
color: #0000ff;
cursor: pointer;
}
.livesrc:hover {
Expand Down Expand Up @@ -63,12 +56,12 @@ Type: cpu<br>
Duration: 10s, Total samples = 1.12s (11.20%)<br>Total: 1.12s</div><h2>line1000</h2><p class="filename">testdata/file1000.src</p>
<pre onClick="pprof_toggle_asm(event)">
Total: 1.10s 1.10s (flat, cum) 98.21%
<span class=line> 1</span> <span class=deadsrc> 1.10s 1.10s line1 </span><span class=asm> 1.10s 1.10s 1000: instruction one <span class=unimportant>file1000.src:1</span>
<span class=line> 1</span> <span class=livesrc> 1.10s 1.10s line1 </span><span class=asm> 1.10s 1.10s 1000: instruction one <span class=unimportant>file1000.src:1</span>
. . 1001: instruction two <span class=unimportant>file1000.src:1</span>
⋮
. . 1003: instruction four <span class=unimportant>file1000.src:1</span>
</span>
<span class=line> 2</span> <span class=deadsrc> . . line2 </span><span class=asm> . . 1002: instruction three <span class=unimportant>file1000.src:2</span>
<span class=line> 2</span> <span class=livesrc> . . line2 </span><span class=asm> . . 1002: instruction three <span class=unimportant>file1000.src:2</span>
</span>
<span class=line> 3</span> <span class=nop> . . line3 </span>
<span class=line> 4</span> <span class=nop> . . line4 </span>
Expand All @@ -84,13 +77,13 @@ Duration: 10s, Total samples = 1.12s (11.20%)<br>Total: 1.12s</div><h2>line1000<
<span class=line> 3</span> <span class=nop> . . line3 </span>
<span class=line> 4</span> <span class=nop> . . line4 </span>
<span class=line> 5</span> <span class=nop> . . line5 </span>
<span class=line> 6</span> <span class=deadsrc> 10ms 1.01s line6 </span><span class=asm> <span class=inlinesrc> line5 </span> <span class=unimportant>file3000.src:5</span>
<span class=line> 6</span> <span class=livesrc> 10ms 1.01s line6 </span><span class=asm> <span class=inlinesrc> line5 </span> <span class=unimportant>file3000.src:5</span>
<span class=inlinesrc> line2 </span> <span class=unimportant>file3000.src:2</span>
10ms 1.01s 3000: instruction one <span class=unimportant>file3000.src:2</span>
</span>
<span class=line> 7</span> <span class=nop> . . line7 </span>
<span class=line> 8</span> <span class=nop> . . line8 </span>
<span class=line> 9</span> <span class=deadsrc> . 110ms line9 </span><span class=asm> <span class=inlinesrc> line8 </span> <span class=unimportant>file3000.src:8</span>
<span class=line> 9</span> <span class=livesrc> . 110ms line9 </span><span class=asm> <span class=inlinesrc> line8 </span> <span class=unimportant>file3000.src:8</span>
. 100ms 3001: instruction two <span class=unimportant>file3000.src:8</span>
<span class=inlinesrc> line5 </span> <span class=unimportant>file3000.src:5</span>
. 10ms 3002: instruction three <span class=unimportant>file3000.src:5</span>
Expand Down
220 changes: 148 additions & 72 deletions internal/report/source.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -132,6 +132,7 @@ func printWebSource(w io.Writer, rpt *Report, obj plugin.ObjTool) error {
// sourcePrinter holds state needed for generating source+asm HTML listing.
type sourcePrinter struct {
reader *sourceReader
synth *synthCode
objectTool plugin.ObjTool
objects map[string]plugin.ObjFile // Opened object files
sym *regexp.Regexp // May be nil
Expand All @@ -146,6 +147,12 @@ type sourcePrinter struct {
prettyNames map[string]string
}

// addrInfo holds information for an address we are interested in.
type addrInfo struct {
loc *profile.Location // Always non-nil
obj plugin.ObjFile // May be nil
}

// instructionInfo holds collected information for an instruction.
type instructionInfo struct {
objAddr uint64 // Address in object file (with base subtracted out)
Expand Down Expand Up @@ -207,6 +214,7 @@ func PrintWebList(w io.Writer, rpt *Report, obj plugin.ObjTool, maxFiles int) er
func newSourcePrinter(rpt *Report, obj plugin.ObjTool, sourcePath string) *sourcePrinter {
sp := &sourcePrinter{
reader: newSourceReader(sourcePath, rpt.options.TrimPath),
synth: newSynthCode(rpt.prof.Mapping),
objectTool: obj,
objects: map[string]plugin.ObjFile{},
sym: rpt.options.Symbol,
Expand All @@ -225,19 +233,21 @@ func newSourcePrinter(rpt *Report, obj plugin.ObjTool, sourcePath string) *sourc
}
}

addrs := map[uint64]bool{}
addrs := map[uint64]addrInfo{}
flat := map[uint64]int64{}
cum := map[uint64]int64{}

// Record an interest in the function corresponding to lines[index].
markInterest := func(addr uint64, lines []profile.Line, index int) {
fn := lines[index]
markInterest := func(addr uint64, loc *profile.Location, index int) {
fn := loc.Line[index]
if fn.Function == nil {
return
}
sp.interest[fn.Function.Name] = true
sp.interest[fn.Function.SystemName] = true
addrs[addr] = true
if _, ok := addrs[addr]; !ok {
addrs[addr] = addrInfo{loc, sp.objectFile(loc.Mapping)}
}
}

// See if sp.sym matches line.
Expand Down Expand Up @@ -270,15 +280,21 @@ func newSourcePrinter(rpt *Report, obj plugin.ObjTool, sourcePath string) *sourc
sp.prettyNames[line.Function.SystemName] = line.Function.Name
}

cum[loc.Address] += value
addr := loc.Address
if addr == 0 {
// Some profiles are missing valid addresses.
addr = sp.synth.address(loc)
}

cum[addr] += value
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is pre-existing and doesn't have to be changed (if it needs to be changed) in this CL, but: do we handle recursion correctly here? It feels that we'll double count the cumulative time if the same address is present multiple times in the stack.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think you are right. Let me look at that in a separate change.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hate to butt in here, but is there a chance that this is related to #720?

I'm not familiar with this code, but a flavor of #720 manifested for me with the following conditions:

  • using weblist instead of list
  • providing the binary for disassembly

and had the following behavior:

  • in a sample function that had 4 caller locations, the count was 5x what the expected value (e.g. that returned by list or weblist without the binary) was.
  • the printed assembly was printed 5 times

image

As far as I can tell, that fits the bill for the code in question here: the call tree for this function is only invoked for web printing and not the CLI interactions

if i == 0 {
flat[loc.Address] += value
flat[addr] += value
}

if sp.sym == nil || (address != nil && loc.Address == *address) {
if sp.sym == nil || (address != nil && addr == *address) {
// Interested in top-level entry of stack.
if len(loc.Line) > 0 {
markInterest(loc.Address, loc.Line, len(loc.Line)-1)
markInterest(addr, loc, len(loc.Line)-1)
}
continue
}
Expand All @@ -287,7 +303,7 @@ func newSourcePrinter(rpt *Report, obj plugin.ObjTool, sourcePath string) *sourc
matchFile := (loc.Mapping != nil && sp.sym.MatchString(loc.Mapping.File))
for j, line := range loc.Line {
if (j == 0 && matchFile) || matches(line) {
markInterest(loc.Address, loc.Line, j)
markInterest(addr, loc, j)
}
}
}
Expand All @@ -306,10 +322,11 @@ func (sp *sourcePrinter) close() {
}
}

func (sp *sourcePrinter) expandAddresses(rpt *Report, addrs map[uint64]bool, flat map[uint64]int64) {
func (sp *sourcePrinter) expandAddresses(rpt *Report, addrs map[uint64]addrInfo, flat map[uint64]int64) {
// We found interesting addresses (ones with non-zero samples) above.
// Get covering address ranges and disassemble the ranges.
ranges := sp.splitIntoRanges(rpt.prof, addrs, flat)
ranges, unprocessed := sp.splitIntoRanges(rpt.prof, addrs, flat)
sp.handleUnprocessed(addrs, unprocessed)

// Trim ranges if there are too many.
const maxRanges = 25
Expand Down Expand Up @@ -394,78 +411,115 @@ func (sp *sourcePrinter) expandAddresses(rpt *Report, addrs map[uint64]bool, fla
frames = lastFrames
}

// See if the stack contains a function we are interested in.
for i, f := range frames {
if !sp.interest[f.Func] {
continue
}
sp.addStack(addr, frames)
}
}
}

// Record sub-stack under frame's file/line.
fname := canonicalizeFileName(f.File)
file := sp.files[fname]
if file == nil {
file = &sourceFile{
fname: fname,
lines: map[int][]sourceInst{},
funcName: map[int]string{},
}
sp.files[fname] = file
}
callees := frames[:i]
stack := make([]callID, 0, len(callees))
for j := len(callees) - 1; j >= 0; j-- { // Reverse so caller is first
stack = append(stack, callID{
file: callees[j].File,
line: callees[j].Line,
})
}
file.lines[f.Line] = append(file.lines[f.Line], sourceInst{addr, stack})
func (sp *sourcePrinter) addStack(addr uint64, frames []plugin.Frame) {
// See if the stack contains a function we are interested in.
for i, f := range frames {
if !sp.interest[f.Func] {
continue
}

// Remember the first function name encountered per source line
// and assume that that line belongs to that function.
if _, ok := file.funcName[f.Line]; !ok {
file.funcName[f.Line] = f.Func
}
// Record sub-stack under frame's file/line.
fname := canonicalizeFileName(f.File)
file := sp.files[fname]
if file == nil {
file = &sourceFile{
fname: fname,
lines: map[int][]sourceInst{},
funcName: map[int]string{},
}
sp.files[fname] = file
}
callees := frames[:i]
stack := make([]callID, 0, len(callees))
for j := len(callees) - 1; j >= 0; j-- { // Reverse so caller is first
stack = append(stack, callID{
file: callees[j].File,
line: callees[j].Line,
})
}
file.lines[f.Line] = append(file.lines[f.Line], sourceInst{addr, stack})

// Remember the first function name encountered per source line
// and assume that that line belongs to that function.
if _, ok := file.funcName[f.Line]; !ok {
file.funcName[f.Line] = f.Func
}
}
}

// splitIntoRanges converts the set of addresses we are interested in into a set of address
// ranges to disassemble.
func (sp *sourcePrinter) splitIntoRanges(prof *profile.Profile, set map[uint64]bool, flat map[uint64]int64) []addressRange {
// List of mappings so we can stop expanding address ranges at mapping boundaries.
mappings := append([]*profile.Mapping{}, prof.Mapping...)
sort.Slice(mappings, func(i, j int) bool { return mappings[i].Start < mappings[j].Start })
// synthAsm is the special disassembler value used for instructions without an object file.
const synthAsm = ""

// handleUnprocessed handles addresses that were skipped by splitIntoRanges because they
// did not belong to a known object file.
func (sp *sourcePrinter) handleUnprocessed(addrs map[uint64]addrInfo, unprocessed []uint64) {
// makeFrames synthesizes a []plugin.Frame list for the specified address.
// The result will typically have length 1, but may be longer if address corresponds
// to inlined calls.
makeFrames := func(addr uint64) []plugin.Frame {
loc := addrs[addr].loc
stack := make([]plugin.Frame, 0, len(loc.Line))
for _, line := range loc.Line {
fn := line.Function
if fn == nil {
continue
}
stack = append(stack, plugin.Frame{
Func: fn.Name,
File: fn.Filename,
Line: int(line.Line),
})
}
return stack
}

var result []addressRange
addrs := make([]uint64, 0, len(set))
for addr := range set {
addrs = append(addrs, addr)
for _, addr := range unprocessed {
frames := makeFrames(addr)
x := instructionInfo{
objAddr: addr,
length: 1,
disasm: synthAsm,
}
if len(frames) > 0 {
x.file = frames[0].File
x.line = frames[0].Line
}
sp.insts[addr] = x

sp.addStack(addr, frames)
}
}

// splitIntoRanges converts the set of addresses we are interested in into a set of address
// ranges to disassemble. It also returns the set of addresses found that did not have an
// associated object file and were therefore not added to an address range.
func (sp *sourcePrinter) splitIntoRanges(prof *profile.Profile, addrMap map[uint64]addrInfo, flat map[uint64]int64) ([]addressRange, []uint64) {
// Partition addresses into two sets: ones with a known object file, and ones without.
var addrs, unprocessed []uint64
for addr, info := range addrMap {
if info.obj != nil {
addrs = append(addrs, addr)
} else {
unprocessed = append(unprocessed, addr)
}
}
sort.Slice(addrs, func(i, j int) bool { return addrs[i] < addrs[j] })

mappingIndex := 0
const expand = 500 // How much to expand range to pick up nearby addresses.
var result []addressRange
for i, n := 0, len(addrs); i < n; {
begin, end := addrs[i], addrs[i]
sum := flat[begin]
i++

// Advance to mapping containing addrs[i]
for mappingIndex < len(mappings) && mappings[mappingIndex].Limit <= begin {
mappingIndex++
}
if mappingIndex >= len(mappings) {
// TODO(sanjay): Report missed address and its samples.
break
}
m := mappings[mappingIndex]
obj := sp.objectFile(m)
if obj == nil {
// TODO(sanjay): Report missed address and its samples.
continue
}
info := addrMap[begin]
m := info.loc.Mapping
obj := info.obj // Non-nil because of the partitioning done above.

// Find following addresses that are close enough to addrs[i].
for i < n && addrs[i] <= end+2*expand && addrs[i] < m.Limit {
Expand All @@ -488,7 +542,7 @@ func (sp *sourcePrinter) splitIntoRanges(prof *profile.Profile, set map[uint64]b

result = append(result, addressRange{begin, end, obj, m, sum})
}
return result
return result, unprocessed
}

func (sp *sourcePrinter) initSamples(flat, cum map[uint64]int64) {
Expand Down Expand Up @@ -674,9 +728,12 @@ func (sp *sourcePrinter) functions(f *sourceFile) []sourceFunction {
return funcs
}

// objectFile return the object for the named file, opening it if necessary.
// objectFile return the object for the specified mapping, opening it if necessary.
// It returns nil on error.
func (sp *sourcePrinter) objectFile(m *profile.Mapping) plugin.ObjFile {
if m == nil {
return nil
}
if object, ok := sp.objects[m.File]; ok {
return object // May be nil if we detected an error earlier.
}
Expand Down Expand Up @@ -734,12 +791,28 @@ func printFunctionSourceLine(w io.Writer, lineNo int, flat, cum int64, lineConte
return
}

nestedInfo := false
cl := "deadsrc"
for _, an := range assembly {
if len(an.inlineCalls) > 0 || an.instruction != synthAsm {
nestedInfo = true
cl = "livesrc"
}
}

fmt.Fprintf(w,
"<span class=line> %6d</span> <span class=deadsrc> %10s %10s %8s %s </span>",
lineNo,
"<span class=line> %6d</span> <span class=%s> %10s %10s %8s %s </span>",
lineNo, cl,
valueOrDot(flat, rpt), valueOrDot(cum, rpt),
"", template.HTMLEscapeString(lineContents))
srcIndent := indentation(lineContents)
if nestedInfo {
srcIndent := indentation(lineContents)
printNested(w, srcIndent, assembly, reader, rpt)
}
fmt.Fprintln(w)
}

func printNested(w io.Writer, srcIndent int, assembly []assemblyInstruction, reader *sourceReader, rpt *Report) {
fmt.Fprint(w, "<span class=asm>")
var curCalls []callID
for i, an := range assembly {
Expand Down Expand Up @@ -772,6 +845,9 @@ func printFunctionSourceLine(w io.Writer, lineNo int, flat, cum int64, lineConte
template.HTMLEscapeString(filepath.Base(c.file)), c.line)
}
curCalls = an.inlineCalls
if an.instruction == synthAsm {
continue
}
text := strings.Repeat(" ", srcIndent+4+4*len(curCalls)) + an.instruction
fmt.Fprintf(w, " %8s %10s %10s %8x: %s <span class=unimportant>%s</span>\n",
"", valueOrDot(flat, rpt), valueOrDot(cum, rpt), an.address,
Expand All @@ -781,7 +857,7 @@ func printFunctionSourceLine(w io.Writer, lineNo int, flat, cum int64, lineConte
// would cause double-escaping of file name.
fileline)
}
fmt.Fprintln(w, "</span>")
fmt.Fprint(w, "</span>")
}

// printFunctionClosing prints the end of a function in a weblist report.
Expand Down
Loading