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.

Sign up for GitHub

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

Jump to bottom

Start showing inlined functions in stack trace #208

Merged
merged 5 commits into from
Feb 19, 2024
Merged

Start showing inlined functions in stack trace #208

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
1111313
Start showing inlined functions in stack trace
DariaKunoichi Feb 14, 2024
36e411d
Handle tests for inlined functions for golang < 1.11
DariaKunoichi Feb 15, 2024
e004cea
Check version manually without external packages
DariaKunoichi Feb 15, 2024
a41982d
Fix notifier tests
DariaKunoichi Feb 19, 2024
f5fead2
Added change to CHANGELOG
DariaKunoichi Feb 19, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 7 additions & 0 deletions CHANGELOG.md
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,12 @@
# Changelog

## TBD

### Bug fixes

* Start showing inlined functions in stack trace
[#208](https://github.com/bugsnag/bugsnag-go/pull/208)

## 2.2.0 (2022-10-12)

### Enhancements
Expand Down
35 changes: 24 additions & 11 deletions v2/errors/error.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,9 +4,10 @@ package errors
import (
"bytes"
"fmt"
"github.com/pkg/errors"
"reflect"
"runtime"

"github.com/pkg/errors"
)

// The maximum number of stackframes on any error.
Expand Down Expand Up @@ -64,7 +65,7 @@ func New(e interface{}, skip int) *Error {
trace := e.StackTrace()
stack := make([]uintptr, len(trace))
for i, ptr := range trace {
stack[i] = uintptr(ptr) - 1
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can you include some justification on the PR description for this change? It seems fairly fundamental to all our stacktrace reporting, so I'm surprised it's incorrect.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It is actually moving the whole stack to ignore the newest item. With the -1 added the stack for example looks like:
PTR: main.A
STACK[0]: main.B
PTR: main.B
STACK[1]: main.C
PTR: main.C
STACK[2]: main.main
PTR: main.main
STACK[3]: main.main
PTR: runtime.main
STACK[4]: runtime.main
PTR: runtime.goexit
STACK[5]: runtime.goexit

after changing to not modify the uintptr address:
PTR: main.A
STACK[0]: main.A
PTR: main.B
STACK[1]: main.B
PTR: main.C
STACK[2]: main.C
PTR: main.main
STACK[3]: main.main
PTR: runtime.main
STACK[4]: runtime.main
PTR: runtime.goexit
STACK[5]: runtime.goexit

stack[i] = uintptr(ptr)
}
return &Error{
Err: e,
Expand Down Expand Up @@ -132,20 +133,32 @@ func (err *Error) StackFrames() []StackFrame {
if err.frames == nil {
callers := runtime.CallersFrames(err.stack)
err.frames = make([]StackFrame, 0, len(err.stack))

for frame, more := callers.Next(); more; frame, more = callers.Next() {
if frame.Func == nil {
// Ignore fully inlined functions
continue
}
pkg, name := packageAndName(frame.Func)
err.frames = append(err.frames, StackFrame{
processedStackFrame := StackFrame{
function: frame.Func,
File: frame.File,
LineNumber: frame.Line,
Name: name,
Package: pkg,
ProgramCounter: frame.PC,
})
}

frameFunc := frame.Func
if frameFunc == nil {
newFrameFunc := runtime.FuncForPC(frame.PC)
if newFrameFunc != nil {
file, line := newFrameFunc.FileLine(frame.PC)
// Unwrap fully inlined functions
processedStackFrame.File = file
processedStackFrame.LineNumber = line
processedStackFrame.function = newFrameFunc
frameFunc = newFrameFunc
}
}

pkg, name := packageAndName(frameFunc)
processedStackFrame.Name = name
processedStackFrame.Package = pkg
err.frames = append(err.frames, processedStackFrame)
}
}

Expand Down
24 changes: 22 additions & 2 deletions v2/errors/error_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,7 @@ import (

// fixture functions doing work to avoid inlining
func a(i int) error {
if b(i + 5) && b(i + 6) {
if b(i+5) && b(i+6) {
return nil
}
return fmt.Errorf("not gonna happen")
Expand Down Expand Up @@ -47,8 +47,28 @@ func TestParsePanicStack(t *testing.T) {
}
expected := []StackFrame{
StackFrame{Name: "TestParsePanicStack.func1", File: "errors/error_test.go"},
StackFrame{Name: "a", File: "errors/error_test.go", LineNumber: 16},
StackFrame{Name: "gopanic"},
}

golangVersion := runtime.Version()

// TODO remove this after dropping support for Golang 1.11
// Golang version < 1.12 cannot unwrap inlined functions correctly.
if strings.HasPrefix(golangVersion, "go1.11") {
expected = append(expected,
StackFrame{Name: "a", File: "errors/error_test.go", LineNumber: 29},
StackFrame{Name: "a", File: "errors/error_test.go", LineNumber: 29},
StackFrame{Name: "a", File: "errors/error_test.go", LineNumber: 16},
)
} else {
// For versions >= 1.12 inlined functions show normally
expected = append(expected,
StackFrame{Name: "c", File: "errors/error_test.go", LineNumber: 29},
StackFrame{Name: "b", File: "errors/error_test.go", LineNumber: 23},
StackFrame{Name: "a", File: "errors/error_test.go", LineNumber: 16},
)
}

assertStacksMatch(t, expected, err.StackFrames())
}()

Expand Down
4 changes: 4 additions & 0 deletions v2/errors/stackframe.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -70,6 +70,10 @@ func (frame *StackFrame) SourceLine() (string, error) {
}

func packageAndName(fn *runtime.Func) (string, string) {
if fn == nil {
return "", ""
}

name := fn.Name()
pkg := ""

Expand Down
6 changes: 2 additions & 4 deletions v2/go.mod
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,11 +3,9 @@ module github.com/bugsnag/bugsnag-go/v2
go 1.15

require (
github.com/bitly/go-simplejson v0.5.0
github.com/bmizerany/assert v0.0.0-20160611221934-b7ed37b82869 // indirect
github.com/bitly/go-simplejson v0.5.1
github.com/bugsnag/panicwrap v1.3.4
github.com/google/uuid v1.3.0
github.com/google/uuid v1.6.0
github.com/kardianos/osext v0.0.0-20190222173326-2bc1f35cddc0 // indirect
github.com/kr/pretty v0.2.1 // indirect
github.com/pkg/errors v0.9.1
)
15 changes: 4 additions & 11 deletions v2/go.sum
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,17 +1,10 @@
github.com/bitly/go-simplejson v0.5.0 h1:6IH+V8/tVMab511d5bn4M7EwGXZf9Hj6i2xSwkNEM+Y=
github.com/bitly/go-simplejson v0.5.0/go.mod h1:cXHtHw4XUPsvGaxgjIAn8PhEWG9NfngEKAMDJEczWVA=
github.com/bmizerany/assert v0.0.0-20160611221934-b7ed37b82869 h1:DDGfHa7BWjL4YnC6+E63dPcxHo2sUxDIu8g3QgEJdRY=
github.com/bmizerany/assert v0.0.0-20160611221934-b7ed37b82869/go.mod h1:Ekp36dRnpXw/yCqJaO+ZrUyxD+3VXMFFr56k5XYrpB4=
github.com/bitly/go-simplejson v0.5.1 h1:xgwPbetQScXt1gh9BmoJ6j9JMr3TElvuIyjR8pgdoow=
github.com/bitly/go-simplejson v0.5.1/go.mod h1:YOPVLzCfwK14b4Sff3oP1AmGhI9T9Vsg84etUnlyp+Q=
github.com/bugsnag/panicwrap v1.3.4 h1:A6sXFtDGsgU/4BLf5JT0o5uYg3EeKgGx3Sfs+/uk3pU=
github.com/bugsnag/panicwrap v1.3.4/go.mod h1:D/8v3kj0zr8ZAKg1AQ6crr+5VwKN5eIywRkfhyM/+dE=
github.com/google/uuid v1.3.0 h1:t6JiXgmwXMjEs8VusXIJk2BXHsn+wx8BZdTaoZ5fu7I=
github.com/google/uuid v1.3.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo=
github.com/google/uuid v1.6.0 h1:NIvaJDMOsjHA8n1jAhLSgzrAzy1Hgr+hNrb57e+94F0=
github.com/google/uuid v1.6.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo=
github.com/kardianos/osext v0.0.0-20190222173326-2bc1f35cddc0 h1:iQTw/8FWTuc7uiaSepXwyf3o52HaUYcV+Tu66S3F5GA=
github.com/kardianos/osext v0.0.0-20190222173326-2bc1f35cddc0/go.mod h1:1NbS8ALrpOvjt0rHPNLyCIeMtbizbir8U//inJ+zuB8=
github.com/kr/pretty v0.2.1 h1:Fmg33tUaq4/8ym9TJN1x7sLJnHVwhP33CNkpYV/7rwI=
github.com/kr/pretty v0.2.1/go.mod h1:ipq/a2n7PKx3OHsz4KJII5eveXtPO4qwEXGdVfWzfnI=
github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ=
github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE=
github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI=
github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4=
github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
95 changes: 79 additions & 16 deletions v2/notifier_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@ package bugsnag_test

import (
"fmt"
"runtime"
"strings"
"testing"

Expand Down Expand Up @@ -61,21 +62,52 @@ func TestStackframesAreSkippedCorrectly(t *testing.T) {
defer notifier.AutoNotify()
crash("NaN")
}()
assertStackframesMatch(t, []errors.StackFrame{
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func4.1", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func4", File: "notifier_test.go"},
})

var expected []errors.StackFrame
golangVersion := runtime.Version()
// TODO remove this after dropping support for Golang 1.11
// Golang version < 1.12 cannot unwrap inlined functions correctly.
if strings.HasPrefix(golangVersion, "go1.11") {
expected = append(expected,
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func4.1", File: "notifier_test.go"}, //inlined crash func
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func4.1", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func4", File: "notifier_test.go"},
)
} else {
expected = append(expected,
errors.StackFrame{Name: "crash", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func4.1", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func4", File: "notifier_test.go"},
)
}

assertStackframesMatch(t, expected)
})
t.Run("bugsnag.AutoNotify", func(st *testing.T) {
func() {
defer func() { recover() }()
defer bugsnag.AutoNotify()
crash("NaN")
}()
assertStackframesMatch(t, []errors.StackFrame{
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func5.1", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func5", File: "notifier_test.go"},
})
var expected []errors.StackFrame
golangVersion := runtime.Version()
// TODO remove this after dropping support for Golang 1.11
// Golang version < 1.12 cannot unwrap inlined functions correctly.
if strings.HasPrefix(golangVersion, "go1.11") {
expected = append(expected,
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func5.1", File: "notifier_test.go"}, //inlined crash func
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func5.1", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func5", File: "notifier_test.go"},
)
} else {
expected = append(expected,
errors.StackFrame{Name: "crash", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func5.1", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func5", File: "notifier_test.go"},
)
}

assertStackframesMatch(t, expected)
})

// Expect the following frames to be present for *.Recover
Expand All @@ -92,20 +124,50 @@ func TestStackframesAreSkippedCorrectly(t *testing.T) {
defer notifier.Recover()
crash("NaN")
}()
assertStackframesMatch(t, []errors.StackFrame{
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func6.1", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func6", File: "notifier_test.go"},
})
var expected []errors.StackFrame
golangVersion := runtime.Version()
// TODO remove this after dropping support for Golang 1.11
// Golang version < 1.12 cannot unwrap inlined functions correctly.
if strings.HasPrefix(golangVersion, "go1.11") {
expected = append(expected,
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func6.1", File: "notifier_test.go"}, //inlined crash func
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func6.1", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func6", File: "notifier_test.go"},
)
} else {
expected = append(expected,
errors.StackFrame{Name: "crash", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func6.1", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func6", File: "notifier_test.go"},
)
}

