Merge branch 'intermittent-404s' into 'master'

Add logs for more visibility in 404s and archive corruption event

See merge request gitlab-org/gitlab-pages!760

6 files changed, 36 insertions, 2 deletions

diff --git a/internal/domain/domain.go b/internal/domain/domain.go
index 76a1cf25..1cfee100 100644
--- a/internal/domain/domain.go
+++ b/internal/domain/domain.go
@@ -9,6 +9,7 @@ import (
 
 	"gitlab.com/gitlab-org/gitlab-pages/internal/errortracking"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/httperrors"
+	"gitlab.com/gitlab-org/gitlab-pages/internal/logging"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/serving"
 )
 
@@ -126,6 +127,7 @@ func (d *Domain) ServeFileHTTP(w http.ResponseWriter, r *http.Request) bool {
 	if err != nil {
 		if errors.Is(err, ErrDomainDoesNotExist) {
 			// serve generic 404
+			logging.LogRequest(r).WithError(ErrDomainDoesNotExist).Error("failed to serve the file")
 			httperrors.Serve404(w)
 			return true
 		}
@@ -144,6 +146,7 @@ func (d *Domain) ServeNotFoundHTTP(w http.ResponseWriter, r *http.Request) {
 	if err != nil {
 		if errors.Is(err, ErrDomainDoesNotExist) {
 			// serve generic 404
+			logging.LogRequest(r).WithError(ErrDomainDoesNotExist).Error("failed to serve the not found page")
 			httperrors.Serve404(w)
 			return
 		}
@@ -168,6 +171,7 @@ func (d *Domain) ServeNamespaceNotFound(w http.ResponseWriter, r *http.Request)
 	if err != nil {
 		if errors.Is(err, ErrDomainDoesNotExist) {
 			// serve generic 404
+			logging.LogRequest(r).WithError(ErrDomainDoesNotExist).Error("failed while finding parent namespace domain for a request that failed authentication")
 			httperrors.Serve404(w)
 			return
 		}
diff --git a/internal/httprange/http_reader.go b/internal/httprange/http_reader.go
index 08779bc8..8e85a6d3 100644
--- a/internal/httprange/http_reader.go
+++ b/internal/httprange/http_reader.go
@@ -88,8 +88,13 @@ func (r *Reader) ensureResponse() error {
 		// cleanup body on failure from r.setResponse to avoid memory leak
 		res.Body.Close()
 		logging.LogRequest(req).WithError(err).WithFields(log.Fields{
-			"status":      res.StatusCode,
-			"status_text": res.Status,
+			"range_start":   r.rangeStart,
+			"range_size":    r.rangeSize,
+			"offset":        r.offset,
+			"resource_size": r.Resource.Size,
+			"resource_url":  logging.CleanURL(r.Resource.URL()),
+			"status":        res.StatusCode,
+			"status_text":   res.Status,
 		}).Error(rangeRequestFailedErrMsg)
 	}
 
diff --git a/internal/source/gitlab/client/client.go b/internal/source/gitlab/client/client.go
index 5dc090dd..4fd2363b 100644
--- a/internal/source/gitlab/client/client.go
+++ b/internal/source/gitlab/client/client.go
@@ -13,6 +13,7 @@ import (
 
 	"github.com/golang-jwt/jwt/v4"
 	"gitlab.com/gitlab-org/labkit/correlation"
+	"gitlab.com/gitlab-org/labkit/log"
 
 	"gitlab.com/gitlab-org/gitlab-pages/internal/config"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/domain"
@@ -108,6 +109,11 @@ func (gc *Client) GetLookup(ctx context.Context, host string) api.Lookup {
 	}
 
 	if resp == nil {
+		log.WithError(domain.ErrDomainDoesNotExist).WithFields(
+			log.Fields{
+				"correlation_id": correlation.ExtractFromContext(ctx),
+				"host":           host,
+			}).Error("unexpected nil response from gitlab")
 		return api.Lookup{Name: host, Error: domain.ErrDomainDoesNotExist}
 	}
 
diff --git a/internal/source/gitlab/gitlab.go b/internal/source/gitlab/gitlab.go
index d0233028..e1087ddb 100644
--- a/internal/source/gitlab/gitlab.go
+++ b/internal/source/gitlab/gitlab.go
@@ -12,6 +12,7 @@ import (
 
 	"gitlab.com/gitlab-org/gitlab-pages/internal/config"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/domain"
+	"gitlab.com/gitlab-org/gitlab-pages/internal/logging"
 	"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"
@@ -99,6 +100,14 @@ func (g *Gitlab) Resolve(r *http.Request) (*serving.Request, error) {
 		}
 	}
 
+	logging.LogRequest(r).WithError(domain.ErrDomainDoesNotExist).WithFields(
+		log.Fields{
+			"host":               host,
+			"lookup_paths_count": size,
+			"lookup_paths":       response.Domain.LookupPaths,
+			"url_path":           urlPath,
+		}).Error("could not find project lookup path")
+
 	return nil, domain.ErrDomainDoesNotExist
 }
 
diff --git a/internal/vfs/zip/archive.go b/internal/vfs/zip/archive.go
index c44f45ef..0a9ac0d7 100644
--- a/internal/vfs/zip/archive.go
+++ b/internal/vfs/zip/archive.go
@@ -121,6 +121,9 @@ func (a *zipArchive) readArchive(url string) {
 
 	a.resource, a.err = httprange.NewResource(ctx, url, a.fs.httpClient)
 	if a.err != nil {
+		log.WithFields(log.Fields{
+			"url": url,
+		}).WithError(a.err).Infoln("read zip archive request failed")
 		metrics.ZipOpened.WithLabelValues("error").Inc()
 		return
 	}
@@ -132,6 +135,9 @@ func (a *zipArchive) readArchive(url string) {
 	})
 
 	if a.archive == nil || a.err != nil {
+		log.WithFields(log.Fields{
+			"url": url,
+		}).WithError(a.err).Infoln("loading zip archive files into memory failed")
 		metrics.ZipOpened.WithLabelValues("error").Inc()
 		return
 	}
diff --git a/internal/vfs/zip/vfs.go b/internal/vfs/zip/vfs.go
index 3fcef556..b87b7822 100644
--- a/internal/vfs/zip/vfs.go
+++ b/internal/vfs/zip/vfs.go
@@ -9,6 +9,7 @@ import (
 	"time"
 
 	"github.com/patrickmn/go-cache"
+	"gitlab.com/gitlab-org/labkit/log"
 
 	"gitlab.com/gitlab-org/gitlab-pages/internal/config"
 	"gitlab.com/gitlab-org/gitlab-pages/internal/httpfs"
@@ -208,6 +209,9 @@ func (zfs *zipVFS) findOrCreateArchive(key string) (*zipArchive, error) {
 		case archiveCorrupted:
 			// this means that archive is likely changed
 			// we should invalidate it immediately
+			log.WithFields(log.Fields{
+				"archive_key": key,
+			}).Error("archive corrupted")
 			metrics.ZipCacheRequests.WithLabelValues("archive", "corrupted").Inc()
 			archive = nil
 		}