fix: fix metrics and logs not including domain resolution time

Currently we do logging and metrics capturing
after we did the domain information lookup.

It allows us to add more information to access logs.

But it also distorts metrics because domain information
lookup takes time.

This logic was originally introduced in
https://gitlab.com/gitlab-org/gitlab-pages/-/merge_requests/157/diffs

It didn't matter back than because we didn't lookup domain via API as we do now.
Now it does matter.

So this commits moves metrics and logging middlewares almost to the top of pipeline.

Changelog: fixed

6 files changed, 21 insertions, 228 deletions

diff --git a/app.go b/app.go
index 9eeef53b..ad659109 100644
--- a/app.go
+++ b/app.go
@@ -138,7 +138,7 @@ func (a *theApp) tryAuxiliaryHandlers(w http.ResponseWriter, r *http.Request, ht
 }
 
 // healthCheckMiddleware is serving the application status check
-func (a *theApp) healthCheckMiddleware(handler http.Handler) (http.Handler, error) {
+func (a *theApp) healthCheckMiddleware(handler http.Handler) http.Handler {
 	healthCheck := http.HandlerFunc(func(w http.ResponseWriter, _r *http.Request) {
 		if a.isReady() {
 			w.Write([]byte("success\n"))
@@ -147,19 +147,14 @@ func (a *theApp) healthCheckMiddleware(handler http.Handler) (http.Handler, erro
 		}
 	})
 
-	loggedHealthCheck, err := logging.BasicAccessLogger(healthCheck, a.config.Log.Format, nil)
-	if err != nil {
-		return nil, err
-	}
-
 	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 		if r.RequestURI == a.config.General.StatusPath {
-			loggedHealthCheck.ServeHTTP(w, r)
+			healthCheck.ServeHTTP(w, r)
 			return
 		}
 
 		handler.ServeHTTP(w, r)
-	}), nil
+	})
 }
 
 // auxiliaryMiddleware will handle status updates, not-ready requests and other
