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.

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

runtime: runtime_expandFinalInlineFrame doesn't skip trailing wrappers #58288

Closed
korniltsev opened this issue Feb 3, 2023 · 6 comments
Closed
Assignees
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone

Comments

@korniltsev
Copy link
Contributor

korniltsev commented Feb 3, 2023

What version of Go are you using (go version)?

$ go version
go version devel go1.21-9222a01e65 Fri Feb 3 04:37:17 2023 +0000 darwin/amd64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/korniltsev/Library/Caches/go-build"
GOENV="/Users/korniltsev/Library/Application Support/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOINSECURE=""
GOMODCACHE="/Users/korniltsev/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/korniltsev/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/Users/korniltsev/github/go-darwin-amd64-bootstrap"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/Users/korniltsev/github/go-darwin-amd64-bootstrap/pkg/tool/darwin_amd64"
GOVCS=""
GOVERSION="devel go1.21-9222a01e65 Fri Feb 3 04:37:17 2023 +0000"
GCCGO="gccgo"
GOAMD64="v1"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/Users/korniltsev/github/go/src/go.mod"
GOWORK=""
CGO_CFLAGS="-O2 -g"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-O2 -g"
CGO_FFLAGS="-O2 -g"
CGO_LDFLAGS="-O2 -g"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -arch x86_64 -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/2t/v1n4q5yj48315c_ccftr_d_c0000gn/T/go-build2988258767=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

I noticed an inconsistency in handling inline wrapper functions between runtime_expandFinalInlineFrame and gentraceback.
gentraceback ignores a wrapper function with an inlined function and runtime_expandFinalInlineFrame does not ignore and append to stacktrace. Because of that profileBuilder.appendLocsForStack may emit different locations for exactly the same stack, depending on the order of processed records. For example if a builder sees a wrapped function for the first time as a last item in the stack, it will be expanded with an extra pc of a wrapped function and emit a location with two functions. At the same time if a builder sees a wrapped function for the first time in the middle of the stack, it will emit a location with one function.
In order to reproduce the issue with pprof profiles you need to have a profile sample with a stacktrace ending(truncated) with a wrapper function(for example a heap profile with a stack[31] pointing to a wrapped inlined function).
An easier way to reproduce the inconsistency calling runtime_expandFinalInlineFrame directly:
https://go.dev/play/p/FW8j4zXCrqN

What did you expect to see?

======== stack ========
108a6f3 runtime.Callers
108a6dd main.stackHandler.handle
108a0d2 main.main
1031127 runtime.main
105ad21 runtime.goexit
======== truncated ========
108a6f3 runtime.Callers
108a6dd main.stackHandler.handle
======== expanded ========
108a6f3 runtime.Callers
108a6dd main.stackHandler.handle

What did you see instead?

======== stack ========
108a6d3 runtime.Callers
108a6bd main.stackHandler.handle
108a0b2 main.main
1031127 runtime.main
105ad01 runtime.goexit
======== truncated ========
108a6d3 runtime.Callers
108a6bd main.stackHandler.handle
======== expanded ========
108a6d3 runtime.Callers
108a6bd main.stackHandler.handle
108a6b8 main.(*stackHandler).handle

Possible fix

diff --git a/src/runtime/symtab.go b/src/runtime/symtab.go
index dead27e5f2..da83fd93ea 100644
--- a/src/runtime/symtab.go
+++ b/src/runtime/symtab.go
@@ -230,7 +230,11 @@ func runtime_expandFinalInlineFrame(stk []uintptr) []uintptr {
        }

        // N.B. we want to keep the last parentPC which is not inline.
-       stk = append(stk, pc)
+       if f.funcID == funcID_wrapper && elideWrapperCalling(lastFuncID) {
+               // Ignore wrapper functions (except when they trigger panics).
+       } else {
+               stk = append(stk, pc)
+       }

        return stk
 }

CC @prattmic

@seankhliao seankhliao changed the title affected/package: runtime.runtime_expandFinalInlineFrame runtime: runtime_expandFinalInlineFrame Feb 3, 2023
@gopherbot gopherbot added the compiler/runtime Issues related to the Go compiler and/or runtime. label Feb 3, 2023
@prattmic prattmic changed the title runtime: runtime_expandFinalInlineFrame runtime: runtime_expandFinalInlineFrame doesn't skip trailing wrappers Feb 3, 2023
@prattmic prattmic added this to the Go1.21 milestone Feb 3, 2023
@prattmic
Copy link
Member

prattmic commented Feb 3, 2023

Thanks, good catch. Would you like to send that patch as a CL yourself?

@mknyszek mknyszek added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Feb 3, 2023
@mknyszek
Copy link
Contributor

mknyszek commented Feb 3, 2023

CC @golang/runtime

@cherrymui
Copy link
Member

For profile, maybe we want to always include the wrapper frame, so it matches more closely to what actually happened at runtime? Not sure if this can be done easily with the current structure.

@prattmic
Copy link
Member

prattmic commented Feb 3, 2023

Even if so, runtime_expandFinalInlineFrame would be the wrong play for that policy. runtime_expandFinalInlineFrame is only used on the very last PC in the stack (which might be a truncated inline stack due to the 64 PC limit), not on all PCs.

@cherrymui
Copy link
Member

I agree that runtime_expandFinalInlineFrame would be the wrong play. I'm just wondering if we could instead include the wrapper frames consistently.

@gopherbot
Copy link

Change https://go.dev/cl/465097 mentions this issue: runtime: skip trailing wrappers in runtime_expandFinalInlineFrame

johanbrandhorst pushed a commit to Pryz/go that referenced this issue Feb 12, 2023
The existing runtime_expandFinalInlineFrame implementation doesn't skip trailing wrappers, but
gentraceback does skip wrapper functions.
This change makes runtime_expandFinalInlineFrame handling wrapper functions consistent to gentraceback.

Fixes golang#58288

Change-Id: I1b0e2c10b0a89bcb1e787b98d27730cb40a34406
Reviewed-on: https://go-review.googlesource.com/c/go/+/465097
Reviewed-by: Michael Pratt <mpratt@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Auto-Submit: Michael Pratt <mpratt@google.com>
Run-TryBot: Michael Pratt <mpratt@google.com>
Reviewed-by: David Chase <drchase@google.com>
@golang golang locked and limited conversation to collaborators Feb 9, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Development

No branches or pull requests

5 participants