Comments (5)
Thanks for reporting this. Here some investigation notes.
Program I used to reproduce:
package rfstack
import (
"fmt"
"os"
"reflect"
"runtime"
"testing"
)
var data []byte
type P struct{}
func alloc() {
stk := make([]uintptr, 32)
stk = stk[:runtime.Callers(0, stk)]
frames := runtime.CallersFrames(stk)
for {
frame, more := frames.Next()
fmt.Fprintf(os.Stderr, "%#x\t%s\n", frame.PC, frame.Function)
if !more {
break
}
}
data = make([]byte, 16*1024*1024)
}
func caller(rec int) {
if rec == 0 {
alloc()
} else {
caller(rec - 1)
}
}
func (p *P) Foo() {
caller(5)
}
func hotspot() {
for i := 0; i < (1 << 31); i++ {
}
}
func (p *P) Bar() {
hotspot()
}
func TestHeap(t *testing.T) {
var p P
reflect.ValueOf(&p).MethodByName("Foo").Call([]reflect.Value{})
}
func TestCPU(t *testing.T) {
var p P
reflect.ValueOf(&p).MethodByName("Bar").Call([]reflect.Value{})
}
Running it I can see the stack looks like what it is expected to look like:
$ go test -v -memprofile mem.prof rfstack_test.go
=== RUN TestHeap
0x406f4d runtime.Callers
0x479fb2 command-line-arguments.alloc
0x47a20b command-line-arguments.caller
0x47a221 command-line-arguments.caller
0x47a221 command-line-arguments.caller
0x47a221 command-line-arguments.caller
0x47a221 command-line-arguments.caller
0x47a221 command-line-arguments.caller
0x47a259 command-line-arguments.(*P).Foo
0x4566cb runtime.call32
0x4e0f37 reflect.Value.call
0x4e0853 reflect.Value.Call
0x47a371 command-line-arguments.TestHeap
0x4750d0 testing.tRunner
0x4591a0 runtime.goexit
--- PASS: TestHeap (0.00s)
=== RUN TestCPU
--- PASS: TestCPU (0.67s)
PASS
ok command-line-arguments 0.711s
and the heap profile file has the 0x47a222 value repeated 5 times too, so the stack frames below the reflection frame are in the profile:
$ cat mem.prof
heap profile: 1: 16777216 [1: 16777216] @ heap/1048576
1: 16777216 [1: 16777216] @ 0x47a174 0x47a20c 0x47a222 0x47a222 0x47a222 0x47a222 0x47a222 0x47a25a 0x4566cc 0x4e0f38 0x4e0854 0x47a372 0x4750d1 0x4591a1
# runtime.MemStats
# Alloc = 16925600
# TotalAlloc = 16957344
# Sys = 22202616
# Lookups = 4
# Mallocs = 488
# Frees = 182
# HeapAlloc = 16925600
# HeapSys = 17301504
# HeapIdle = 57344
# HeapInuse = 17244160
# HeapReleased = 0
# HeapObjects = 306
# Stack = 524288 / 524288
# MSpan = 9920 / 16384
# MCache = 14400 / 16384
# BuckHashSys = 1442375
# NextGC = 17949064
# PauseNs = [238794 279742 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]
# NumGC = 2
# DebugGC = false
Yet, pprof output seems to have stripped all frames from runtime.call32 and below:
$ pprof rfstack.test mem.prof
File: rfstack.test
Type: space
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 16MB, 100% of 16MB total
flat flat% sum% cum cum%
16MB 100% 100% 16MB 100% reflect.Value.call /usr/lib/google-golang/src/reflect/value.go
0 0% 100% 16MB 100% command-line-arguments.TestHeap /usr/local/google/home/aalexand/projects/golang-reflection-stack/rfstack_test.go
0 0% 100% 16MB 100% reflect.Value.Call /usr/lib/google-golang/src/reflect/value.go
0 0% 100% 16MB 100% runtime.goexit /usr/lib/google-golang/src/runtime/asm_amd64.s
0 0% 100% 16MB 100% testing.tRunner /usr/lib/google-golang/src/testing/testing.go
(pprof) tree
Showing nodes accounting for 16MB, 100% of 16MB total
----------------------------------------------------------+-------------
flat flat% sum% cum cum% calls calls% + context
----------------------------------------------------------+-------------
16MB 100% | reflect.Value.Call /usr/lib/google-golang/src/reflect/value.go
16MB 100% 100% 16MB 100% | reflect.Value.call /usr/lib/google-golang/src/reflect/value.go
----------------------------------------------------------+-------------
16MB 100% | testing.tRunner /usr/lib/google-golang/src/testing/testing.go
0 0% 100% 16MB 100% | command-line-arguments.TestHeap /usr/local/google/home/aalexand/projects/golang-reflection-stack/rfstack_test.go
16MB 100% | reflect.Value.Call /usr/lib/google-golang/src/reflect/value.go
----------------------------------------------------------+-------------
16MB 100% | command-line-arguments.TestHeap /usr/local/google/home/aalexand/projects/golang-reflection-stack/rfstack_test.go
0 0% 100% 16MB 100% | reflect.Value.Call /usr/lib/google-golang/src/reflect/value.go
16MB 100% | reflect.Value.call /usr/lib/google-golang/src/reflect/value.go
----------------------------------------------------------+-------------
0 0% 100% 16MB 100% | runtime.goexit /usr/lib/google-golang/src/runtime/asm_amd64.s
16MB 100% | testing.tRunner /usr/lib/google-golang/src/testing/testing.go
----------------------------------------------------------+-------------
16MB 100% | runtime.goexit /usr/lib/google-golang/src/runtime/asm_amd64.s
0 0% 100% 16MB 100% | testing.tRunner /usr/lib/google-golang/src/testing/testing.go
16MB 100% | command-line-arguments.TestHeap /usr/local/google/home/aalexand/projects/golang-reflection-stack/rfstack_test.go
----------------------------------------------------------+-------------
I first thought this could be a symbolization issue, but the addresses of interest symbolize fine through the binary:
$ addr2line -f -e rfstack.test 0x47a222 0x47a25a
command-line-arguments.caller
/usr/local/google/home/aalexand/projects/golang-reflection-stack/rfstack_test.go:36
command-line-arguments.(*P).Foo
/usr/local/google/home/aalexand/projects/golang-reflection-stack/rfstack_test.go:40
from pprof.
What happens is that profile. RemoveUninteresting()
turns out to be overly aggressively pruning the frames for the use case in hand. For heap profiles the "drop" pattern list includes runtime\..*
regular expression and so the frame runtime.call32 matches it and gets dropped along with all the callee frames.
There is the counterpart "keep" pattern list which only includes runtime\.panic
item today, and I think the fix is to add runtime\.call32
there, but I want to double-check with the Go team.
from pprof.
Adding
`runtime\.call32`,
`runtime\.call64`,
to the allocSkipRxStr list changes the pprof output to the expected:
File: rfstack.test
Type: space
Showing nodes accounting for 16MB, 100% of 16MB total
flat flat% sum% cum cum%
16MB 100% 100% 16MB 100% command-line-arguments.alloc /usr/local/google/home/aalexand/projects/golang-reflection-stack/rfstack_test.go
0 0% 100% 16MB 100% command-line-arguments.(*P).Foo /usr/local/google/home/aalexand/projects/golang-reflection-stack/rfstack_test.go
0 0% 100% 16MB 100% command-line-arguments.TestHeap /usr/local/google/home/aalexand/projects/golang-reflection-stack/rfstack_test.go
0 0% 100% 16MB 100% command-line-arguments.caller /usr/local/google/home/aalexand/projects/golang-reflection-stack/rfstack_test.go
0 0% 100% 16MB 100% reflect.Value.Call /usr/lib/google-golang/src/reflect/value.go
0 0% 100% 16MB 100% reflect.Value.call /usr/lib/google-golang/src/reflect/value.go
0 0% 100% 16MB 100% runtime.call32 /usr/lib/google-golang/src/runtime/asm_amd64.s
0 0% 100% 16MB 100% runtime.goexit /usr/lib/google-golang/src/runtime/asm_amd64.s
0 0% 100% 16MB 100% testing.tRunner /usr/lib/google-golang/src/testing/testing.go
The discussion on golang-nuts hasn't been too active so far, so I'll file a Go bug to get it going.
from pprof.
@aalexand great, thanks for investigating. Glad to hear this might get fixed.
from pprof.
Filed golang/go#18077.
from pprof.
Related Issues (20)
- Set Function.start_line when symbolizing HOT 3
- Patch CVE for d3-color HOT 1
- make sources/sinks a different color HOT 2
- Canvas size related to initial size of a graph, should use the full space
- New flamegraph: 'hover shows details on the top' from old flame-graph missing HOT 2
- Nice to have: 'grab' cursor when dragging the graph HOT 2
- How to load debug symbols from separately installed `-dbgsym` packages? HOT 7
- don't need profile after convert HOT 1
- Pprof does not resolve symbols HOT 2
- [Help Needed] How to Accelerate `pprof -top` Command Execution for Profiling Data? HOT 2
- extended dependencies because of browser test HOT 4
- panics if profile is not found HOT 1
- The calling relationship of CPU profile results is wrong HOT 3
- New flamegraph cannot copy strings
- Unknown heap traces HOT 1
- list [-e] [-f format] [-json] [build flags] HOT 1
- list [-e] [-f format] [-json] [build flags] ...
- How to efficiently compress pprof files? HOT 1
- Add release tag HOT 1
- Symbolization seems to fail with buildID mismatch error when a profiling target application is run by invoking a linker directly HOT 1
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from pprof.