Merge branch 'mk/refactor-logging' into 'master'

Refactor logging helpers to reduce signature creep

See merge request gitlab-org/gitlab-workhorse!662

changelogs/unreleased/mk-refactor-logging.yml

+---
+title: Extract logging concerns into a separate module
+merge_request:
+author:
+type: other

internal/api/api.go

@@ -18,6 +18,8 @@ import (
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/config"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/gitaly"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/log"
+
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/secret"
 )
 
@@ -322,7 +324,7 @@ func passResponseBack(httpResponse *http.Response, w http.ResponseWriter, r *htt
 	}
 	w.WriteHeader(httpResponse.StatusCode)
 	if _, err := io.Copy(w, responseBody); err != nil {
-		helper.LogError(r, err)
+		log.WithRequest(r).WithError(err).Error()
 	}
 }
 

internal/badgateway/roundtripper.go

@@ -9,9 +9,7 @@ import (
 	"strings"
 	"time"
 
-	"gitlab.com/gitlab-org/labkit/log"
-
-	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/log"
 )
 
 // Error is a custom error for pretty Sentry 'issues'
@@ -42,11 +40,7 @@ func (t *roundTripper) RoundTrip(r *http.Request) (*http.Response, error) {
 	// instead of 500s we catch the RoundTrip error here and inject a
 	// 502 response.
 	fields := log.Fields{"duration_ms": int64(time.Since(start).Seconds() * 1000)}
-	helper.LogErrorWithFields(
-		r,
-		&sentryError{fmt.Errorf("badgateway: failed to receive response: %v", err)},
-		fields,
-	)
+	log.WithRequest(r).WithFields(fields).WithError(&sentryError{fmt.Errorf("badgateway: failed to receive response: %v", err)}).Error()
 
 	injectedResponse := &http.Response{
 		StatusCode: http.StatusBadGateway,

internal/git/archive.go

@@ -24,6 +24,7 @@ import (
 
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/gitaly"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/log"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/senddata"
 )
 
@@ -116,14 +117,14 @@ func (a *archive) Inject(w http.ResponseWriter, r *http.Request, sendData string
 	setArchiveHeaders(w, format, archiveFilename)
 	w.WriteHeader(200) // Don't bother with HTTP 500 from this point on, just return
 	if _, err := io.Copy(w, reader); err != nil {
-		helper.LogError(r, &copyError{fmt.Errorf("SendArchive: copy 'git archive' output: %v", err)})
+		log.WithRequest(r).WithError(&copyError{fmt.Errorf("SendArchive: copy 'git archive' output: %v", err)}).Error()
 		return
 	}
 
 	if cacheEnabled {
 		err := finalizeCachedArchive(tempFile, params.ArchivePath)
 		if err != nil {
-			helper.LogError(r, fmt.Errorf("SendArchive: finalize cached archive: %v", err))
+			log.WithRequest(r).WithError(fmt.Errorf("SendArchive: finalize cached archive: %v", err)).Error()
 			return
 		}
 	}

internal/git/diff.go

@@ -8,6 +8,7 @@ import (
 
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/gitaly"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/log"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/senddata"
 )
 
@@ -39,10 +40,7 @@ func (d *diff) Inject(w http.ResponseWriter, r *http.Request, sendData string) {
 	}
 
 	if err := diffClient.SendRawDiff(ctx, w, request); err != nil {
-		helper.LogError(
-			r,
-			&copyError{fmt.Errorf("diff.RawDiff: request=%v, err=%v", request, err)},
-		)
+		log.WithRequest(r).WithError(&copyError{fmt.Errorf("diff.RawDiff: %v", err)}).Error()
 		return
 	}
 }

internal/git/format-patch.go

@@ -8,6 +8,7 @@ import (
 
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/gitaly"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/log"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/senddata"
 )
 
@@ -39,10 +40,7 @@ func (p *patch) Inject(w http.ResponseWriter, r *http.Request, sendData string)
 	}
 
 	if err := diffClient.SendRawPatch(ctx, w, request); err != nil {
-		helper.LogError(
-			r,
-			&copyError{fmt.Errorf("diff.RawPatch: request=%v, err=%v", request, err)},
-		)
+		log.WithRequest(r).WithError(&copyError{fmt.Errorf("diff.RawPatch: %v", err)}).Error()
 		return
 	}
 }

