Migrate to labkit error tracking

This drops our custom error tracking logic written
on top of raven-go and instead uses labkit's
errortracking module.

changelogs/unreleased/mk-labkit-error-tracking.yml

+---
+title: Migrate error tracking from raven to labkit
+merge_request: 671
+author:
+type: other

go.mod

@@ -8,10 +8,8 @@ require (
 	github.com/FZambia/sentinel v1.0.0
 	github.com/alecthomas/chroma v0.7.3
 	github.com/aws/aws-sdk-go v1.36.1
-	github.com/certifi/gocertifi v0.0.0-20200922220541-2c3bb06c6054 // indirect
 	github.com/dgrijalva/jwt-go v3.2.0+incompatible
 	github.com/disintegration/imaging v1.6.2
-	github.com/getsentry/raven-go v0.2.0
 	github.com/golang/gddo v0.0.0-20190419222130-af0f2af80721
 	github.com/golang/protobuf v1.4.3
 	github.com/gomodule/redigo v2.0.0+incompatible

go.sum

@@ -145,8 +145,6 @@ github.com/cenkalti/backoff v2.2.1+incompatible/go.mod h1:90ReRw6GdpyfrHakVjL/QH
 github.com/census-instrumentation/opencensus-proto v0.2.1/go.mod h1:f6KPmirojxKA12rnyqOA5BBL4O983OfeGPqjHWSTneU=
 github.com/census-instrumentation/opencensus-proto v0.3.0/go.mod h1:f6KPmirojxKA12rnyqOA5BBL4O983OfeGPqjHWSTneU=
 github.com/certifi/gocertifi v0.0.0-20180905225744-ee1a9a0726d2/go.mod h1:GJKEexRPVJrBSOjoqN5VNOIKJ5Q3RViH6eu3puDRwx4=
-github.com/certifi/gocertifi v0.0.0-20200922220541-2c3bb06c6054 h1:uH66TXeswKn5PW5zdZ39xEwfS9an067BirqA+P4QaLI=
-github.com/certifi/gocertifi v0.0.0-20200922220541-2c3bb06c6054/go.mod h1:sGbDF6GwGcLpkNXPUTkMRoywsNa/ol15pxFe6ERfguA=
 github.com/cespare/xxhash/v2 v2.1.1 h1:6MnRN8NT7+YBpUIWxHtefFZOKTAPgGjpQSxqLNn0+qY=
 github.com/cespare/xxhash/v2 v2.1.1/go.mod h1:VGX0DQ3Q6kWi7AoAeZDth3/j3BFtOZR5XLFGgcrjCOs=
 github.com/chzyer/logex v1.1.10/go.mod h1:+Ywpsq7O8HXn0nuIou7OrIPyXbp3wmkHB+jjWRnGsAI=

internal/errortracker/sentry.go

+package errortracker
+
+import (
+	"fmt"
+	"net/http"
+	"os"
+	"runtime/debug"
+
+	"gitlab.com/gitlab-org/labkit/errortracking"
+
+	"gitlab.com/gitlab-org/labkit/log"
+)
+
+// NewHandler allows us to handle panics in upstreams gracefully, by logging them
+// using structured logging and reporting them into Sentry as `error`s with a
+// proper correlation ID attached.
+func NewHandler(next http.Handler) http.Handler {
+	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		defer func() {
+			if p := recover(); p != nil {
+				fields := log.ContextFields(r.Context())
+				log.WithFields(fields).Error(p)
+				debug.PrintStack()
+				// A panic isn't always an `error`, so we may have to convert it into one.
+				e, ok := p.(error)
+				if !ok {
+					e = fmt.Errorf("%v", p)
+				}
+				TrackFailedRequest(r, e, fields)
+			}
+		}()
+
+		next.ServeHTTP(w, r)
+	})
+}
+
+func TrackFailedRequest(r *http.Request, err error, fields log.Fields) {
+	captureOpts := []errortracking.CaptureOption{
+		errortracking.WithContext(r.Context()),
+		errortracking.WithRequest(r),
+	}
+	for k, v := range fields {
+		captureOpts = append(captureOpts, errortracking.WithField(k, fmt.Sprintf("%v", v)))
+	}
+
+	errortracking.Capture(err, captureOpts...)
+}
+
+func Initialize(version string) error {
+	// Use a custom environment variable (not SENTRY_DSN) to prevent
+	// clashes with gitlab-rails.
+	sentryDSN := os.Getenv("GITLAB_WORKHORSE_SENTRY_DSN")
+	sentryEnvironment := os.Getenv("GITLAB_WORKHORSE_SENTRY_ENVIRONMENT")
+
+	return errortracking.Initialize(
+		errortracking.WithSentryDSN(sentryDSN),
+		errortracking.WithSentryEnvironment(sentryEnvironment),
+		errortracking.WithVersion(version),
+	)
+}

