Logging: Log frontend errors (#28073)

* basic frontend Sentry integration * backend endpoint to capture sentry events * WIP! * log user email for frontend logs * remove debug logging * lint fixes * Fix type exports & property names Co-authored-by: Arve Knudsen <arve.knudsen@gmail.com> * additional struct naming fix * rename log endpoint, config section & interface * add sentry sample rate to config * refac to use EchoSrv * log user id * backend tests * tests for SentryEchoBackend * sentry echo backend tests * CustomEndpointTransport tests * Update pkg/api/frontend_logging_test.go Co-authored-by: Arve Knudsen <arve.knudsen@gmail.com> * Update conf/defaults.ini Co-authored-by: Arve Knudsen <arve.knudsen@gmail.com> * Update pkg/api/frontend_logging_test.go Co-authored-by: Arve Knudsen <arve.knudsen@gmail.com> * don't export unnecesasrily * update go.sum * get rid of Convey in tests, use stdlib * add sentry config to sample.ini * cleanup to set orig logging handler in test * Apply suggestions from code review Co-authored-by: Arve Knudsen <arve.knudsen@gmail.com> * PR feedback changes * lock sentry version Co-authored-by: Arve Knudsen <arve.knudsen@gmail.com>
2020-11-12 12:29:43 +01:00
parent 0c054d1a9f
commit 76df096791
25 changed files with 880 additions and 3 deletions
@@ -0,0 +1,149 @@
+package api
+
+import (
+	"net/http"
+	"testing"
+	"time"
+
+	"github.com/getsentry/sentry-go"
+	"github.com/grafana/grafana/pkg/models"
+	log "github.com/inconshreveable/log15"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+)
+
+type logScenarioFunc func(c *scenarioContext, logs []*log.Record)
+
+func logSentryEventScenario(t *testing.T, desc string, event frontendSentryEvent, fn logScenarioFunc) {
+	t.Run(desc, func(t *testing.T) {
+		logs := []*log.Record{}
+		origHandler := frontendLogger.GetHandler()
+		frontendLogger.SetHandler(log.FuncHandler(func(r *log.Record) error {
+			logs = append(logs, r)
+			return nil
+		}))
+		t.Cleanup(func() {
+			frontendLogger.SetHandler(origHandler)
+		})
+
+		sc := setupScenarioContext("/log")
+		hs := HTTPServer{}
+
+		handler := Wrap(func(w http.ResponseWriter, c *models.ReqContext) Response {
+			sc.context = c
+			return hs.logFrontendMessage(c, event)
+		})
+
+		sc.m.Post(sc.url, handler)
+		sc.fakeReqWithParams("POST", sc.url, map[string]string{}).exec()
+		fn(sc, logs)
+	})
+}
+
+func TestFrontendLoggingEndpoint(t *testing.T) {
+	ts, err := time.Parse("2006-01-02T15:04:05.000Z", "2020-10-22T06:29:29.078Z")
+	require.NoError(t, err)
+
+	t.Run("FrontendLoggingEndpoint", func(t *testing.T) {
+		request := sentry.Request{
+			URL: "http://localhost:3000/",
+			Headers: map[string]string{
+				"User-Agent": "Chrome",
+			},
+		}
+
+		user := sentry.User{
+			Email: "geralt@kaermorhen.com",
+			ID:    "45",
+		}
+
+		errorEvent := frontendSentryEvent{
+			&sentry.Event{
+				EventID:   "123",
+				Level:     sentry.LevelError,
+				Request:   &request,
+				Timestamp: ts,
+			},
+			&frontendSentryException{
+				Values: []frontendSentryExceptionValue{
+					{
+						Type:  "UserError",
+						Value: "Please replace user and try again",
+						Stacktrace: sentry.Stacktrace{
+							Frames: []sentry.Frame{
+								{
+									Function: "foofn",
+									Filename: "foo.js",
+									Lineno:   123,
+									Colno:    23,
+								},
+								{
+									Function: "barfn",
+									Filename: "bar.js",
+									Lineno:   113,
+									Colno:    231,
+								},
+							},
+						},
+					},
+				},
+			},
+		}
+
+		logSentryEventScenario(t, "Should log received error event", errorEvent, func(sc *scenarioContext, logs []*log.Record) {
+			assert.Equal(t, 200, sc.resp.Code)
+			assert.Len(t, logs, 1)
+			assertContextContains(t, logs[0], "logger", "frontend")
+			assertContextContains(t, logs[0], "url", errorEvent.Request.URL)
+			assertContextContains(t, logs[0], "user_agent", errorEvent.Request.Headers["User-Agent"])
+			assertContextContains(t, logs[0], "event_id", errorEvent.EventID)
+			assertContextContains(t, logs[0], "original_timestamp", errorEvent.Timestamp)
+			assertContextContains(t, logs[0], "stacktrace", `UserError: Please replace user and try again
+  at foofn (foo.js:123:23)
+  at barfn (bar.js:113:231)`)
+		})
+
+		messageEvent := frontendSentryEvent{
+			&sentry.Event{
+				EventID:   "123",
+				Level:     sentry.LevelInfo,
+				Request:   &request,
+				Timestamp: ts,
+				Message:   "hello world",
+				User:      user,
+			},
+			nil,
+		}
+
+		logSentryEventScenario(t, "Should log received message event", messageEvent, func(sc *scenarioContext, logs []*log.Record) {
+			assert.Equal(t, 200, sc.resp.Code)
+			assert.Len(t, logs, 1)
+			assert.Equal(t, "hello world", logs[0].Msg)
+			assert.Equal(t, log.LvlInfo, logs[0].Lvl)
+			assertContextContains(t, logs[0], "logger", "frontend")
+			assertContextContains(t, logs[0], "url", messageEvent.Request.URL)
+			assertContextContains(t, logs[0], "user_agent", messageEvent.Request.Headers["User-Agent"])
+			assertContextContains(t, logs[0], "event_id", messageEvent.EventID)
+			assertContextContains(t, logs[0], "original_timestamp", messageEvent.Timestamp)
+			assert.NotContains(t, logs[0].Ctx, "stacktrace")
+			assertContextContains(t, logs[0], "user_email", user.Email)
+			assertContextContains(t, logs[0], "user_id", user.ID)
+		})
+	})
+}
+
+func indexOf(arr []interface{}, item string) int {
+	for i, elem := range arr {
+		if elem == item {
+			return i
+		}
+	}
+	return -1
+}
+
+func assertContextContains(t *testing.T, logRecord *log.Record, label string, value interface{}) {
+	assert.Contains(t, logRecord.Ctx, label)
+	labelIdx := indexOf(logRecord.Ctx, label)
+	assert.Equal(t, value, logRecord.Ctx[labelIdx+1])
+}