Improve logging and correlation ID

22 files changed, 114 insertions, 86 deletions

diff --git a/app.go b/app.go
index 05203478..8f17e535 100644
--- a/app.go
+++ b/app.go
@@ -12,7 +12,7 @@ import (
 
 	ghandlers "github.com/gorilla/handlers"
 	"github.com/rs/cors"
-	log "github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/labkit/log"
 
 	"gitlab.com/gitlab-org/go-mimedb"
 	"gitlab.com/gitlab-org/labkit/correlation"
@@ -346,11 +346,17 @@ func (a *theApp) buildHandlerPipeline() (http.Handler, error) {
 
 	// Custom response headers
 	handler = a.customHeadersMiddleware(handler)
+	//handler = http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+	//	fmt.Printf("the req headers: %+v\n", r.Header)
+	//	fmt.Printf("the correlationID must have been here: %q\n", correlation.ExtractFromContext(r.Context()))
+	//	handler.ServeHTTP(w, r)
+	//	return
+	//})
 
 	// Correlation ID injection middleware
 	var correlationOpts []correlation.InboundHandlerOption
 	if a.config.General.PropagateCorrelationID {
-		correlationOpts = append(correlationOpts, correlation.WithPropagation())
+		correlationOpts = append(correlationOpts, correlation.WithPropagation(), correlation.WithSetResponseHeader())
 	}
 	handler = correlation.InjectCorrelationID(handler, correlationOpts...)
 
diff --git a/daemon.go b/daemon.go
index be790417..9ddb5377 100644
--- a/daemon.go
+++ b/daemon.go
@@ -12,7 +12,7 @@ import (
 	"strings"
 	"syscall"
 
-	log "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
 
 	"gitlab.com/gitlab-org/gitlab-pages/internal/config"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/jail"
@@ -36,7 +36,7 @@ func daemonMain() {
 		fatal(os.ErrPermission, "could not get current working directory")
 	}
 
-	log.WithFields(log.Fields{
+	logrus.WithFields(logrus.Fields{
 		"uid": syscall.Getuid(),
 		"gid": syscall.Getgid(),
 		"wd":  wd,
@@ -146,7 +146,7 @@ func chrootDaemon(cmd *exec.Cmd) (*jail.Jail, error) {
 }
 
 func jailCopyCertDir(cage *jail.Jail, sslCertDir, jailCertsDir string) error {
-	log.WithFields(log.Fields{
+	logrus.WithFields(logrus.Fields{
 		"ssl-cert-dir": sslCertDir,
 	}).Debug("Copying certs from SSL_CERT_DIR")
 
@@ -164,7 +164,7 @@ func jailCopyCertDir(cage *jail.Jail, sslCertDir, jailCertsDir string) error {
 
 		err = cage.CopyTo(jailCertsDir+"/"+fi.Name(), sslCertDir+"/"+fi.Name())
 		if err != nil {
-			log.WithError(err).Errorf("failed to copy cert: %q", fi.Name())
+			logrus.WithError(err).Errorf("failed to copy cert: %q", fi.Name())
 			// Go on and try to copy other files. We don't want the whole
 			// startup process to fail due to a single failure here.
 		}
@@ -177,7 +177,7 @@ func jailDaemonCerts(cmd *exec.Cmd, cage *jail.Jail) error {
 	sslCertFile := os.Getenv("SSL_CERT_FILE")
 	sslCertDir := os.Getenv("SSL_CERT_DIR")
 	if sslCertFile == "" && sslCertDir == "" {
-		log.Warn("Neither SSL_CERT_FILE nor SSL_CERT_DIR environment variable is set. HTTPS requests will fail.")
+		logrus.Warn("Neither SSL_CERT_FILE nor SSL_CERT_DIR environment variable is set. HTTPS requests will fail.")
 		return nil
 	}
 
@@ -243,7 +243,7 @@ func jailCreate(cmd *exec.Cmd) (*jail.Jail, error) {
 	// https://github.com/golang/go/issues/22846
 	err = cage.Copy("/etc/nsswitch.conf")
 	if err != nil {
-		log.WithError(err).Warn("/etc/nsswitch.conf couldn't be copied to the jail, /etc/hosts might not be applicable")
+		logrus.WithError(err).Warn("/etc/nsswitch.conf couldn't be copied to the jail, /etc/hosts might not be applicable")
 	}
 
 	// Add certificates inside the jail
@@ -290,7 +290,7 @@ func daemonize(config *config.Config) error {
 		return err
 	}
 
-	log.WithFields(log.Fields{
+	logrus.WithFields(logrus.Fields{
 		"uid":        uid,
 		"gid":        gid,
 		"in-place":   inPlace,
@@ -311,7 +311,7 @@ func daemonize(config *config.Config) error {
 		wrapper, err = jailDaemon(pagesRoot, cmd)
 	}
 	if err != nil {
-		log.WithError(err).Print("chroot failed")
+		logrus.WithError(err).Print("chroot failed")
 		return err
 	}
 	defer wrapper.Dispose()
@@ -323,7 +323,7 @@ func daemonize(config *config.Config) error {
 	_ = wrapper.Unshare()
 
 	if err := wrapper.Build(); err != nil {
-		log.WithError(err).Print("chroot build failed")
+		logrus.WithError(err).Print("chroot build failed")
 		return err
 	}
 
@@ -339,7 +339,7 @@ func daemonize(config *config.Config) error {
 
 	// Start the process
 	if err := cmd.Start(); err != nil {
-		log.WithError(err).Error("start failed")
+		logrus.WithError(err).Error("start failed")
 		return err
 	}
 
diff --git a/internal/acme/acme.go b/internal/acme/acme.go
index 3bfa8f2e..039be32a 100644
--- a/internal/acme/acme.go
+++ b/internal/acme/acme.go
@@ -6,9 +6,8 @@ import (
 	"path/filepath"
 	"strings"
 
-	log "github.com/sirupsen/logrus"
-
 	"gitlab.com/gitlab-org/gitlab-pages/internal/host"
+	"gitlab.com/gitlab-org/gitlab-pages/internal/logging"
 )
 
 // Middleware handles acme challenges by redirecting them to GitLab instance
@@ -45,7 +44,7 @@ func isAcmeChallenge(path string) bool {
 func (m *Middleware) redirectToGitlab(w http.ResponseWriter, r *http.Request) bool {
 	redirectURL, err := url.Parse(m.GitlabURL)
 	if err != nil {
-		log.WithError(err).Error("Can't parse GitLab URL for acme challenge redirect")
+		logging.LogRequest(r).WithError(err).Error("Can't parse GitLab URL for acme challenge redirect")
 		return false
 	}
 
@@ -55,7 +54,7 @@ func (m *Middleware) redirectToGitlab(w http.ResponseWriter, r *http.Request) bo
 	query.Set("token", filepath.Base(r.URL.Path))
 	redirectURL.RawQuery = query.Encode()
 
-	log.WithField("redirect_url", redirectURL).Debug("Redirecting to GitLab for processing acme challenge")
+	logging.LogRequest(r).WithField("redirect_url", redirectURL).Debug("Redirecting to GitLab for processing acme challenge")
 
 	http.Redirect(w, r, redirectURL.String(), http.StatusTemporaryRedirect)
 	return true
diff --git a/internal/auth/auth.go b/internal/auth/auth.go
index 5d503799..aab2f3cd 100644
--- a/internal/auth/auth.go
+++ b/internal/auth/auth.go
@@ -15,14 +15,14 @@ import (
 
 	"github.com/gorilla/securecookie"
 	"github.com/gorilla/sessions"
-	log "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
 	"golang.org/x/crypto/hkdf"
 
-	"gitlab.com/gitlab-org/labkit/correlation"
 	"gitlab.com/gitlab-org/labkit/errortracking"
 
 	"gitlab.com/gitlab-org/gitlab-pages/internal/httperrors"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/httptransport"
+	"gitlab.com/gitlab-org/gitlab-pages/internal/logging"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/request"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/source"
 )
@@ -270,7 +270,7 @@ func (a *Auth) handleProxyingAuth(session *sessions.Session, w http.ResponseWrit
 
 		url := fmt.Sprintf(authorizeURLTemplate, a.gitLabServer, a.clientID, a.redirectURI, state, a.authScope)
 
-		logRequest(r).WithFields(log.Fields{
+		logRequest(r).WithFields(logrus.Fields{
 			"gitlab_server": a.gitLabServer,
 			"pages_domain":  domain,
 		}).Info("Redirecting user to gitlab for oauth")
@@ -615,14 +615,8 @@ func checkResponseForInvalidToken(resp *http.Response, session *sessions.Session
 	return false
 }
 
-func logRequest(r *http.Request) *log.Entry {
-	state := r.URL.Query().Get("state")
-	return log.WithFields(log.Fields{
-		"correlation_id": correlation.ExtractFromContext(r.Context()),
-		"host":           r.Host,
-		"path":           r.URL.Path,
-		"state":          state,
-	})
+func logRequest(r *http.Request) *logrus.Entry {
+	return logging.LogRequest(r).WithField("state", r.URL.Query().Get("state"))
 }
 
 // generateKeys derives count hkdf keys from a secret, ensuring the key is
diff --git a/internal/config/config.go b/internal/config/config.go
index 1fe6aa0e..196b9685 100644
--- a/internal/config/config.go
+++ b/internal/config/config.go
@@ -8,7 +8,7 @@ import (
 	"time"
 
 	"github.com/namsral/flag"
-	log "github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/labkit/log"
 
 	"gitlab.com/gitlab-org/gitlab-pages/internal/config/tls"
 )
diff --git a/internal/httperrors/httperrors.go b/internal/httperrors/httperrors.go
index 476d270c..ed56ee10 100644
--- a/internal/httperrors/httperrors.go
+++ b/internal/httperrors/httperrors.go
@@ -4,9 +4,9 @@ import (
 	"fmt"
 	"net/http"
 
-	log "github.com/sirupsen/logrus"
-
+	"gitlab.com/gitlab-org/labkit/correlation"
 	"gitlab.com/gitlab-org/labkit/errortracking"
+	"gitlab.com/gitlab-org/labkit/log"
 )
 
 type content struct {
@@ -184,8 +184,9 @@ func Serve500(w http.ResponseWriter) {
 // Serve500WithRequest returns a 500 error response / HTML page to the http.ResponseWriter
 func Serve500WithRequest(w http.ResponseWriter, r *http.Request, reason string, err error) {
 	log.WithFields(log.Fields{
-		"host": r.Host,
-		"path": r.URL.Path,
+		"correlation_id": correlation.ExtractFromContext(r.Context()),
+		"host":           r.Host,
+		"path":           r.URL.Path,
 	}).WithError(err).Error(reason)
 	errortracking.Capture(err, errortracking.WithRequest(r))
 	serveErrorPage(w, content500)
diff --git a/internal/httptransport/metered_round_tripper.go b/internal/httptransport/metered_round_tripper.go
index 471449ec..3fe8dd3a 100644
--- a/internal/httptransport/metered_round_tripper.go
+++ b/internal/httptransport/metered_round_tripper.go
@@ -9,7 +9,9 @@ import (
 	"time"
 
 	"github.com/prometheus/client_golang/prometheus"
-	log "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
+
+	"gitlab.com/gitlab-org/gitlab-pages/internal/logging"
 )
 
 type meteredRoundTripper struct {
@@ -68,8 +70,8 @@ func (mrt *meteredRoundTripper) RoundTrip(r *http.Request) (*http.Response, erro
 }
 
 func (mrt *meteredRoundTripper) logResponse(req *http.Request, resp *http.Response) {
-	if log.GetLevel() == log.TraceLevel {
-		l := log.WithFields(log.Fields{
+	if logrus.GetLevel() == logrus.TraceLevel {
+		l := logging.LogRequest(req).WithFields(logrus.Fields{
 			"client_name":     mrt.name,
 			"req_url":         req.URL.String(),
 			"res_status_code": resp.StatusCode,
@@ -79,7 +81,7 @@ func (mrt *meteredRoundTripper) logResponse(req *http.Request, resp *http.Respon
 			l = l.WithField(strings.ToLower(header), strings.Join(value, ";"))
 		}
 
-		l.Traceln("response")
+		l.Traceln("response from client")
 	}
 }
 
diff --git a/internal/httptransport/transport.go b/internal/httptransport/transport.go
index 0b437a67..f284de39 100644
--- a/internal/httptransport/transport.go
+++ b/internal/httptransport/transport.go
@@ -8,7 +8,7 @@ import (
 	"sync"
 	"time"
 
-	log "github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/labkit/log"
 )
 
 const (
diff --git a/internal/httptransport/transport_darwin.go b/internal/httptransport/transport_darwin.go
index b73009da..46be2540 100644
--- a/internal/httptransport/transport_darwin.go
+++ b/internal/httptransport/transport_darwin.go
@@ -11,7 +11,7 @@ import (
 	"path/filepath"
 	"strings"
 
-	log "github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/labkit/log"
 )
 
 const (
diff --git a/internal/jail/mount_linux.go b/internal/jail/mount_linux.go
index 54093c40..cb5a6bed 100644
--- a/internal/jail/mount_linux.go
+++ b/internal/jail/mount_linux.go
@@ -4,7 +4,7 @@ import (
 	"fmt"
 	"syscall"
 
-	log "github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/labkit/log"
 	"golang.org/x/sys/unix"
 )
 
diff --git a/internal/logging/logging.go b/internal/logging/logging.go
index 10705a9a..4ffbeb4b 100644
--- a/internal/logging/logging.go
+++ b/internal/logging/logging.go
@@ -82,23 +82,31 @@ func BasicAccessLogger(handler http.Handler, format string, extraFields log.Extr
 		return nil, err
 	}
 
-	if extraFields == nil {
-		extraFields = func(r *http.Request) log.Fields {
-			return log.Fields{
-				"correlation_id": correlation.ExtractFromContext(r.Context()),
-				"pages_https":    request.IsHTTPS(r),
-				"pages_host":     r.Host,
-			}
-		}
-	}
-
 	return log.AccessLogger(handler,
-		log.WithExtraFields(extraFields),
+		log.WithExtraFields(enrichExtraFields(extraFields)),
 		log.WithAccessLogger(accessLogger),
 		log.WithXFFAllowed(func(sip string) bool { return false }),
 	), nil
 }
 
+func enrichExtraFields(extraFields log.ExtraFieldsGeneratorFunc) log.ExtraFieldsGeneratorFunc {
+	return func(r *http.Request) log.Fields {
+		enrichedFields := log.Fields{
+			"correlation_id": correlation.ExtractFromContext(r.Context()),
+			"pages_https":    request.IsHTTPS(r),
+			"pages_host":     r.Host,
+		}
+
+		if extraFields != nil {
+			for field, value := range extraFields(r) {
+				enrichedFields[field] = value
+			}
+		}
+
+		return enrichedFields
+	}
+}
+
 // AccessLogger configures the GitLab pages HTTP access logger middleware with extra log fields
 func AccessLogger(handler http.Handler, format string) (http.Handler, error) {
 	return BasicAccessLogger(handler, format, getExtraLogFields)
diff --git a/internal/source/disk/map.go b/internal/source/disk/map.go
index 0413d409..05ab4c30 100644
--- a/internal/source/disk/map.go
+++ b/internal/source/disk/map.go
@@ -10,7 +10,8 @@ import (
 	"time"
 
 	"github.com/karrick/godirwalk"
-	log "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/labkit/log"
 
 	"gitlab.com/gitlab-org/gitlab-pages/internal/domain"
 	"gitlab.com/gitlab-org/gitlab-pages/metrics"
@@ -294,7 +295,7 @@ func Watch(rootDomain string, updater domainsUpdater, interval time.Duration) {
 }
 
 func logConfiguredDomains(dm Map) {
-	if log.GetLevel() != log.DebugLevel {
+	if logrus.GetLevel() != logrus.DebugLevel {
 		return
 	}
 
diff --git a/internal/source/gitlab/cache/entry.go b/internal/source/gitlab/cache/entry.go
index 0b980774..769f1713 100644
--- a/internal/source/gitlab/cache/entry.go
+++ b/internal/source/gitlab/cache/entry.go
@@ -72,7 +72,7 @@ func (e *Entry) Lookup() *api.Lookup {
 func (e *Entry) Retrieve(ctx context.Context) (lookup *api.Lookup) {
 	// We run the code within an additional func() to run both `e.setResponse`
 	// and `e.retrieve.Retrieve` asynchronously.
-	e.retrieve.Do(func() { go func() { e.setResponse(e.retriever.Retrieve(e.domain)) }() })
+	e.retrieve.Do(func() { go func() { e.setResponse(e.retriever.Retrieve(ctx, e.domain)) }() })
 
 	select {
 	case <-ctx.Done():
diff --git a/internal/source/gitlab/cache/retriever.go b/internal/source/gitlab/cache/retriever.go
index 656ccce6..344fb653 100644
--- a/internal/source/gitlab/cache/retriever.go
+++ b/internal/source/gitlab/cache/retriever.go
@@ -5,7 +5,8 @@ import (
 	"errors"
 	"time"
 
-	log "github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/labkit/correlation"
+	"gitlab.com/gitlab-org/labkit/log"
 
 	"gitlab.com/gitlab-org/gitlab-pages/internal/domain"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/source/gitlab/api"
@@ -33,22 +34,31 @@ func NewRetriever(client api.Client, retrievalTimeout, maxRetrievalInterval time
 
 // Retrieve retrieves a lookup response from external source with timeout and
 // backoff. It has its own context with timeout.
-func (r *Retriever) Retrieve(domain string) (lookup api.Lookup) {
+func (r *Retriever) Retrieve(originalCtx context.Context, domain string) (lookup api.Lookup) {
+	logMsg := ""
+	correlationID := correlation.ExtractFromContext(originalCtx)
+
 	ctx, cancel := context.WithTimeout(context.Background(), r.retrievalTimeout)
 	defer cancel()
 
 	select {
 	case <-ctx.Done():
-		log.Debug("retrieval context done")
+
+		logMsg = "retrieval context done"
+
 		lookup = api.Lookup{Error: errors.New("retrieval context done")}
 	case lookup = <-r.resolveWithBackoff(ctx, domain):
-		log.WithFields(log.Fields{
-			"lookup_name":  lookup.Name,
-			"lookup_paths": lookup.Domain,
-			"lookup_error": lookup.Error,
-		}).Debug("retrieval response sent")
+		logMsg = "retrieval response sent"
 	}
 
+	log.WithFields(log.Fields{
+		"correlation_id":   correlationID,
+		"requested_domain": domain,
+		"lookup_name":      lookup.Name,
+		"lookup_paths":     lookup.Domain,
+		"lookup_error":     lookup.Error,
+	}).Debug(logMsg)
+
 	return lookup
 }
 
diff --git a/internal/source/gitlab/client/client.go b/internal/source/gitlab/client/client.go
index 2317107f..20595ce9 100644
--- a/internal/source/gitlab/client/client.go
+++ b/internal/source/gitlab/client/client.go
@@ -28,6 +28,8 @@ import (
 // or a 401 given that the credentials used are wrong
 const ConnectionErrorMsg = "failed to connect to internal Pages API"
 
+const transportClientName = "gitlab_internal_api"
+
 // ErrUnauthorizedAPI is returned when resolving a domain with the GitLab API
 // returns a http.StatusUnauthorized. This happens if the common secret file
 // is not synced between gitlab-pages and gitlab-rails servers.
@@ -68,8 +70,11 @@ func NewClient(baseURL string, secretKey []byte, connectionTimeout, jwtTokenExpi
 		httpClient: &http.Client{
 			Timeout: connectionTimeout,
 			Transport: httptransport.NewMeteredRoundTripper(
-				correlation.NewInstrumentedRoundTripper(httptransport.DefaultTransport),
-				"gitlab_internal_api",
+				correlation.NewInstrumentedRoundTripper(
+					httptransport.DefaultTransport,
+					correlation.WithClientName(transportClientName),
+				),
+				transportClientName,
 				metrics.DomainsSourceAPITraceDuration,
 				metrics.DomainsSourceAPICallDuration,
 				metrics.DomainsSourceAPIReqTotal,
@@ -149,7 +154,6 @@ func (gc *Client) get(ctx context.Context, path string, params url.Values) (*htt
 	if err != nil {
 		return nil, err
 	}
-
 	resp, err := gc.httpClient.Do(req)
 	if err != nil {
 		return nil, err
@@ -204,6 +208,9 @@ func (gc *Client) request(ctx context.Context, method string, endpoint *url.URL)
 		return nil, err
 	}
 
+	correlationID := correlation.ExtractFromContextOrGenerate(ctx)
+	ctx = correlation.ContextWithCorrelation(ctx, correlationID)
+
 	req = req.WithContext(ctx)
 
 	token, err := gc.token()
diff --git a/internal/source/gitlab/factory.go b/internal/source/gitlab/factory.go
index 027150fe..21572cd0 100644
--- a/internal/source/gitlab/factory.go
+++ b/internal/source/gitlab/factory.go
@@ -6,7 +6,7 @@ import (
 	"strings"
 
 	"github.com/sirupsen/logrus"
-	log "github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/labkit/log"
 
 	"gitlab.com/gitlab-org/gitlab-pages/internal/serving"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/serving/disk/local"
diff --git a/internal/source/gitlab/gitlab.go b/internal/source/gitlab/gitlab.go
index e52a34f0..8a3af074 100644
--- a/internal/source/gitlab/gitlab.go
+++ b/internal/source/gitlab/gitlab.go
@@ -12,9 +12,10 @@ import (
 	"github.com/cenkalti/backoff/v4"
 	"gitlab.com/gitlab-org/labkit/log"
 
+	"gitlab.com/gitlab-org/gitlab-pages/internal/request"
+
 	"gitlab.com/gitlab-org/gitlab-pages/internal/config"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/domain"
-	"gitlab.com/gitlab-org/gitlab-pages/internal/request"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/serving"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/source/gitlab/api"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/source/gitlab/cache"
diff --git a/internal/source/gitlab/gitlab_poll.go b/internal/source/gitlab/gitlab_poll.go
index a2a7e5f0..110eb829 100644
--- a/internal/source/gitlab/gitlab_poll.go
+++ b/internal/source/gitlab/gitlab_poll.go
@@ -4,7 +4,7 @@ import (
 	"time"
 
 	"github.com/cenkalti/backoff/v4"
-	log "github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/labkit/log"
 )
 
 const (
diff --git a/internal/vfs/root.go b/internal/vfs/root.go
index 30d97b0b..9c7528b3 100644
--- a/internal/vfs/root.go
+++ b/internal/vfs/root.go
@@ -5,7 +5,8 @@ import (
 	"os"
 	"strconv"
 
-	log "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/labkit/log"
 
 	"gitlab.com/gitlab-org/gitlab-pages/metrics"
 )
@@ -27,15 +28,15 @@ func (i *instrumentedRoot) increment(operation string, err error) {
 	metrics.VFSOperations.WithLabelValues(i.name, operation, strconv.FormatBool(err == nil)).Inc()
 }
 
-func (i *instrumentedRoot) log() *log.Entry {
-	return log.WithField("vfs", i.name).WithField("root-path", i.rootPath)
+func (i *instrumentedRoot) log(ctx context.Context) *logrus.Entry {
+	return log.ContextLogger(ctx).WithField("vfs", i.name).WithField("root-path", i.rootPath)
 }
 
 func (i *instrumentedRoot) Lstat(ctx context.Context, name string) (os.FileInfo, error) {
 	fi, err := i.root.Lstat(ctx, name)
 
 	i.increment("Lstat", err)
-	i.log().
+	i.log(ctx).
 		WithField("name", name).
 		WithError(err).
 		Traceln("Lstat call")
@@ -47,7 +48,7 @@ func (i *instrumentedRoot) Readlink(ctx context.Context, name string) (string, e
 	target, err := i.root.Readlink(ctx, name)
 
 	i.increment("Readlink", err)
-	i.log().
+	i.log(ctx).
 		WithField("name", name).
 		WithField("ret-target", target).
 		WithError(err).
@@ -60,7 +61,7 @@ func (i *instrumentedRoot) Open(ctx context.Context, name string) (File, error)
 	f, err := i.root.Open(ctx, name)
 
 	i.increment("Open", err)
-	i.log().
+	i.log(ctx).
 		WithField("name", name).
 		WithError(err).
 		Traceln("Open call")
diff --git a/internal/vfs/vfs.go b/internal/vfs/vfs.go
index 2304f903..40fe8bc7 100644
--- a/internal/vfs/vfs.go
+++ b/internal/vfs/vfs.go
@@ -4,7 +4,8 @@ import (
 	"context"
 	"strconv"
 
-	log "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/labkit/log"
 
 	"gitlab.com/gitlab-org/gitlab-pages/internal/config"
 	"gitlab.com/gitlab-org/gitlab-pages/metrics"
@@ -29,15 +30,15 @@ func (i *instrumentedVFS) increment(operation string, err error) {
 	metrics.VFSOperations.WithLabelValues(i.fs.Name(), operation, strconv.FormatBool(err == nil)).Inc()
 }
 
-func (i *instrumentedVFS) log() *log.Entry {
-	return log.WithField("vfs", i.fs.Name())
+func (i *instrumentedVFS) log(ctx context.Context) *logrus.Entry {
+	return log.ContextLogger(ctx).WithField("vfs", i.fs.Name())
 }
 
 func (i *instrumentedVFS) Root(ctx context.Context, path string) (Root, error) {
 	root, err := i.fs.Root(ctx, path)
 
 	i.increment("Root", err)
-	i.log().
+	i.log(ctx).
 		WithField("path", path).
 		WithError(err).
 		Traceln("Root call")
diff --git a/internal/vfs/zip/archive.go b/internal/vfs/zip/archive.go
index 981881c0..087ddda8 100644
--- a/internal/vfs/zip/archive.go
+++ b/internal/vfs/zip/archive.go
@@ -14,7 +14,7 @@ import (
 	"sync/atomic"
 	"time"
 
-	log "github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/labkit/log"
 
 	"gitlab.com/gitlab-org/gitlab-pages/internal/httprange"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/vfs"
@@ -101,9 +101,9 @@ func (a *zipArchive) openArchive(parentCtx context.Context, url string) (err err
 		err := ctx.Err()
 		switch err {
 		case context.Canceled:
-			log.WithError(err).Traceln("open zip archive request canceled")
+			log.ContextLogger(parentCtx).WithError(err).Traceln("open zip archive request canceled")
 		case context.DeadlineExceeded:
-			log.WithError(err).Traceln("open zip archive timed out")
+			log.ContextLogger(parentCtx).WithError(err).Traceln("open zip archive timed out")
 		}
 
 		return err
diff --git a/main.go b/main.go
index ec4f917f..080ad6ed 100644
--- a/main.go
+++ b/main.go
@@ -7,9 +7,8 @@ import (
 	"os"
 	"time"
 
-	log "github.com/sirupsen/logrus"
-
 	"gitlab.com/gitlab-org/labkit/errortracking"
+	"gitlab.com/gitlab-org/labkit/log"
 
 	cfg "gitlab.com/gitlab-org/gitlab-pages/internal/config"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/logging"
@@ -63,8 +62,8 @@ func appMain() {
 	log.WithFields(log.Fields{
 		"version":  VERSION,
 		"revision": REVISION,
-	}).Print("GitLab Pages Daemon")
-	log.Printf("URL: https://gitlab.com/gitlab-org/gitlab-pages")
+	}).Info("GitLab Pages Daemon")
+	log.Info("URL: https://gitlab.com/gitlab-org/gitlab-pages")
 
 	if err := os.Chdir(config.General.RootDir); err != nil {
 		fatal(err, "could not change directory into pagesRoot")
@@ -186,8 +185,6 @@ func printVersion(showVersion bool, version string) {
 }
 
 func main() {
-	log.SetOutput(os.Stderr)
-
 	rand.Seed(time.Now().UnixNano())
 
 	metrics.MustRegister()