@@ -234,24 +229,13 @@ func (a *theApp) buildHandlerPipeline() (http.Handler, error) {
 	handler = a.auxiliaryMiddleware(handler)
 	handler = a.Auth.AuthenticationMiddleware(handler, a.source)
 	handler = a.AcmeMiddleware.AcmeMiddleware(handler)
-	handler, err := logging.BasicAccessLogger(handler, a.config.Log.Format, domain.LogFields)
-	if err != nil {
-		return nil, err
-	}
-
-	// Metrics
-	metricsMiddleware := labmetrics.NewHandlerFactory(labmetrics.WithNamespace("gitlab_pages"))
-	handler = metricsMiddleware(handler)
 
 	handler = routing.NewMiddleware(handler, a.source)
 
 	handler = handlers.Ratelimiter(handler, &a.config.RateLimit)
 
 	// Health Check
-	handler, err = a.healthCheckMiddleware(handler)
-	if err != nil {
-		return nil, err
-	}
+	handler = a.healthCheckMiddleware(handler)
 
 	// Custom response headers
 	handler = customheaders.NewMiddleware(handler, a.CustomHeaders)
@@ -262,6 +246,15 @@ func (a *theApp) buildHandlerPipeline() (http.Handler, error) {
 		correlationOpts = append(correlationOpts, correlation.WithPropagation())
 	}
 	handler = handlePanicMiddleware(handler)
+
+	// Access logs and metrics
+	handler, err := logging.BasicAccessLogger(handler, a.config.Log.Format)
+	if err != nil {
+		return nil, err
+	}
+	metricsMiddleware := labmetrics.NewHandlerFactory(labmetrics.WithNamespace("gitlab_pages"))
+	handler = metricsMiddleware(handler)
+
 	handler = correlation.InjectCorrelationID(handler, correlationOpts...)
 
 	// These middlewares MUST be added in the end.
diff --git a/app_test.go b/app_test.go
index db4d9d67..3b1d6697 100644
--- a/app_test.go
+++ b/app_test.go
@@ -118,8 +118,7 @@ func TestHealthCheckMiddleware(t *testing.T) {
 			r := httptest.NewRequest("GET", tc.path, nil)
 			rr := httptest.NewRecorder()
 
-			middleware, err := app.healthCheckMiddleware(handler)
-			require.NoError(t, err)
+			middleware := app.healthCheckMiddleware(handler)
 			middleware.ServeHTTP(rr, r)
 
 			require.Equal(t, tc.status, rr.Code)
diff --git a/internal/domain/logging.go b/internal/domain/logging.go
deleted file mode 100644
index 2ecddf6c..00000000
--- a/internal/domain/logging.go
+++ /dev/null
@@ -1,31 +0,0 @@
-package domain
-
-import (
-	"net/http"
-
-	"gitlab.com/gitlab-org/labkit/log"
-)
-
-func LogFields(r *http.Request) log.Fields {
-	logFields := log.Fields{
-		"pages_https": r.URL.Scheme == "https",
-		"pages_host":  GetHost(r),
-	}
-
-	d := FromRequest(r)
-	if d == nil {
-		return logFields
-	}
-
-	lp, err := d.GetLookupPath(r)
-	if err != nil {
-		logFields["error"] = err.Error()
-		return logFields
-	}
-
-	logFields["pages_project_serving_type"] = lp.ServingType
-	logFields["pages_project_prefix"] = lp.Prefix
-	logFields["pages_project_id"] = lp.ProjectID
-
-	return logFields
-}
diff --git a/internal/domain/logging_test.go b/internal/domain/logging_test.go
deleted file mode 100644
index b736758c..00000000
--- a/internal/domain/logging_test.go
+++ /dev/null
@@ -1,71 +0,0 @@
-package domain
-
-import (
-	"net/http"
-	"testing"
-
-	log "github.com/sirupsen/logrus"
-	"github.com/stretchr/testify/require"
-
-	"gitlab.com/gitlab-org/gitlab-pages/internal/serving"
-)
-
-type resolver struct {
-	err error
-	f   func(*http.Request) *serving.LookupPath
-}
-
-func (r *resolver) Resolve(req *http.Request) (*serving.Request, error) {
-	if r.f != nil {
-		return &serving.Request{LookupPath: r.f(req)}, nil
-	}
-
-	return nil, r.err
-}
-
-func TestDomainLogFields(t *testing.T) {
-	domainWithResolver := New("", "", "", &resolver{f: func(*http.Request) *serving.LookupPath {
-		return &serving.LookupPath{
-			ServingType: "file",
-			ProjectID:   100,
-			Prefix:      "/prefix",
-		}
-	}})
-
-	tests := map[string]struct {
-		domain         *Domain
-		host           string
-		expectedFields log.Fields
-	}{
-		"nil_domain_returns_empty_fields": {
-			domain:         nil,
-			host:           "gitlab.io",
-			expectedFields: log.Fields{"pages_https": false, "pages_host": "gitlab.io"},
-		},
-		"unresolved_domain_returns_error": {
-			domain:         New("githost.io", "", "", &resolver{err: ErrDomainDoesNotExist}),
-			host:           "gitlab.io",
-			expectedFields: log.Fields{"error": ErrDomainDoesNotExist.Error(), "pages_https": false, "pages_host": "gitlab.io"},
-		},
-		"domain_with_fields": {
-			domain: domainWithResolver,
-			host:   "gitlab.io",
-			expectedFields: log.Fields{
-				"pages_https":                false,
-				"pages_host":                 "gitlab.io",
-				"pages_project_id":           uint64(100),
-				"pages_project_prefix":       "/prefix",
-				"pages_project_serving_type": "file",
-			},
-		},
-	}
-	for name, tt := range tests {
-		t.Run(name, func(t *testing.T) {
-			r, err := http.NewRequest("GET", "/", nil)
-			require.NoError(t, err)
-
-			r = ReqWithHostAndDomain(r, tt.host, tt.domain)
-			require.Equal(t, tt.expectedFields, LogFields(r))
-		})
-	}
-}
diff --git a/internal/logging/logging.go b/internal/logging/logging.go
index edc670d6..6e8533d8 100644
--- a/internal/logging/logging.go
+++ b/internal/logging/logging.go
@@ -52,34 +52,24 @@ func getAccessLogger(format string) (*logrus.Logger, error) {
 }
 
 // BasicAccessLogger configures the GitLab pages basic HTTP access logger middleware
-func BasicAccessLogger(handler http.Handler, format string, extraFields log.ExtraFieldsGeneratorFunc) (http.Handler, error) {
+func BasicAccessLogger(handler http.Handler, format string) (http.Handler, error) {
 	accessLogger, err := getAccessLogger(format)
 	if err != nil {
 		return nil, err
 	}
 
 	return log.AccessLogger(handler,
-		log.WithExtraFields(enrichExtraFields(extraFields)),
+		log.WithExtraFields(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
+func extraFields(r *http.Request) log.Fields {
+	return log.Fields{
+		"correlation_id": correlation.ExtractFromContext(r.Context()),
+		"pages_https":    request.IsHTTPS(r),
+		"pages_host":     r.Host,
 	}
 }
 
diff --git a/internal/logging/logging_test.go b/internal/logging/logging_test.go
deleted file mode 100644
index d56f6777..00000000
--- a/internal/logging/logging_test.go
+++ /dev/null
@@ -1,87 +0,0 @@
-package logging
-
-import (
-	"net/http"
-	"testing"
-
-	"github.com/stretchr/testify/require"
-
-	"gitlab.com/gitlab-org/gitlab-pages/internal/domain"
-	"gitlab.com/gitlab-org/gitlab-pages/internal/request"
-	"gitlab.com/gitlab-org/gitlab-pages/internal/serving"
-)
-
-type resolver struct {
-	err error
-	f   func(*http.Request) *serving.LookupPath
-}
-
-func (r *resolver) Resolve(req *http.Request) (*serving.Request, error) {
-	if r.f != nil {
-		return &serving.Request{LookupPath: r.f(req)}, nil
-	}
-
-	return nil, r.err
-}
-
-func TestGetExtraLogFields(t *testing.T) {
-	domainWithResolver := domain.New("", "", "", &resolver{f: func(*http.Request) *serving.LookupPath {
-		return &serving.LookupPath{
-			ServingType: "file",
-			ProjectID:   100,
-			Prefix:      "/prefix",
-			SHA256:      "foo",
-		}
-	}})
-
-	tests := []struct {
-		name                  string
-		scheme                string
-		host                  string
-		expectedHTTPS         interface{}
-		expectedHost          interface{}
-		expectedProjectID     interface{}
-		expectedProjectPrefix interface{}
-		expectedServingType   interface{}
-		expectedErrMsg        interface{}
-	}{
-		{
-			name:                  "https",
-			scheme:                request.SchemeHTTPS,
-			host:                  "githost.io",
-			expectedHTTPS:         true,
-			expectedHost:          "githost.io",
-			expectedProjectID:     uint64(100),
-			expectedProjectPrefix: "/prefix",
-			expectedServingType:   "file",
-		},
-		{
-			name:                  "http",
-			scheme:                request.SchemeHTTP,
-			host:                  "githost.io",
-			expectedHTTPS:         false,
-			expectedHost:          "githost.io",
-			expectedProjectID:     uint64(100),
-			expectedProjectPrefix: "/prefix",
-			expectedServingType:   "file",
-		},
-	}
-
-	for _, tt := range tests {
-		t.Run(tt.name, func(t *testing.T) {
-			req, err := http.NewRequest("GET", "/", nil)
-			require.NoError(t, err)
-
-			req.URL.Scheme = tt.scheme
-			req = domain.ReqWithHostAndDomain(req, tt.host, domainWithResolver)
-
-			got := domain.LogFields(req)
-			require.Equal(t, tt.expectedHTTPS, got["pages_https"])
-			require.Equal(t, tt.expectedHost, got["pages_host"])
-			require.Equal(t, tt.expectedProjectID, got["pages_project_id"])
-			require.Equal(t, tt.expectedProjectPrefix, got["pages_project_prefix"])
-			require.Equal(t, tt.expectedServingType, got["pages_project_serving_type"])
-			require.Equal(t, tt.expectedErrMsg, got["error"])
-		})
-	}
-}