Improve logging and correlation ID

7 files changed, 36 insertions, 17 deletions

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 (