sentry-go icon indicating copy to clipboard operation
sentry-go copied to clipboard

Go 1.21 has changed function closures names and it disrupts grouping

Open lawrencejones opened this issue 11 months ago • 4 comments

Summary

Nothing is going wrong wrong, but upgrading to go 1.21 almost entirely broke our ability to group errors.

Steps To Reproduce

This is because if you have a program like this:

package main

import (
	"encoding/json"
	"fmt"

	"github.com/getsentry/sentry-go"
)

func main() {
	Run()
}

func Run() {
	Logger()("hello")
}

func Logger() func(msg string) {
	return func(msg string) {
		fmt.Println(msg)
		data, _ := json.MarshalIndent(sentry.NewStacktrace(), "", "  ")
		fmt.Println(string(data))
	}
}

It produces different function names depending on your go version:

Go 1.20

$ docker run --workdir=/app -v "$(pwd):/app" --rm -t golang:1.20 go run main.go
go: downloading github.com/getsentry/sentry-go v0.24.0
go: downloading golang.org/x/sys v0.6.0
go: downloading golang.org/x/text v0.8.0
hello
{
  "frames": [
    {
      "function": "main",
      "module": "main",
      "abs_path": "/app/main.go",
      "lineno": 11,
      "in_app": true
    },
    {
      "function": "Run",
      "module": "main",
      "abs_path": "/app/main.go",
      "lineno": 15,
      "in_app": true
    },
    {
      "function": "Logger.func1",
      "module": "main",
      "abs_path": "/app/main.go",
      "lineno": 21,
      "in_app": true
    }
  ]
}

Go 1.21

$ docker run --workdir=/app -v "$(pwd):/app" --rm -t golang:1.21 go run main.go
Digest: sha256:b490ae1f0ece153648dd3c5d25be59a63f966b5f9e1311245c947de4506981aaStatus: Downloaded newer image for golang:1.21
go: downloading github.com/getsentry/sentry-go v0.24.0go: downloading golang.org/x/sys v0.6.0
go: downloading golang.org/x/text v0.8.0
hello
{
  "frames": [
    {
      "function": "main",
      "module": "main",
      "abs_path": "/app/main.go",
      "lineno": 11,
      "in_app": true
    },
    {
      "function": "Run",
      "module": "main",
      "abs_path": "/app/main.go",
      "lineno": 15,
      "in_app": true
    },
    {
      "function": "Run.Logger.func1",
      "module": "main",
      "abs_path": "/app/main.go",
      "lineno": 21,
      "in_app": true
    }
  ]
}

Why is this a problem

The closured function returned by Logger is no longer consistently identifiable across the codebase using it's function name, because unlike in go 1.20 or lower where it is Logger.func1, with 1.21+ this has now acquired a prefix and is Run.Logger.func1 to acknowledge that it was constructed from within Run.

While potentially useful for debugging or PGO, this significantly impacts event grouping for issues as you likely want to group on the stacktrace of the error returned in Logger.func1 but those traces will no longer match if the prefix has been modified. The prefix will often be modified in standard Go apps because of the HTTP middleware pattern where you chain handlers like:

			// Apply best practice security headers
			func(h http.Handler, _ mw.LookupFunc) http.Handler {
				return mw.ApplySecurity(h)
			},
			// Apply compression if the client supports it
			func(h http.Handler, _ mw.LookupFunc) http.Handler {
				return gziphandler.GzipHandler(h)
			},

Which means the prefix will be Run.funcX where X is the number of chains you have in your Run method, and any change to X – caused by moving your call around, or adding a new function – will change all stackframes of any errors produced by Logger.func1 for the purpose of any stacktrace grouping we have in Sentry.

Expected Behavior

Errors generated from Logger.func1 with otherwise similar frames should be grouped in Sentry, as they were with Go 1.20.

Additional context

To fix this for our app, we have forked sentry-go and applied a patch here: https://github.com/incident-io/sentry-go/pull/1

This seems to be working well. Where the problematic grouping for our app looked like this with Go 1.21 and no patch: image

Where you can see Run.func61.Run.func61... which caused all our grouping keys to bust, the patch now generates much cleaner grouping keys that look much closer to the grouping we had with Go 1.20: image

Some advice on whether you'd like us to submit this PR to upstream or if you'd like to handle this differently would be great, and you'll probably want to warn people that upgrading to Go 1.21 will cause their Sentry grouping to become much more volatile.

Thanks!

lawrencejones avatar Sep 06 '23 16:09 lawrencejones

Thanks for the detailed overview and a suggested fix, we'll look into this.

tonyo avatar Sep 06 '23 17:09 tonyo

Does https://github.com/getsentry/sentry-go/pull/707 relate to this?

cleptric avatar Sep 06 '23 20:09 cleptric

Hey @cleptric 👋

I did see #707 when I was originally debugging this but from what I can tell, it's something different. The function names output by 1.21 don't include colons.

lawrencejones avatar Sep 08 '23 09:09 lawrencejones

@lawrencejones This only seems to happen specifically when calling a closured function correct? Or at least I can't see this behaviour otherwise.

Could you share a deep sentry stack trace or two? I think I might have a simpler solution but I just need to see some more hairy/complex examples. :) What I'm trying to see is if the parent of the current frame's function name is always the unwanted prefix in the current frame's function name. Ie a little example I cooked up (other fields removed for clarity):

{
      "function": "Run.func1.1"
},
{
      "function": "Run.func1.1.Logger.func1"
}

If that's the case then something like this might work: https://github.com/greywolve/sentry-go/commit/b026f440d6f6de6933d7110e0da2a2ddd0d90702

greywolve avatar Sep 08 '23 16:09 greywolve