gccgo problems with pprof CPU profile #26595
Comments
|
Updating the skip count in the call to runtime.callers from runtime.sigprof seems to help: Oddly, this doesn't work for gollvm (there it looks like we need a skip count of 6). |
|
OK, here is a cleaned up version of the call stack at the point where SIGPROF invokes runtime.callers. The linking step for the gollvm version of the program is picking up system libgcc (as opposed to gccgo, which has its own copy of libgcc); the system libgcc has no debug info. In the gccgo case, when the libbacktrace callback is invoked, it sees the __morestack function name from the DWARF info and is able to exclude the frame immediately. In the gollvm case, the callback can't see the function name and has to include it into the trace -- this is what leads to the off-by-one error. |
|
Maybe we can explicitly discard the stack frame above |
|
@ianlancetaylor yes, I think that is the way to go. I played around with using a fixed skip count and then trying to detect/repair situations where the backtrace callback can't immediately prune away __morestack, but your approach is much simpler. One new hiccup is that with the fix in, I am now seeing test failures (sporadic) in the runtime/pprof package test. Representative example: I looked at the test and the bugs it was intended to fix -- unless I am mistaken it doesn't make much sense to run this test for gccgo (let me know if you concur). |
|
Change https://golang.org/cl/126175 mentions this issue: |
|
Change https://golang.org/cl/126316 mentions this issue: |
When writing stack frames to the pprof CPU profile machinery, it is
very important to insure that the frames emitted do not contain any
frames corresponding to artifacts of the profiling process itself
(signal handlers, sigprof, etc). This patch changes runtime.sigprof to
strip out those frames from the raw stack generated by
"runtime.callers".
Fixes golang/go#26595.
Reviewed-on: https://go-review.googlesource.com/126175
git-svn-id: svn+ssh://gcc.gnu.org/svn/gcc/trunk@263035 138bc75d-0d04-0410-961f-82ee72b054a4
In the CPU profile tests for gccgo, check to make sure that the runtime's sigprof handler itself doesn't appear in the profile. Add a "skip if gccgo" guard to one testpoint. Updates #26595 Change-Id: I92a44161d61f17b9305ce09532134edd229745a7 Reviewed-on: https://go-review.googlesource.com/126316 Run-TryBot: Than McIntosh <[email protected]> TryBot-Result: Gobot Gobot <[email protected]> Reviewed-by: Ian Lance Taylor <[email protected]>
What version of Go are you using (
go version)?Tip for Go:
go version devel +48c79734ff Fri Jul 20 20:08:15 2018 +0000 linux/amd64
Tip for Gccgo
go version go1.10.3 gccgo (GCC) 9.0.0 20180724 (experimental) linux/amd64
Does this issue reproduce with the latest release?
Yes.
What operating system and processor architecture are you using (
go env)?Linux/amd64.
What did you do?
When collecting pprof CPU profiles using a gccgo-based toolchain I've noticed that there are unfriendly artifacts in the profile data, at least relative to what I see with the main Go compiler.
Here is a repro recipe. This uses "dwarf-check", a very small application that inspects the generated DWARF for ELF + MachoO binaries, looking for a specific class of bugs/insanities.
Step 1: download and build the app to profile:
Step 2: run the program to generate a profile. This invocation runs the program on itself, emitting a CPU profile to cpu.p:
Step 3: inspect the profile using "pprof"
Repeat the steps above with the main Go, then with gccgo.
For gccgo:
NB: I am using upstream 'pprof', in case that matters (e.g. "go get -u github.com/google/pprof").
What did you expect to see?
For the profile collected with the main Go compiler, the top functions in the rofile look like:
What did you see instead?
For gccgo, I see the following top function in the profile:
The first problem seems to be that the sigprof handler itself is showing up in the profile... seems to me that this should not be happening, based on what I see in the regular Go CPU profile.
The second problem seems to be that there (apparently) bogus entries in the call stacks that are attributed to routines in libc.so, which I am pretty sure are not really being invoked (e.g. _IO_funlockfile).
Here is an excerpt from the "raw" dump from the gccgo run:
and the corresponding locations ("1", "2" above, etc) from later in the dump:
All of the entries in the profile start with the same sequence:
where is the actual function executing at the time SIGPROF was delivered. Location 4 is the suspicious one -- the IP is recorded as 0x7fa77097e0bf, which falls into the libc mapping:
Here 0x7fa77097e0bf - 0x7fa77096d000 is 0x110bf; disassembling the library in question I see:
In other words, the IP value in question doesn't really make sense as far as I can tell.
The text was updated successfully, but these errors were encountered: