fix: log.Error() missing bugsnag caller

.github/workflows/pull-request.yml

@@ -13,6 +13,6 @@ jobs:
       - name: Set up Go
         uses: actions/setup-go@v3
         with:
-          go-version: 1.16
+          go-version: "1.20"
       - name: Run unit tests
         run: make vet test

go.mod

@@ -1,28 +1,54 @@
 module github.com/replicatedcom/saaskit
 
-go 1.16
+go 1.20
 
 require (
-	github.com/Microsoft/go-winio v0.5.0 // indirect
 	github.com/aws/aws-sdk-go v1.38.45
 	github.com/bugsnag/bugsnag-go/v2 v2.1.2
-	github.com/cockroachdb/apd v1.1.0 // indirect
 	github.com/gin-gonic/gin v1.7.1
+	github.com/jackc/pgx v3.6.2+incompatible
+	github.com/johntdyer/slack-go v0.0.0-20180213144715-95fac1160b22
+	github.com/pkg/errors v0.9.1
+	github.com/sirupsen/logrus v1.8.1
+	github.com/stretchr/testify v1.7.0
+	golang.org/x/crypto v0.0.0-20210513164829-c07d793c2f9a
+	gopkg.in/DataDog/dd-trace-go.v1 v1.31.0
+)
+
+require (
+	github.com/DataDog/datadog-go v4.4.0+incompatible // indirect
+	github.com/Microsoft/go-winio v0.5.0 // indirect
+	github.com/bugsnag/panicwrap v1.3.4 // indirect
+	github.com/cockroachdb/apd v1.1.0 // indirect
+	github.com/davecgh/go-spew v1.1.1 // indirect
+	github.com/gin-contrib/sse v0.1.0 // indirect
+	github.com/go-playground/locales v0.13.0 // indirect
+	github.com/go-playground/universal-translator v0.17.0 // indirect
+	github.com/go-playground/validator/v10 v10.4.1 // indirect
 	github.com/go-sql-driver/mysql v1.6.0 // indirect
+	github.com/gofrs/uuid v4.0.0+incompatible // indirect
+	github.com/golang/protobuf v1.3.3 // indirect
 	github.com/google/uuid v1.2.0 // indirect
 	github.com/jackc/fake v0.0.0-20150926172116-812a484cc733 // indirect
-	github.com/jackc/pgx v3.6.2+incompatible
-	github.com/johntdyer/slack-go v0.0.0-20180213144715-95fac1160b22
+	github.com/jmespath/go-jmespath v0.4.0 // indirect
+	github.com/json-iterator/go v1.1.9 // indirect
+	github.com/kardianos/osext v0.0.0-20190222173326-2bc1f35cddc0 // indirect
+	github.com/leodido/go-urn v1.2.0 // indirect
 	github.com/lib/pq v1.10.2 // indirect
+	github.com/mattn/go-isatty v0.0.12 // indirect
 	github.com/mattn/go-sqlite3 v1.14.7 // indirect
+	github.com/modern-go/concurrent v0.0.0-20180228061459-e0a39a4cb421 // indirect
+	github.com/modern-go/reflect2 v0.0.0-20180701023420-4b7aa43c6742 // indirect
 	github.com/opentracing/opentracing-go v1.2.0 // indirect
 	github.com/philhofer/fwd v1.1.1 // indirect
-	github.com/pkg/errors v0.9.1
+	github.com/pmezard/go-difflib v1.0.0 // indirect
 	github.com/shopspring/decimal v1.3.1 // indirect
-	github.com/sirupsen/logrus v1.8.1
-	github.com/stretchr/testify v1.7.0
-	golang.org/x/crypto v0.0.0-20210513164829-c07d793c2f9a
+	github.com/tinylib/msgp v1.1.2 // indirect
+	github.com/ugorji/go/codec v1.1.7 // indirect
+	golang.org/x/sys v0.0.0-20210124154548-22da62e12c0c // indirect
+	golang.org/x/text v0.3.3 // indirect
 	golang.org/x/time v0.0.0-20210220033141-f8bda1e9f3ba // indirect
 	golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1 // indirect
-	gopkg.in/DataDog/dd-trace-go.v1 v1.31.0
+	gopkg.in/yaml.v2 v2.2.8 // indirect
+	gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c // indirect
 )

go.sum

@@ -94,7 +94,6 @@ github.com/stretchr/testify v1.7.0 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5Cc
 github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
 github.com/tinylib/msgp v1.1.2 h1:gWmO7n0Ys2RBEb7GPYB9Ujq8Mk5p2U08lRnmMcGy6BQ=
 github.com/tinylib/msgp v1.1.2/go.mod h1:+d+yLhGm8mzTaHzB+wgMYrodPfmZrzkirds8fDWklFE=