assertStackframesMatch(t, expected)
})
t.Run("bugsnag.Recover", func(st *testing.T) {
func() {
defer bugsnag.Recover()
crash("NaN")
}()
assertStackframesMatch(t, []errors.StackFrame{
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func7.1", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func7", File: "notifier_test.go"},
})
var expected []errors.StackFrame
golangVersion := runtime.Version()
// TODO remove this after dropping support for Golang 1.11
// Golang version < 1.12 cannot unwrap inlined functions correctly.
if strings.HasPrefix(golangVersion, "go1.11") {
expected = append(expected,
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func7.1", File: "notifier_test.go"}, //inlined crash func
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func7.1", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func7", File: "notifier_test.go"},
)
} else {
expected = append(expected,
errors.StackFrame{Name: "crash", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func7.1", File: "notifier_test.go"},
errors.StackFrame{Name: "TestStackframesAreSkippedCorrectly.func7", File: "notifier_test.go"},
)
}

assertStackframesMatch(t, expected)
})
}

Expand Down Expand Up @@ -187,6 +249,7 @@ func assertStackframesMatch(t *testing.T, expected []errors.StackFrame) {
if strings.HasSuffix(file, expectedFrame.File) && expectedFrame.Name == method {
lastmatch = index
matched++
break
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can you also provide rationale for this change in the PR description? Why did it pass before and not now?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It passed before because the stack was:

  1. func.1
  2. func
    and each function got matched only once so matched count was correct.

When I added expansion of inlines the stack became:

  1. func.1 (for go1.11 and crash for everything else)
  2. func.1
  3. func
    that caused incorrect matching of actual and expected stacks - each actual stackframe could be matched many times - we did not stop comparing after finding first match.
    Matched count exceeded expected stack length and panic happened on the next log. (out of bounds idx)
    Notice that error_test.go has the break in the same place while matching stacks.

}
}
}
Expand Down
Loading