From 5f172ea9327f36b1fdb6c4dff00f70bd2378dc67 Mon Sep 17 00:00:00 2001 From: Samuel Berthe Date: Sun, 5 Jul 2026 16:55:10 +0200 Subject: [PATCH 1/3] perf(stacktrace): defer frame symbolization to first read MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Program counters are still captured eagerly at error-creation time via runtime.Callers (the stack is gone afterwards, so this cannot move), but resolving PCs into file/function/line strings through runtime.CallersFrames — the dominant cost of error creation per CPU profile (~30% of BenchmarkNew) — now happens behind a sync.Once on first access to Stacktrace()/Sources()/StackFrames(). Most errors in production are created, checked against nil, and discarded without ever being formatted (BenchmarkBuilderCreatedNotRead models this), so they no longer pay for symbolization at all. Errors that are formatted pay the same total cost as before, on first read. Filtering rules, their inputs (StackTraceMaxDepth is snapshotted at capture time) and output are unchanged. GOROOT and the examples-package prefix are now computed once at init instead of per error — runtime.GOROOT re-reads an env var on every call. This implements the existing "@TODO: filtering should be done lazily, not at creation time". benchstat (linux/amd64, Intel Xeon @ 2.80GHz, -count=6 -cpu=1): │ before │ after │ New 4.335µ ± 3% 1.779µ ± 1% -58.96% (p=0.002 n=6) Wrap 4.618µ ± 3% 1.517µ ± 1% -67.15% (p=0.002 n=6) NewStacktrace 4.506µ ± 5% 1.773µ ± 4% -60.65% (p=0.002 n=6) CreatedNotRead/simple/Wrap 5.689µ ± 4% 1.837µ ± 3% -67.72% (p=0.002 n=6) CreatedNotRead/rich/chain=7 5.333µ ± 3% 2.042µ ± 1% -61.71% (p=0.002 n=6) CreateThenStacktrace 6.405µ ± 7% 6.302µ ± 4% ~ (p=0.589 n=6) ToMap 8.644µ ± 5% 8.316µ ± 3% -3.80% (p=0.026 n=6) │ B/op │ B/op │ New 2.336Ki ± 0% 1.273Ki ± 0% -45.48% (p=0.002 n=6) Wrap 2.320Ki ± 0% 1.258Ki ± 0% -45.79% (p=0.002 n=6) CreateThenStacktrace 3.477Ki ± 0% 3.523Ki ± 0% +1.35% (p=0.002 n=6) BenchmarkCreateThenStacktrace is added in this commit to keep the deferred cost measurable: the existing read benchmarks reuse a single error, which would otherwise amortize resolution away. --- benchmarks/benchmark_test.go | 15 ++++ error.go | 4 +- stacktrace.go | 140 +++++++++++++++++++++++------------ stacktrace_test.go | 23 +++--- 4 files changed, 120 insertions(+), 62 deletions(-) diff --git a/benchmarks/benchmark_test.go b/benchmarks/benchmark_test.go index 4c6b818..e57976e 100644 --- a/benchmarks/benchmark_test.go +++ b/benchmarks/benchmark_test.go @@ -190,3 +190,18 @@ func BenchmarkRecover(b *testing.B) { _ = oops.Recover(func() { panic("test panic") }) } } + +// BenchmarkCreateThenStacktrace measures the combined cost of creating an +// error and immediately formatting its stack trace. Stack frame symbolization +// is deferred to the first read, so this benchmark exposes the full +// create+resolve+format cost that the single-error read benchmarks above +// (ToMap, LogValue) amortize away by reusing one error across iterations. +func BenchmarkCreateThenStacktrace(b *testing.B) { + inner := errors.New("inner") + b.ReportAllocs() + for i := 0; i < b.N; i++ { + err := oops.Wrap(inner) + oopsErr, _ := oops.AsOops(err) + _ = oopsErr.Stacktrace() + } +} diff --git a/error.go b/error.go index 85f6e8f..d463057 100644 --- a/error.go +++ b/error.go @@ -514,7 +514,7 @@ func (o OopsError) rawBlocks() []outputBlock { var blocks []outputBlock recursive(o, func(e OopsError) bool { if e.stacktrace != nil { - filteredFrames := applyFrameSkip(e.stacktrace.frames) + filteredFrames := applyFrameSkip(e.stacktrace.resolvedFrames()) if len(filteredFrames) > 0 { blocks = append(blocks, outputBlock{e.err, e.msg, filteredFrames}) } @@ -544,7 +544,7 @@ func (o OopsError) StackFrames() []runtime.Frame { if o.stacktrace == nil { return nil } - filtered := applyFrameSkip(o.stacktrace.frames) + filtered := applyFrameSkip(o.stacktrace.resolvedFrames()) frames := make([]runtime.Frame, len(filtered)) for i, f := range filtered { frames[i] = runtime.Frame{ diff --git a/stacktrace.go b/stacktrace.go index ce2a68b..8a65f55 100644 --- a/stacktrace.go +++ b/stacktrace.go @@ -7,6 +7,7 @@ import ( "slices" "strconv" "strings" + "sync" "github.com/samber/lo" ) @@ -61,6 +62,13 @@ var ( // This is determined at package initialization time and used // to identify frames that should be excluded from stack traces. packageName = reflect.TypeOf(fake{}).PkgPath() + + // packageNameExamples and goroot are filtering inputs that never change + // at runtime; computing them once here keeps them out of the per-frame + // resolution loop (runtime.GOROOT in particular re-reads an env var on + // every call). + packageNameExamples = packageName + "/examples/" + goroot = runtime.GOROOT() ) // oopsStacktraceFrame represents a single frame in a stack trace. @@ -98,11 +106,82 @@ func (frame *oopsStacktraceFrame) String() string { // oopsStacktrace represents a complete stack trace with multiple frames. // It contains a span identifier for correlation and an ordered list // of stack frames representing the call hierarchy. +// +// Program counters are captured eagerly at error-creation time (the stack is +// gone afterwards), but resolving them into file/function/line strings is +// deferred to the first read: symbolization via runtime.CallersFrames is the +// dominant cost of error creation, and most errors are created, checked +// against nil, and discarded without their stack trace ever being formatted. type oopsStacktrace struct { - span string // Unique identifier for the stack trace + span string + + // pcs holds the raw program counters captured by runtime.Callers, + // consumed (and set to nil) by resolve on first access. + pcs []uintptr + // maxDepth snapshots StackTraceMaxDepth at capture time so a later + // change of the global does not alter already-captured traces. + maxDepth int + + once sync.Once frames []oopsStacktraceFrame // Ordered list of stack frames (most recent first) } +// resolvedFrames symbolizes the captured program counters on first call and +// returns the filtered frames. Safe for concurrent use. +func (st *oopsStacktrace) resolvedFrames() []oopsStacktraceFrame { + st.once.Do(st.resolve) + return st.frames +} + +// resolve converts raw program counters into filtered, display-ready frames. +// It applies the same filtering rules that previously ran at capture time: +// frames from GOROOT and from this package are excluded (except examples and +// tests), and at most maxDepth frames are kept. +func (st *oopsStacktrace) resolve() { + if len(st.pcs) == 0 { + return + } + + frames := make([]oopsStacktraceFrame, 0, st.maxDepth) + + // Iterate over the captured frames + iter := runtime.CallersFrames(st.pcs) + for len(frames) < st.maxDepth { + frame, more := iter.Next() + + // Clean up the file path by removing Go path prefixes + file := removeGoPath(frame.File) + + // Apply frame filtering logic + isGoPkg := len(goroot) > 0 && strings.Contains(file, goroot) // skip frames in GOROOT if it's set + isOopsPkg := strings.Contains(file, packageName) // skip frames in this package + isExamplePkg := strings.Contains(file, packageNameExamples) // do not skip frames in this package examples + isTestPkg := strings.Contains(file, "_test.go") // do not skip frames in tests + + // Include frame if it passes all filtering criteria + if !isGoPkg && (!isOopsPkg || isExamplePkg || isTestPkg) { + frames = append(frames, oopsStacktraceFrame{ + pc: frame.PC, + // Extract a short, readable function name — only for frames + // that are kept, since the runtime/oops frames filtered out + // above would pay the string processing for nothing. + function: shortFuncName(frame.Function), + file: file, + line: frame.Line, + rawFile: frame.File, + rawFunction: frame.Function, + }) + } + + if !more { + break + } + } + + st.frames = frames + st.pcs = nil +} + // Error implements the error interface for stack traces. // This allows stack traces to be used directly as errors if needed. func (st *oopsStacktrace) Error() string { @@ -136,7 +215,7 @@ func (st *oopsStacktrace) String(deepestFrame string) string { } // Iterate through all frames and format them - for _, frame := range st.frames { + for _, frame := range st.resolvedFrames() { if frame.file != "" { currentFrame := frame.String() @@ -170,11 +249,12 @@ func (st *oopsStacktrace) String(deepestFrame string) string { // - header: Formatted string like "main.go:42 main()" // - body: Slice of strings containing source code lines with line numbers func (st *oopsStacktrace) Source() (string, []string) { - if len(st.frames) == 0 { + frames := st.resolvedFrames() + if len(frames) == 0 { return "", []string{} } - firstFrame := st.frames[0] + firstFrame := frames[0] header := firstFrame.String() body := getSourceFromFrame(firstFrame) @@ -201,59 +281,21 @@ func (st *oopsStacktrace) Source() (string, []string) { // // stack := newStacktrace("span-123", 0) // fmt.Println(stack.String("")) -// -// @TODO: filtering should be done lazily, not at creation time. func newStacktrace(span string, skip int) *oopsStacktrace { - frames := make([]oopsStacktraceFrame, 0, StackTraceMaxDepth) - // Capture all program counters in a single batch call. // The buffer must be large enough to hold the desired user frames PLUS the - // oops-internal and runtime frames that will be filtered out during iteration. - // Cap at 512 to avoid huge allocations when StackTraceMaxDepth is set to a - // very large value. + // oops-internal and runtime frames that will be filtered out during + // resolution. Cap at 512 to avoid huge allocations when StackTraceMaxDepth + // is set to a very large value. bufSize := min(StackTraceMaxDepth*3+20, 512) pcs := make([]uintptr, bufSize) n := runtime.Callers(1+skip, pcs) - pcs = pcs[:n] - - // Define package name patterns for filtering (computed once, outside the loop) - packageNameExamples := packageName + "/examples/" - goroot := runtime.GOROOT() - - // Iterate over the captured frames - iter := runtime.CallersFrames(pcs) - for len(frames) < StackTraceMaxDepth { - frame, more := iter.Next() - - // Clean up the file path by removing Go path prefixes - file := removeGoPath(frame.File) - - // Apply frame filtering logic - isGoPkg := len(goroot) > 0 && strings.Contains(file, goroot) // skip frames in GOROOT if it's set - isOopsPkg := strings.Contains(file, packageName) // skip frames in this package - isExamplePkg := strings.Contains(file, packageNameExamples) // do not skip frames in this package examples - isTestPkg := strings.Contains(file, "_test.go") // do not skip frames in tests - - // Include frame if it passes all filtering criteria - if !isGoPkg && (!isOopsPkg || isExamplePkg || isTestPkg) { - frames = append(frames, oopsStacktraceFrame{ - pc: frame.PC, - function: shortFuncName(frame.Function), - file: file, - line: frame.Line, - rawFile: frame.File, - rawFunction: frame.Function, - }) - } - - if !more { - break - } - } + // Symbolization and filtering happen lazily in resolve, on first read. return &oopsStacktrace{ - span: span, - frames: frames, + span: span, + pcs: pcs[:n], + maxDepth: StackTraceMaxDepth, } } diff --git a/stacktrace_test.go b/stacktrace_test.go index 49e0c3d..a3c9a2d 100644 --- a/stacktrace_test.go +++ b/stacktrace_test.go @@ -52,21 +52,22 @@ func TestStacktrace(t *testing.T) { path := strings.Replace(bi.Path, ".test", "", 1) // starting go1.24, go adds ".test" to the path when running tests - if st.frames != nil { - for _, f := range st.frames { + frames := st.resolvedFrames() + if frames != nil { + for _, f := range frames { is.Contains(f.file, path, "frame file %s should contain %s", f.file, path) } - is.Len(st.frames, 7, "expected 7 frames") + is.Len(frames, 7, "expected 7 frames") - if len(st.frames) == 7 { - is.Equal("f", (st.frames)[0].function) - is.Equal("e", (st.frames)[1].function) - is.Equal("d", (st.frames)[2].function) - is.Equal("c", (st.frames)[3].function) - is.Equal("b", (st.frames)[4].function) - is.Equal("a", (st.frames)[5].function) - is.Equal("TestStacktrace", (st.frames)[6].function) + if len(frames) == 7 { + is.Equal("f", frames[0].function) + is.Equal("e", frames[1].function) + is.Equal("d", frames[2].function) + is.Equal("c", frames[3].function) + is.Equal("b", frames[4].function) + is.Equal("a", frames[5].function) + is.Equal("TestStacktrace", frames[6].function) } } } From 785a90b14f39afddf813201482a916e25eda8031 Mon Sep 17 00:00:00 2001 From: Samuel Berthe Date: Sun, 5 Jul 2026 17:01:06 +0200 Subject: [PATCH 2/3] Potential fix for pull request finding Co-authored-by: Copilot Autofix powered by AI <175728472+Copilot@users.noreply.github.com> --- stacktrace.go | 1 + 1 file changed, 1 insertion(+) diff --git a/stacktrace.go b/stacktrace.go index 8a65f55..7b9396a 100644 --- a/stacktrace.go +++ b/stacktrace.go @@ -139,6 +139,7 @@ func (st *oopsStacktrace) resolvedFrames() []oopsStacktraceFrame { // tests), and at most maxDepth frames are kept. func (st *oopsStacktrace) resolve() { if len(st.pcs) == 0 { + st.pcs = nil return } From 9046a7a77f796b6e3f4a3b6d16c32a6b307db90c Mon Sep 17 00:00:00 2001 From: Samuel Berthe Date: Sun, 5 Jul 2026 17:02:02 +0200 Subject: [PATCH 3/3] Potential fix for pull request finding Co-authored-by: Copilot Autofix powered by AI <175728472+Copilot@users.noreply.github.com> --- stacktrace.go | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/stacktrace.go b/stacktrace.go index 7b9396a..a0f6a36 100644 --- a/stacktrace.go +++ b/stacktrace.go @@ -143,7 +143,8 @@ func (st *oopsStacktrace) resolve() { return } - frames := make([]oopsStacktraceFrame, 0, st.maxDepth) + capDepth := min(st.maxDepth, len(st.pcs)) + frames := make([]oopsStacktraceFrame, 0, capDepth) // Iterate over the captured frames iter := runtime.CallersFrames(st.pcs)