-github.com/ugorji/go v1.1.7 h1:/68gy2h+1mWMrwZFeD1kQialdSzAb432dtpeJ42ovdo=
 github.com/ugorji/go v1.1.7/go.mod h1:kZn38zHttfInRq0xu/PH0az30d+z6vm202qpg1oXVMw=
 github.com/ugorji/go/codec v1.1.7 h1:2SvQaVZ1ouYrrKKwoSk2pzd4A9evlKJb9oTL+OaLUSs=
 github.com/ugorji/go/codec v1.1.7/go.mod h1:Ax+UKWsSmolVDwsd+7N3ZtXu+yMGCf907BLYF3GoBXY=
@@ -104,17 +103,14 @@ golang.org/x/crypto v0.0.0-20210513164829-c07d793c2f9a h1:kr2P4QFmQr29mSLA43kwrO
 golang.org/x/crypto v0.0.0-20210513164829-c07d793c2f9a/go.mod h1:P+XmwS30IXTQdn5tA2iutPOUgjI07+tq3H3K9MVA1s8=
 golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
 golang.org/x/net v0.0.0-20201110031124-69a78807bb2b/go.mod h1:sp8m0HH+o8qH0wwXwYZr8TS3Oi6o0r6Gce1SSxlDquU=
-golang.org/x/net v0.0.0-20210226172049-e18ecbb05110/go.mod h1:m0MpNAwzfU5UDzcl9v0D8zg8gWTRqZa9RBIspLL5mdg=
 golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
 golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 golang.org/x/sys v0.0.0-20191026070338-33540a1f6037/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 golang.org/x/sys v0.0.0-20191204072324-ce4227a45e2e/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 golang.org/x/sys v0.0.0-20200116001909-b77594299b42/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
-golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 golang.org/x/sys v0.0.0-20210124154548-22da62e12c0c h1:VwygUrnw9jn88c4u8GD3rZQbqrP/tgas88tPUbBxQrk=
 golang.org/x/sys v0.0.0-20210124154548-22da62e12c0c/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
-golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo=
 golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
 golang.org/x/text v0.3.2/go.mod h1:bEr9sfX3Q8Zfm5fL9x+3itogRgK3+ptLWKqgva+5dAk=
 golang.org/x/text v0.3.3 h1:cokOdA+Jmi5PJGXLlLllQSgYigAEfHXJAERHVMaCc2k=

log/bugsnag.go

