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)
- pprof: proper source release HOT 1
- Add `period` (sampling) information in pprof web viewer.
- heap samples are not what I expect HOT 1
- How to interpret top? HOT 1
- weblist gives wrong flat count HOT 4
- otool-classic unable to find /usr/lib libraries on MacOS
- why printWebSource is much complex than printSource HOT 1
- How can I located the function in pprof with method has "*" ? HOT 1
- source: duplicate (func, file) pair HOT 1
- pprof -http no display source HOT 2
- Would pprof be open to using D2 (pure Go graph engine)? HOT 2
- upgrade d3-flamegraph to fix security vuln HOT 2
- FR: Public interface / function for reporting HOT 2
- Drops in numbers with -alloc_space option HOT 3
- Proto: document how function names should be structured HOT 1
- SVG heap graph inconvenient for color blind HOT 3
- Proposal: add Discriminator field to Line message HOT 6
- quotes in CPU profile tags not escaped properly HOT 1
- Jsjdj
- Switch to the new flame graph implementation by default and remove d3 dependency HOT 3
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.