internal/helper/helpers.go

@@ -14,50 +14,31 @@ import (
 	"syscall"
 
 	"github.com/sebest/xff"
-	"gitlab.com/gitlab-org/labkit/log"
-	"gitlab.com/gitlab-org/labkit/mask"
+
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/log"
 )
 
 const NginxResponseBufferHeader = "X-Accel-Buffering"
 
-func logErrorWithFields(r *http.Request, err error, fields log.Fields) {
-	if err != nil {
-		CaptureRavenError(r, err, fields)
-	}
-
-	printError(r, err, fields)
-}
-
-func CaptureAndFail(w http.ResponseWriter, r *http.Request, err error, msg string, code int) {
+func CaptureAndFail(w http.ResponseWriter, r *http.Request, err error, msg string, code int, loggerCallbacks ...log.ConfigureLogger) {
 	http.Error(w, msg, code)
-	logErrorWithFields(r, err, nil)
-}
+	logger := log.WithRequest(r).WithError(err)
+
+	for _, cb := range loggerCallbacks {
+		logger = cb(logger)
+	}
 
-func Fail500(w http.ResponseWriter, r *http.Request, err error) {
-	CaptureAndFail(w, r, err, "Internal server error", http.StatusInternalServerError)
+	logger.Error(msg)
 }
 
-func Fail500WithFields(w http.ResponseWriter, r *http.Request, err error, fields log.Fields) {
-	http.Error(w, "Internal server error", http.StatusInternalServerError)
-	logErrorWithFields(r, err, fields)
+func Fail500(w http.ResponseWriter, r *http.Request, err error, loggerCallbacks ...log.ConfigureLogger) {
+	CaptureAndFail(w, r, err, "Internal server error", http.StatusInternalServerError, loggerCallbacks...)
 }
 
 func RequestEntityTooLarge(w http.ResponseWriter, r *http.Request, err error) {
 	CaptureAndFail(w, r, err, "Request Entity Too Large", http.StatusRequestEntityTooLarge)
 }
 
-func printError(r *http.Request, err error, fields log.Fields) {
-	if r != nil {
-		entry := log.WithContextFields(r.Context(), log.Fields{
-			"method": r.Method,
-			"uri":    mask.URL(r.RequestURI),
-		})
-		entry.WithFields(fields).WithError(err).Error()
-	} else {
-		log.WithFields(fields).WithError(err).Error("unknown error")
-	}
-}
-
 func SetNoCacheHeaders(header http.Header) {
 	header.Set("Cache-Control", "no-cache, no-store, max-age=0, must-revalidate")
 	header.Set("Pragma", "no-cache")
@@ -97,7 +78,7 @@ func OpenFile(path string) (file *os.File, fi os.FileInfo, err error) {
 func URLMustParse(s string) *url.URL {
 	u, err := url.Parse(s)
 	if err != nil {
-		log.WithError(err).WithField("url", s).Fatal("urlMustParse")
+		log.WithError(err).WithFields(log.Fields{"url": s}).Error("urlMustParse")
 	}
 	return u
 }

internal/helper/raven.go

-package helper
-
-import (
-	"net/http"
-	"reflect"
-
-	raven "github.com/getsentry/raven-go"
-
-	//lint:ignore SA1019 this was recently deprecated. Update workhorse to use labkit errortracking package.
-	correlation "gitlab.com/gitlab-org/labkit/correlation/raven"
-
-	"gitlab.com/gitlab-org/labkit/log"
-)
-
-var ravenHeaderBlacklist = []string{
-	"Authorization",
-	"Private-Token",
-}
-
-func CaptureRavenError(r *http.Request, err error, fields log.Fields) {
-	client := raven.DefaultClient
-	extra := raven.Extra{}
-
-	for k, v := range fields {
-		extra[k] = v
-	}
-
-	interfaces := []raven.Interface{}
-	if r != nil {
-		CleanHeadersForRaven(r)
-		interfaces = append(interfaces, raven.NewHttp(r))
-
-		//lint:ignore SA1019 this was recently deprecated. Update workhorse to use labkit errortracking package.
-		extra = correlation.SetExtra(r.Context(), extra)
-	}
-
-	exception := &raven.Exception{
-		Stacktrace: raven.NewStacktrace(2, 3, nil),
-		Value:      err.Error(),
-		Type:       reflect.TypeOf(err).String(),
-	}
-	interfaces = append(interfaces, exception)
-
-	packet := raven.NewPacketWithExtra(err.Error(), extra, interfaces...)
-	client.Capture(packet, nil)
-}
-
-func CleanHeadersForRaven(r *http.Request) {
-	if r == nil {
-		return
-	}
-
-	for _, key := range ravenHeaderBlacklist {
-		if r.Header.Get(key) != "" {
-			r.Header.Set(key, "[redacted]")
-		}
-	}
-}

internal/imageresizer/image_resizer.go

@@ -428,16 +428,18 @@ func logFields(startTime time.Time, params *resizeParams, outcome *resizeOutcome
 
 func handleOutcome(w http.ResponseWriter, req *http.Request, startTime time.Time, params *resizeParams, outcome *resizeOutcome) {
 	fields := logFields(startTime, params, outcome)
-	log := log.WithRequest(req).WithFields(fields)
+	logger := log.WithRequest(req).WithFields(fields)
 
 	switch outcome.status {
 	case statusRequestFailure:
 		if outcome.bytesWritten <= 0 {
-			helper.Fail500WithFields(w, req, outcome.err, fields)
+			helper.Fail500(w, req, outcome.err, func(b *log.Builder) *log.Builder {
+				return b.WithFields(fields)
+			})
 		} else {
-			log.WithError(outcome.err).Error(outcome.status)
+			logger.WithError(outcome.err).Error(outcome.status)
 		}
 	default:
-		log.Info(outcome.status)
+		logger.Info(outcome.status)
 	}
 }

internal/log/logging.go

@@ -8,11 +8,13 @@ import (
 	"gitlab.com/gitlab-org/labkit/mask"
 	"golang.org/x/net/context"
 
-	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/errortracker"
 )
 
 type Fields = log.Fields
 
+type ConfigureLogger func(*Builder) *Builder
+
 type Builder struct {
 	entry  *logrus.Entry
 	fields log.Fields
@@ -83,6 +85,6 @@ func (b *Builder) Error(args ...interface{}) {
 	b.entry.Error(args...)
 
 	if b.req != nil && b.err != nil {
-		helper.CaptureRavenError(b.req, b.err, b.fields)
+		errortracker.TrackFailedRequest(b.req, b.err, b.fields)
 	}
 }

internal/upstream/upstream.go

@@ -16,6 +16,7 @@ import (
 	"gitlab.com/gitlab-org/labkit/correlation"
 
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/config"
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/errortracker"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/rejectmethods"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/upload"
@@ -63,7 +64,7 @@ func NewUpstream(cfg config.Config, accessLogger *logrus.Logger) http.Handler {
 		correlationOpts = append(correlationOpts, correlation.WithPropagation())
 	}
 
-	handler := correlation.InjectCorrelationID(&up, correlationOpts...)
+	handler := correlation.InjectCorrelationID(errortracker.NewHandler(&up), correlationOpts...)
 	// TODO: move to LabKit https://gitlab.com/gitlab-org/gitlab-workhorse/-/issues/339
 	handler = rejectmethods.NewMiddleware(handler)
 	return handler

main.go

@@ -16,6 +16,7 @@ import (
 	"gitlab.com/gitlab-org/labkit/tracing"
 
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/config"
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/errortracker"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/queueing"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/redis"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/secret"
@@ -156,6 +157,8 @@ func run(boot bootConfig, cfg config.Config) error {
 	}
 	defer closer.Close()
 
+	errortracker.Initialize(cfg.Version)
+
 	tracing.Initialize(tracing.WithServiceName("gitlab-workhorse"))
 	log.WithField("version", Version).WithField("build_time", BuildTime).Print("Starting")
 
@@ -223,7 +226,7 @@ func run(boot bootConfig, cfg config.Config) error {
 	}
 	defer accessCloser.Close()
 
-	up := wrapRaven(upstream.NewUpstream(cfg, accessLogger))
+	up := upstream.NewUpstream(cfg, accessLogger)
 
 	go func() { finalErrors <- http.Serve(listener, up) }()
 

raven.go

-package main
-
-import (
-	"net/http"
-	"os"
-
-	raven "github.com/getsentry/raven-go"
-
-	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
-)
-
-func wrapRaven(h http.Handler) http.Handler {
-	// Use a custom environment variable (not SENTRY_DSN) to prevent
-	// clashes with gitlab-rails.
-	sentryDSN := os.Getenv("GITLAB_WORKHORSE_SENTRY_DSN")
-	sentryEnvironment := os.Getenv("GITLAB_WORKHORSE_SENTRY_ENVIRONMENT")
-	raven.SetDSN(sentryDSN) // sentryDSN may be empty
-
-	if sentryEnvironment != "" {
-		raven.SetEnvironment(sentryEnvironment)
-	}
-
-	if sentryDSN == "" {
-		return h
-	}
-
-	raven.DefaultClient.SetRelease(Version)
-
-	return http.HandlerFunc(raven.RecoveryHandler(
-		func(w http.ResponseWriter, r *http.Request) {
-			defer func() {
-				if p := recover(); p != nil {
-					helper.CleanHeadersForRaven(r)
-					panic(p)
-				}
-			}()
-
-			h.ServeHTTP(w, r)
-		}))
-}