@@ -68,7 +68,7 @@ func (hook *bugsnagHook) Fire(entry *logrus.Entry) error {
 
 	if _, ok := notifyErr.(*bugsnagerrors.Error); !ok {
 		depth := getCallerDepth()
-		skip := depth - 2 // i am not sure why 2...
+		skip := depth - 1
 		notifyErr = bugsnagerrors.New(notifyErr, skip)
 	}
 

log/bugsnag_test.go

@@ -1,19 +1,27 @@
-package log
+// cannot be part of the log package because getCallerDepth will strip the package from the stack trace
+package log_test
 
 import (
 	"io"
 	"strings"
 	"testing"
 
 	bugsnagerrors "github.com/bugsnag/bugsnag-go/v2/errors"
+	"github.com/replicatedcom/saaskit/log"
 	"github.com/replicatedcom/saaskit/param"
 	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
 )
 
 func TestBugsnagHook(t *testing.T) {
 	param.Init(nil)
+	log.InitLog(&log.LogOptions{
+		LogLevel:   "debug",
+		BugsnagKey: "TESTING",
+	})
 
-	h := &bugsnagHook{}
+	h, err := log.NewBugsnagHook()
+	require.NoError(t, err)
 
 	var bugsnagNotifyErr error
 
@@ -22,9 +30,9 @@ func TestBugsnagHook(t *testing.T) {
 		return nil
 	}
 
-	log := newLogger()
+	log := log.Log
 	log.SetOutput(io.Discard)
-	log.logger.AddHook(h)
+	log.AddHook(h)
 
 	log.Error("test 1")
 	assert.NotNil(t, bugsnagNotifyErr)

log/log.go

@@ -109,11 +109,9 @@ func Error(args ...interface{}) {
 	Log.WithFields(getSaaskitError(args, 1)).Error(args...)
 }
 func Errorf(format string, args ...interface{}) {
-	err := errors.New(fmt.Errorf(format, args...), 1)
-	errFields := logrus.Fields{"saaskit.error": err}
-	Log.WithFields(errFields).Errorf(err.Error())
-	// TODO: we want this, but it doesn't pass go vet
-	// Log.WithFields(getSaaskitErrorf(format, args, 1)).Errorf(format, args...)
+	// NOTE: this must support the %w wrap verb since vandoor uses it
+	err := fmt.Errorf(format, args...)
+	Log.WithFields(getSaaskitErrorf(format, args, 1)).Errorf(err.Error())
 }
 
 func Fatal(args ...interface{}) {
@@ -136,7 +134,7 @@ func filterEvents(event *bugsnag.Event, config *bugsnag.Configuration) error {
 
 func getSaaskitError(args []interface{}, skip int) logrus.Fields {
 	if err, ok := args[0].(error); ok {
-		return logrus.Fields{"saaskit.error": err}
+		return logrus.Fields{"saaskit.error": errors.New(err, skip+1)}
 	} else {
 		return getSaaskitError([]interface{}{errors.New(fmt.Sprint(args...), skip+1)}, 0)
 	}

log/log_test.go

@@ -81,7 +81,7 @@ func TestSaaskitError(t *testing.T) {
 		{
 			name:        "bugsnag error",
 			args:        []interface{}{"test1", "test2"},
-			wantErrType: &errors.Error{},
+			wantErrType: fmt.Errorf("blah"),
 		},
 	}
 	for _, tt := range tests {
@@ -96,10 +96,12 @@ func TestSaaskitError(t *testing.T) {
 
 			require.Len(t, h.entries, 1)
 			require.Contains(t, h.entries[0].Data, "saaskit.error")
-			assert.IsType(t, tt.wantErrType, h.entries[0].Data["saaskit.error"])
 			if bugsnagErr, ok := h.entries[0].Data["saaskit.error"].(*errors.Error); ok {
+				assert.IsType(t, tt.wantErrType, bugsnagErr.Err)
 				firstLine := strings.Split(string(bugsnagErr.Stack()), "\n")[0]
 				assert.Contains(t, firstLine, "log_test.go:")
+			} else {
+				assert.IsType(t, tt.wantErrType, h.entries[0].Data["saaskit.error"])
 			}
 		})
 	}
@@ -112,14 +114,16 @@ func TestSaaskitErrorf(t *testing.T) {
 	Log.SetLevel(logrus.DebugLevel) // default
 
 	tests := []struct {
-		name   string
-		format string
-		args   []interface{}
+		name        string
+		format      string
+		args        []interface{}
+		wantErrType interface{}
 	}{
 		{
-			name:   "bugsnag error",
-			format: "test %s %s",
-			args:   []interface{}{"test1", "test2"},
+			name:        "bugsnag error",
+			format:      "test %s %s",
+			args:        []interface{}{"test1", "test2"},
+			wantErrType: fmt.Errorf("blah"),
 		},
 	}
 	for _, tt := range tests {
@@ -134,10 +138,13 @@ func TestSaaskitErrorf(t *testing.T) {
 
 			require.Len(t, h.entries, 1)
 			require.Contains(t, h.entries[0].Data, "saaskit.error")
-			assert.IsType(t, &errors.Error{}, h.entries[0].Data["saaskit.error"])
-			bugsnagErr, _ := h.entries[0].Data["saaskit.error"].(*errors.Error)
-			firstLine := strings.Split(string(bugsnagErr.Stack()), "\n")[0]
-			assert.Contains(t, firstLine, "log_test.go:")
+			if bugsnagErr, ok := h.entries[0].Data["saaskit.error"].(*errors.Error); ok {
+				assert.IsType(t, tt.wantErrType, bugsnagErr.Err)
+				firstLine := strings.Split(string(bugsnagErr.Stack()), "\n")[0]
+				assert.Contains(t, firstLine, "log_test.go:")
+			} else {
+				assert.IsType(t, tt.wantErrType, h.entries[0].Data["saaskit.error"])
+			}
 		})
 	}
 }
@@ -200,3 +207,34 @@ func Test_getSaaskitErrorf(t *testing.T) {
 		})
 	}
 }
+
+func TestErrorf(t *testing.T) {
+	type args struct {
+		format string
+		args   []interface{}
+	}
+	tests := []struct {
+		name string
+		args args
+		want string
+	}{
+		{
+			name: "test with wrap verb",
+			args: args{
+				format: "test %w",
+				args:   []interface{}{goerrors.New("error")},
+			},
+			want: "test error",
+		},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			buf := bytes.NewBuffer(nil)
+			Log = newLogger()
+			Log.SetOutput(buf)
+			Errorf(tt.args.format, tt.args.args...)
+			fmt.Println(buf.String())
+			assert.Contains(t, buf.String(), fmt.Sprintf(`msg="%s"`, tt.want))
+		})
+	}
+}