internal/git/git-http.go

@@ -12,7 +12,7 @@ import (
 	"sync"
 
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/api"
-	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/log"
 )
 
 const (
@@ -54,7 +54,7 @@ func postRPCHandler(a *api.API, name string, handler func(*HttpResponseWriter, *
 			// no-op. It never reaches net/http because GitHttpResponseWriter calls
 			// WriteHeader on its underlying ResponseWriter at most once.
 			w.WriteHeader(500)
-			helper.LogError(r, fmt.Errorf("%s: %v", name, err))
+			log.WithRequest(r).WithError(fmt.Errorf("%s: %v", name, err)).Error()
 		}
 	})
 }

internal/git/snapshot.go

@@ -9,6 +9,7 @@ import (
 
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/gitaly"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/log"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/senddata"
 )
 
@@ -59,6 +60,6 @@ func (s *snapshot) Inject(w http.ResponseWriter, r *http.Request, sendData strin
 	w.WriteHeader(http.StatusOK) // Errors aren't detectable beyond this point
 
 	if _, err := io.Copy(w, reader); err != nil {
-		helper.LogError(r, fmt.Errorf("SendSnapshot: copy gitaly output: %v", err))
+		log.WithRequest(r).WithError(fmt.Errorf("SendSnapshot: copy gitaly output: %v", err)).Error()
 	}
 }

internal/helper/helpers.go

@@ -20,13 +20,9 @@ import (
 
 const NginxResponseBufferHeader = "X-Accel-Buffering"
 
-func LogError(r *http.Request, err error) {
-	LogErrorWithFields(r, err, nil)
-}
-
-func LogErrorWithFields(r *http.Request, err error, fields log.Fields) {
+func logErrorWithFields(r *http.Request, err error, fields log.Fields) {
 	if err != nil {
-		captureRavenError(r, err, fields)
+		CaptureRavenError(r, err, fields)
 	}
 
 	printError(r, err, fields)
@@ -34,12 +30,7 @@ func LogErrorWithFields(r *http.Request, err error, fields log.Fields) {
 
 func CaptureAndFail(w http.ResponseWriter, r *http.Request, err error, msg string, code int) {
 	http.Error(w, msg, code)
-	LogError(r, err)
-}
-
-func CaptureAndFailWithFields(w http.ResponseWriter, r *http.Request, err error, msg string, code int, fields log.Fields) {
-	http.Error(w, msg, code)
-	LogErrorWithFields(r, err, fields)
+	logErrorWithFields(r, err, nil)
 }
 
 func Fail500(w http.ResponseWriter, r *http.Request, err error) {
@@ -47,7 +38,8 @@ func Fail500(w http.ResponseWriter, r *http.Request, err error) {
 }
 
 func Fail500WithFields(w http.ResponseWriter, r *http.Request, err error, fields log.Fields) {
-	CaptureAndFailWithFields(w, r, err, "Internal server error", http.StatusInternalServerError, fields)
+	http.Error(w, "Internal server error", http.StatusInternalServerError)
+	logErrorWithFields(r, err, fields)
 }
 
 func RequestEntityTooLarge(w http.ResponseWriter, r *http.Request, err error) {
@@ -60,7 +52,7 @@ func printError(r *http.Request, err error, fields log.Fields) {
 			"method": r.Method,
 			"uri":    mask.URL(r.RequestURI),
 		})
-		entry.WithFields(fields).WithError(err).Error("error")
+		entry.WithFields(fields).WithError(err).Error()
 	} else {
 		log.WithFields(fields).WithError(err).Error("unknown error")
 	}

internal/helper/helpers_test.go

@@ -2,13 +2,11 @@ package helper
 
 import (
 	"bytes"
-	"fmt"
 	"io"
 	"net/http"
 	"net/http/httptest"
 	"testing"
 
-	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/require"
 )
 
@@ -142,117 +140,3 @@ func TestFail500WorksWithNils(t *testing.T) {
 	require.Equal(t, http.StatusInternalServerError, w.Code)
 	require.Equal(t, "Internal server error\n", body.String())
 }
-
-func TestLogError(t *testing.T) {
-	tests := []struct {
-		name        string
-		method      string
-		uri         string
-		err         error
-		logMatchers []string
-	}{
-		{
-			name: "nil_request",
-			err:  fmt.Errorf("crash"),
-			logMatchers: []string{
-				`level=error msg="unknown error" error=crash`,
-			},
-		},
-		{
-			name: "nil_request_nil_error",
-			err:  nil,
-			logMatchers: []string{
-				`level=error msg="unknown error" error="<nil>"`,
-			},
-		},
-		{
-			name:   "basic_url",
-			method: "GET",
-			uri:    "http://localhost:3000/",
-			err:    fmt.Errorf("error"),
-			logMatchers: []string{
-				`level=error msg=error correlation_id= error=error method=GET uri="http://localhost:3000/"`,
-			},
-		},
-		{
-			name:   "secret_url",
-			method: "GET",
-			uri:    "http://localhost:3000/path?certificate=123&sharedSecret=123&import_url=the_url&my_password_string=password",
-			err:    fmt.Errorf("error"),
-			logMatchers: []string{
-				`level=error msg=error correlation_id= error=error method=GET uri="http://localhost:3000/path\?certificate=\[FILTERED\]&sharedSecret=\[FILTERED\]&import_url=\[FILTERED\]&my_password_string=\[FILTERED\]"`,
-			},
-		},
-	}
-
-	for _, tt := range tests {
-		t.Run(tt.name, func(t *testing.T) {
-			buf := &bytes.Buffer{}
-
-			oldOut := logrus.StandardLogger().Out
-			logrus.StandardLogger().Out = buf
-			defer func() {
-				logrus.StandardLogger().Out = oldOut
-			}()
-
-			var r *http.Request
-			if tt.uri != "" {
-				r = httptest.NewRequest(tt.method, tt.uri, nil)
-			}
-
-			LogError(r, tt.err)
-
-			logString := buf.String()
-			for _, v := range tt.logMatchers {
-				require.Regexp(t, v, logString)
-			}
-		})
-	}
-}
-
-func TestLogErrorWithFields(t *testing.T) {
-	tests := []struct {
-		name       string
-		request    *http.Request
-		err        error
-		fields     map[string]interface{}
-		logMatcher string
-	}{
-		{
-			name:       "nil_request",
-			err:        fmt.Errorf("crash"),
-			fields:     map[string]interface{}{"extra_one": 123},
-			logMatcher: `level=error msg="unknown error" error=crash extra_one=123`,
-		},
-		{
-			name:       "nil_request_nil_error",
-			err:        nil,
-			fields:     map[string]interface{}{"extra_one": 123, "extra_two": "test"},
-			logMatcher: `level=error msg="unknown error" error="<nil>" extra_one=123 extra_two=test`,
-		},
-		{
-			name:       "basic_url",
-			request:    httptest.NewRequest("GET", "http://localhost:3000/", nil),
-			err:        fmt.Errorf("error"),
-			fields:     map[string]interface{}{"extra_one": 123, "extra_two": "test"},
-			logMatcher: `level=error msg=error correlation_id= error=error extra_one=123 extra_two=test method=GET uri="http://localhost:3000/`,
-		},
-	}
-
-	for _, tt := range tests {
-		t.Run(tt.name, func(t *testing.T) {
-			buf := &bytes.Buffer{}
-
-			oldOut := logrus.StandardLogger().Out
-			logrus.StandardLogger().Out = buf
-			defer func() {
-				logrus.StandardLogger().Out = oldOut
-			}()
-
-			LogErrorWithFields(tt.request, tt.err, tt.fields)
-
-			logString := buf.String()
-			require.Contains(t, logString, tt.logMatcher)
-		})
-	}
-}

internal/helper/raven.go

@@ -17,7 +17,7 @@ var ravenHeaderBlacklist = []string{
 	"Private-Token",
 }
 
-func captureRavenError(r *http.Request, err error, fields log.Fields) {
+func CaptureRavenError(r *http.Request, err error, fields log.Fields) {
 	client := raven.DefaultClient
 	extra := raven.Extra{}
 

internal/imageresizer/image_resizer.go

@@ -19,12 +19,11 @@ import (
 	"github.com/prometheus/client_golang/prometheus/promauto"
 
 	"gitlab.com/gitlab-org/labkit/correlation"
-	"gitlab.com/gitlab-org/labkit/log"
-	"gitlab.com/gitlab-org/labkit/mask"
 	"gitlab.com/gitlab-org/labkit/tracing"
 
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/config"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/log"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/senddata"
 )
 
@@ -203,7 +202,7 @@ func (r *Resizer) Inject(w http.ResponseWriter, req *http.Request, paramsData st
 	if err != nil {
 		// Something failed, but we can still write out the original image, so don't return early.
 		// We need to log this separately since the subsequent steps might add other failures.
-		helper.LogErrorWithFields(req, err, *logFields(start, params, &outcome))
+		log.WithRequest(req).WithFields(logFields(start, params, &outcome)).WithError(err).Error()
 	}
 	defer helper.CleanUpProcessGroup(resizeCmd)
 
@@ -410,13 +409,13 @@ func (o *resizeOutcome) error(err error) {
 	o.err = err
 }
 
-func logFields(startTime time.Time, params *resizeParams, outcome *resizeOutcome) *log.Fields {
+func logFields(startTime time.Time, params *resizeParams, outcome *resizeOutcome) log.Fields {
 	var targetWidth, contentType string
 	if params != nil {
 		targetWidth = fmt.Sprint(params.Width)
 		contentType = fmt.Sprint(params.ContentType)
 	}
-	return &log.Fields{
+	return log.Fields{
 		"subsystem":                      logSystem,
 		"written_bytes":                  outcome.bytesWritten,
 		"duration_s":                     time.Since(startTime).Seconds(),
@@ -428,22 +427,17 @@ func logFields(startTime time.Time, params *resizeParams, outcome *resizeOutcome
 }
 
 func handleOutcome(w http.ResponseWriter, req *http.Request, startTime time.Time, params *resizeParams, outcome *resizeOutcome) {
-	logger := log.ContextLogger(req.Context())
-	fields := *logFields(startTime, params, outcome)
+	fields := logFields(startTime, params, outcome)
+	log := log.WithRequest(req).WithFields(fields)
 
 	switch outcome.status {
 	case statusRequestFailure:
 		if outcome.bytesWritten <= 0 {
 			helper.Fail500WithFields(w, req, outcome.err, fields)
 		} else {
-			helper.LogErrorWithFields(req, outcome.err, fields)
+			log.WithError(outcome.err).Error(outcome.status)
 		}
 	default:
-		logger.WithFields(fields).WithFields(
-			log.Fields{
-				"method": req.Method,
-				"uri":    mask.URL(req.RequestURI),
-			},
-		).Printf(outcome.status)
+		log.Info(outcome.status)
 	}
 }

internal/log/logging.go

+package log
+
+import (
+	"net/http"
+
+	"github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/labkit/log"
+	"gitlab.com/gitlab-org/labkit/mask"
+	"golang.org/x/net/context"
+
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
+)
+
+type Fields = log.Fields
+
+type Builder struct {
+	entry  *logrus.Entry
+	fields log.Fields
+	req    *http.Request
+	err    error
+}
+
+func NewBuilder() *Builder {
+	return &Builder{entry: log.WithFields(nil)}
+}
+
+func WithRequest(r *http.Request) *Builder {
+	return NewBuilder().WithRequest(r)
+}
+
+func (b *Builder) WithRequest(r *http.Request) *Builder {
+	if r == nil {
+		return b
+	}
+
+	b.req = r
+	b.WithFields(log.ContextFields(r.Context())).WithFields(
+		Fields{
+			"method": r.Method,
+			"uri":    mask.URL(r.RequestURI),
+		},
+	)
+	return b
+}
+
+func WithFields(fields Fields) *Builder {
+	return NewBuilder().WithFields(fields)
+}
+
+func (b *Builder) WithFields(fields Fields) *Builder {
+	b.fields = fields
+	b.entry = b.entry.WithFields(fields)
+	return b
+}
+
+func WithContextFields(ctx context.Context, fields Fields) *Builder {
+	return WithFields(log.ContextFields(ctx)).WithFields(fields)
+}
+
+func WithError(err error) *Builder {
+	return NewBuilder().WithError(err)
+}
+
+func (b *Builder) WithError(err error) *Builder {
+	b.err = err
+	b.entry = b.entry.WithError(err)
+	return b
+}
+
+func Info(args ...interface{}) {
+	NewBuilder().Info(args...)
+}
+
+func (b *Builder) Info(args ...interface{}) {
+	b.entry.Info(args...)
+}
+
+func Error(args ...interface{}) {
+	NewBuilder().Error(args...)
+}
+
+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)
+	}
+}

internal/log/logging_test.go

+package log
+
+import (
+	"bytes"
+	"fmt"
+	"net/http"
+	"net/http/httptest"
+	"testing"
+
+	"github.com/stretchr/testify/require"
+)
+
+func captureLogs(b *Builder, testFn func()) string {
+	buf := &bytes.Buffer{}
+
+	logger := b.entry.Logger
+	oldOut := logger.Out
+	logger.Out = buf
+	defer func() {
+		logger.Out = oldOut
+	}()
+
+	testFn()
+
+	return buf.String()
+}
+
+func TestLogInfo(t *testing.T) {
+	b := NewBuilder()
+	logLine := captureLogs(b, func() {
+		b.Info("an observation")
+	})
+
+	require.Regexp(t, `level=info msg="an observation"`, logLine)
+}
+
+func TestLogError(t *testing.T) {
+	b := NewBuilder()
+	logLine := captureLogs(b, func() {
+		b.WithError(fmt.Errorf("the error")).Error()
+	})
+
+	require.Regexp(t, `level=error error="the error"`, logLine)
+}
+
+func TestLogErrorWithMessage(t *testing.T) {
+	b := NewBuilder()
+	logLine := captureLogs(b, func() {
+		b.WithError(fmt.Errorf("the error")).Error("an error occurred")
+	})
+
+	require.Regexp(t, `level=error msg="an error occurred" error="the error"`, logLine)
+}
+
+func TestLogErrorWithRequest(t *testing.T) {
+	tests := []struct {
+		name        string
+		method      string
+		uri         string
+		err         error
+		logMatchers []string
+	}{
+		{
+			name: "nil_request",
+			err:  fmt.Errorf("cause"),
+			logMatchers: []string{
+				`level=error error=cause`,
+			},
+		},
+		{
+			name: "nil_request_nil_error",
+			err:  nil,
+			logMatchers: []string{
+				`level=error error="<nil>"`,
+			},
+		},
+		{
+			name:   "basic_url",
+			method: "GET",
+			uri:    "http://localhost:3000/",
+			err:    fmt.Errorf("cause"),
+			logMatchers: []string{
+				`level=error correlation_id= error=cause method=GET uri="http://localhost:3000/"`,
+			},
+		},
+		{
+			name:   "secret_url",
+			method: "GET",
+			uri:    "http://localhost:3000/path?certificate=123&sharedSecret=123&import_url=the_url&my_password_string=password",
+			err:    fmt.Errorf("cause"),
+			logMatchers: []string{
+				`level=error correlation_id= error=cause method=GET uri="http://localhost:3000/path\?certificate=\[FILTERED\]&sharedSecret=\[FILTERED\]&import_url=\[FILTERED\]&my_password_string=\[FILTERED\]"`,
+			},
+		},
+	}
+
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			b := NewBuilder()
+
+			var r *http.Request
+			if tt.uri != "" {
+				r = httptest.NewRequest(tt.method, tt.uri, nil)
+			}
+
+			logLine := captureLogs(b, func() {
+				b.WithRequest(r).WithError(tt.err).Error()
+			})
+
+			for _, v := range tt.logMatchers {
+				require.Regexp(t, v, logLine)
+			}
+		})
+	}
+}
+
+func TestLogErrorWithFields(t *testing.T) {
+	tests := []struct {
+		name       string
+		request    *http.Request
+		err        error
+		fields     map[string]interface{}
+		logMatcher string
+	}{
+		{
+			name:       "nil_request",
+			err:        fmt.Errorf("cause"),
+			fields:     map[string]interface{}{"extra_one": 123},
+			logMatcher: `level=error error=cause extra_one=123`,
+		},
+		{
+			name:       "nil_request_nil_error",
+			err:        nil,
+			fields:     map[string]interface{}{"extra_one": 123, "extra_two": "test"},
+			logMatcher: `level=error error="<nil>" extra_one=123 extra_two=test`,
+		},
+		{
+			name:       "basic_url",
+			request:    httptest.NewRequest("GET", "http://localhost:3000/", nil),
+			err:        fmt.Errorf("cause"),
+			fields:     map[string]interface{}{"extra_one": 123, "extra_two": "test"},
+			logMatcher: `level=error correlation_id= error=cause extra_one=123 extra_two=test method=GET uri="http://localhost:3000/`,
+		},
+	}
+
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			b := NewBuilder()
+
+			logLine := captureLogs(b, func() {
+				b.WithRequest(tt.request).WithFields(tt.fields).WithError(tt.err).Error()
+			})
+
+			require.Contains(t, logLine, tt.logMatcher)
+		})
+	}
+}

internal/redis/keywatcher.go

@@ -10,9 +10,8 @@ import (
 	"github.com/jpillora/backoff"
 	"github.com/prometheus/client_golang/prometheus"
 	"github.com/prometheus/client_golang/prometheus/promauto"
-	"gitlab.com/gitlab-org/labkit/log"
 
-	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/log"
 )
 
 var (
@@ -64,13 +63,13 @@ func processInner(conn redis.Conn) error {
 			dataStr := string(v.Data)
 			msg := strings.SplitN(dataStr, "=", 2)
 			if len(msg) != 2 {
-				helper.LogError(nil, fmt.Errorf("keywatcher: invalid notification: %q", dataStr))
+				log.WithError(fmt.Errorf("keywatcher: invalid notification: %q", dataStr)).Error()
 				continue
 			}
 			key, value := msg[0], msg[1]
 			notifyChanWatchers(key, value)
 		case error:
-			helper.LogError(nil, fmt.Errorf("keywatcher: pubsub receive: %v", v))
+			log.WithError(fmt.Errorf("keywatcher: pubsub receive: %v", v)).Error()
 			// Intermittent error, return nil so that it doesn't wait before reconnect
 			return nil
 		}
@@ -101,14 +100,14 @@ func Process() {
 	for {
 		conn, err := dialPubSub(workerDialFunc)
 		if err != nil {
-			helper.LogError(nil, fmt.Errorf("keywatcher: %v", err))
+			log.WithError(fmt.Errorf("keywatcher: %v", err)).Error()
 			time.Sleep(redisReconnectTimeout.Duration())
 			continue
 		}
 		redisReconnectTimeout.Reset()
 
 		if err = processInner(conn); err != nil {
-			helper.LogError(nil, fmt.Errorf("keywatcher: process loop: %v", err))
+			log.WithError(fmt.Errorf("keywatcher: process loop: %v", err)).Error()
 		}
 	}
 }

internal/sendurl/sendurl.go

@@ -11,11 +11,11 @@ import (
 	"github.com/prometheus/client_golang/prometheus/promauto"
 
 	"gitlab.com/gitlab-org/labkit/correlation"
-	"gitlab.com/gitlab-org/labkit/log"
 	"gitlab.com/gitlab-org/labkit/mask"
 	"gitlab.com/gitlab-org/labkit/tracing"
 
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/helper"
+	"gitlab.com/gitlab-org/gitlab-workhorse/internal/log"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/senddata"
 )
 
@@ -159,7 +159,7 @@ func (e *entry) Inject(w http.ResponseWriter, r *http.Request, sendData string)
 
 	if err != nil {
 		sendURLRequestsRequestFailed.Inc()
-		helper.LogError(r, fmt.Errorf("SendURL: Copy response: %v", err))
+		log.WithRequest(r).WithError(fmt.Errorf("SendURL: Copy response: %v", err)).Error()
 		return
 	}