diff --git a/cmd/mcrsrv/main.go b/cmd/mcrsrv/main.go index 8750c6f..a6a4b16 100644 --- a/cmd/mcrsrv/main.go +++ b/cmd/mcrsrv/main.go @@ -121,7 +121,7 @@ func runServer(configPath string) error { } // Create OCI handler and HTTP router. - ociHandler := oci.NewHandler(database, store, policyEngine, auditFn) + ociHandler := oci.NewHandler(database, store, policyEngine, auditFn, logger) router := server.NewRouter(authClient, authClient, cfg.MCIAS.ServiceName, ociHandler.Router()) // Mount admin REST endpoints. diff --git a/internal/oci/blob.go b/internal/oci/blob.go index 91da9e7..d6d9d91 100644 --- a/internal/oci/blob.go +++ b/internal/oci/blob.go @@ -23,12 +23,14 @@ func (h *Handler) handleBlobGet(w http.ResponseWriter, r *http.Request, repo, di fmt.Sprintf("repository %q not found", repo)) return } + h.log.Error("blob get: lookup repository", "error", err, "repo", repo) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } exists, err := h.db.BlobExistsInRepo(repoID, digest) if err != nil { + h.log.Error("blob get: check blob exists in repo", "error", err, "repo", repo, "digest", digest) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -40,12 +42,14 @@ func (h *Handler) handleBlobGet(w http.ResponseWriter, r *http.Request, repo, di size, err := h.blobs.Stat(digest) if err != nil { + h.log.Error("blob get: stat blob in storage", "error", err, "repo", repo, "digest", digest) writeOCIError(w, "BLOB_UNKNOWN", http.StatusNotFound, "blob not found in storage") return } rc, err := h.blobs.Open(digest) if err != nil { + h.log.Error("blob get: open blob in storage", "error", err, "repo", repo, "digest", digest) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -70,12 +74,14 @@ func (h *Handler) handleBlobHead(w http.ResponseWriter, r *http.Request, repo, d fmt.Sprintf("repository %q not found", repo)) return } + h.log.Error("blob head: lookup repository", "error", err, "repo", repo) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } exists, err := h.db.BlobExistsInRepo(repoID, digest) if err != nil { + h.log.Error("blob head: check blob exists in repo", "error", err, "repo", repo, "digest", digest) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -87,6 +93,7 @@ func (h *Handler) handleBlobHead(w http.ResponseWriter, r *http.Request, repo, d size, err := h.blobs.Stat(digest) if err != nil { + h.log.Error("blob head: stat blob in storage", "error", err, "repo", repo, "digest", digest) writeOCIError(w, "BLOB_UNKNOWN", http.StatusNotFound, "blob not found in storage") return } diff --git a/internal/oci/blob_test.go b/internal/oci/blob_test.go index 8d45896..21557de 100644 --- a/internal/oci/blob_test.go +++ b/internal/oci/blob_test.go @@ -15,7 +15,7 @@ func TestBlobGet(t *testing.T) { blobs := newFakeBlobs() blobs.data["sha256:layerdigest"] = []byte("layer-content-bytes") - h := NewHandler(fdb, blobs, allowAll(), nil) + h := NewHandler(fdb, blobs, allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/myrepo/blobs/sha256:layerdigest", nil) @@ -47,7 +47,7 @@ func TestBlobHead(t *testing.T) { blobs := newFakeBlobs() blobs.data["sha256:layerdigest"] = []byte("layer-content-bytes") - h := NewHandler(fdb, blobs, allowAll(), nil) + h := NewHandler(fdb, blobs, allowAll(), nil, nil) router := testRouter(h) req := authedRequest("HEAD", "/v2/myrepo/blobs/sha256:layerdigest", nil) @@ -79,7 +79,7 @@ func TestBlobGetNotInRepo(t *testing.T) { blobs := newFakeBlobs() blobs.data["sha256:orphan"] = []byte("data") - h := NewHandler(fdb, blobs, allowAll(), nil) + h := NewHandler(fdb, blobs, allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/myrepo/blobs/sha256:orphan", nil) @@ -103,7 +103,7 @@ func TestBlobGetRepoNotFound(t *testing.T) { fdb := newFakeDB() // No repos. - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/nosuchrepo/blobs/sha256:abc", nil) @@ -131,7 +131,7 @@ func TestBlobGetMultiSegmentRepo(t *testing.T) { blobs := newFakeBlobs() blobs.data["sha256:layerdigest"] = []byte("data") - h := NewHandler(fdb, blobs, allowAll(), nil) + h := NewHandler(fdb, blobs, allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/org/team/app/blobs/sha256:layerdigest", nil) diff --git a/internal/oci/catalog.go b/internal/oci/catalog.go index a44ed73..fbcda55 100644 --- a/internal/oci/catalog.go +++ b/internal/oci/catalog.go @@ -32,6 +32,7 @@ func (h *Handler) handleCatalog(w http.ResponseWriter, r *http.Request) { if n == 0 { repos, err := h.db.ListRepositoryNames(last, 10000) if err != nil { + h.log.Error("catalog: list repository names", "error", err) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -45,6 +46,7 @@ func (h *Handler) handleCatalog(w http.ResponseWriter, r *http.Request) { repos, err := h.db.ListRepositoryNames(last, n+1) if err != nil { + h.log.Error("catalog: list repository names (paginated)", "error", err) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } diff --git a/internal/oci/catalog_test.go b/internal/oci/catalog_test.go index 1496664..a3a947e 100644 --- a/internal/oci/catalog_test.go +++ b/internal/oci/catalog_test.go @@ -13,7 +13,7 @@ func TestCatalog(t *testing.T) { fdb.addRepo("bravo/svc", 2) fdb.addRepo("charlie/app", 3) - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/_catalog", nil) @@ -46,7 +46,7 @@ func TestCatalogPagination(t *testing.T) { fdb.addRepo("bravo/svc", 2) fdb.addRepo("charlie/app", 3) - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) // First page: n=2. @@ -103,7 +103,7 @@ func TestCatalogPagination(t *testing.T) { func TestCatalogEmpty(t *testing.T) { fdb := newFakeDB() - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/_catalog", nil) diff --git a/internal/oci/delete.go b/internal/oci/delete.go index e9ef5ff..eeacfc2 100644 --- a/internal/oci/delete.go +++ b/internal/oci/delete.go @@ -30,6 +30,7 @@ func (h *Handler) handleManifestDelete(w http.ResponseWriter, r *http.Request, r fmt.Sprintf("repository %q not found", repo)) return } + h.log.Error("manifest delete: lookup repository", "error", err, "repo", repo) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -40,12 +41,15 @@ func (h *Handler) handleManifestDelete(w http.ResponseWriter, r *http.Request, r fmt.Sprintf("manifest %q not found", reference)) return } + h.log.Error("manifest delete: delete from database", "error", err, "repo", repo, "digest", reference) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } h.audit(r, "manifest_deleted", repo, reference) + h.log.Info("manifest deleted", "repo", repo, "digest", reference) + w.WriteHeader(http.StatusAccepted) } @@ -64,6 +68,7 @@ func (h *Handler) handleBlobDelete(w http.ResponseWriter, r *http.Request, repo, fmt.Sprintf("repository %q not found", repo)) return } + h.log.Error("blob delete: lookup repository", "error", err, "repo", repo) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -74,11 +79,14 @@ func (h *Handler) handleBlobDelete(w http.ResponseWriter, r *http.Request, repo, fmt.Sprintf("blob %q not found in repository", digest)) return } + h.log.Error("blob delete: delete from database", "error", err, "repo", repo, "digest", digest) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } h.audit(r, "blob_deleted", repo, digest) + h.log.Info("blob deleted", "repo", repo, "digest", digest) + w.WriteHeader(http.StatusAccepted) } diff --git a/internal/oci/delete_test.go b/internal/oci/delete_test.go index dec957a..4983fe5 100644 --- a/internal/oci/delete_test.go +++ b/internal/oci/delete_test.go @@ -13,7 +13,7 @@ func TestManifestDeleteByDigest(t *testing.T) { content := []byte(`{"schemaVersion":2}`) fdb.addManifest(1, "latest", "sha256:aaaa", "application/vnd.oci.image.manifest.v1+json", content) - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("DELETE", "/v2/myrepo/manifests/sha256:aaaa", nil) @@ -37,7 +37,7 @@ func TestManifestDeleteByTagUnsupported(t *testing.T) { content := []byte(`{"schemaVersion":2}`) fdb.addManifest(1, "latest", "sha256:aaaa", "application/vnd.oci.image.manifest.v1+json", content) - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("DELETE", "/v2/myrepo/manifests/latest", nil) @@ -62,7 +62,7 @@ func TestManifestDeleteNotFound(t *testing.T) { fdb.addRepo("myrepo", 1) // No manifests added. - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("DELETE", "/v2/myrepo/manifests/sha256:nonexistent", nil) @@ -85,7 +85,7 @@ func TestManifestDeleteNotFound(t *testing.T) { func TestManifestDeleteRepoNotFound(t *testing.T) { fdb := newFakeDB() - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("DELETE", "/v2/nosuchrepo/manifests/sha256:aaaa", nil) @@ -111,7 +111,7 @@ func TestManifestDeleteCascadesTag(t *testing.T) { content := []byte(`{"schemaVersion":2}`) fdb.addManifest(1, "latest", "sha256:aaaa", "application/vnd.oci.image.manifest.v1+json", content) - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("DELETE", "/v2/myrepo/manifests/sha256:aaaa", nil) @@ -134,7 +134,7 @@ func TestBlobDelete(t *testing.T) { fdb.addRepo("myrepo", 1) fdb.addBlob(1, "sha256:b1") - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("DELETE", "/v2/myrepo/blobs/sha256:b1", nil) @@ -157,7 +157,7 @@ func TestBlobDeleteNotInRepo(t *testing.T) { fdb.addRepo("myrepo", 1) // Blob not added to this repo. - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("DELETE", "/v2/myrepo/blobs/sha256:nonexistent", nil) @@ -180,7 +180,7 @@ func TestBlobDeleteNotInRepo(t *testing.T) { func TestBlobDeleteRepoNotFound(t *testing.T) { fdb := newFakeDB() - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("DELETE", "/v2/nosuchrepo/blobs/sha256:b1", nil) diff --git a/internal/oci/handler.go b/internal/oci/handler.go index 1f1992f..95a0ad4 100644 --- a/internal/oci/handler.go +++ b/internal/oci/handler.go @@ -2,6 +2,7 @@ package oci import ( "io" + "log/slog" "net/http" "strings" @@ -61,16 +62,21 @@ type Handler struct { policy PolicyEval auditFn AuditFunc uploads *uploadManager + log *slog.Logger } -// NewHandler creates a new OCI handler. -func NewHandler(querier DBQuerier, blobs BlobStore, pol PolicyEval, auditFn AuditFunc) *Handler { +// NewHandler creates a new OCI handler. If logger is nil, slog.Default() is used. +func NewHandler(querier DBQuerier, blobs BlobStore, pol PolicyEval, auditFn AuditFunc, logger *slog.Logger) *Handler { + if logger == nil { + logger = slog.Default() + } return &Handler{ db: querier, blobs: blobs, policy: pol, auditFn: auditFn, uploads: newUploadManager(), + log: logger.With("component", "oci"), } } diff --git a/internal/oci/manifest.go b/internal/oci/manifest.go index 9ce62de..c1aab6b 100644 --- a/internal/oci/manifest.go +++ b/internal/oci/manifest.go @@ -59,6 +59,7 @@ func (h *Handler) resolveManifest(w http.ResponseWriter, repo, reference string) fmt.Sprintf("repository %q not found", repo)) return nil, false } + h.log.Error("manifest resolve: lookup repository", "error", err, "repo", repo) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return nil, false } @@ -75,6 +76,7 @@ func (h *Handler) resolveManifest(w http.ResponseWriter, repo, reference string) fmt.Sprintf("manifest %q not found", reference)) return nil, false } + h.log.Error("manifest resolve: lookup manifest", "error", err, "repo", repo, "reference", reference) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return nil, false } @@ -175,6 +177,7 @@ func (h *Handler) handleManifestPut(w http.ResponseWriter, r *http.Request, repo for _, bd := range blobDigests { exists, err := h.db.BlobExists(bd) if err != nil { + h.log.Error("manifest push: check blob exists", "error", err, "repo", repo, "blob_digest", bd) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -197,6 +200,7 @@ func (h *Handler) handleManifestPut(w http.ResponseWriter, r *http.Request, repo BlobDigests: blobDigests, } if err := h.db.PushManifest(params); err != nil { + h.log.Error("manifest push: write to database", "error", err, "repo", repo, "digest", computedDigest, "tag", tag) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -215,6 +219,8 @@ func (h *Handler) handleManifestPut(w http.ResponseWriter, r *http.Request, repo h.auditFn("manifest_pushed", actorID, repo, computedDigest, r.RemoteAddr, details) } + h.log.Info("manifest pushed", "repo", repo, "digest", computedDigest, "tag", tag, "size", len(body)) + w.Header().Set("Location", fmt.Sprintf("/v2/%s/manifests/%s", repo, computedDigest)) w.Header().Set("Docker-Content-Digest", computedDigest) w.Header().Set("Content-Type", mediaType) diff --git a/internal/oci/manifest_test.go b/internal/oci/manifest_test.go index 0295d74..2b8fa6b 100644 --- a/internal/oci/manifest_test.go +++ b/internal/oci/manifest_test.go @@ -13,7 +13,7 @@ func TestManifestGetByTag(t *testing.T) { content := []byte(`{"schemaVersion":2}`) fdb.addManifest(1, "latest", "sha256:aaaa", "application/vnd.oci.image.manifest.v1+json", content) - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/myrepo/manifests/latest", nil) @@ -43,7 +43,7 @@ func TestManifestGetByDigest(t *testing.T) { content := []byte(`{"schemaVersion":2}`) fdb.addManifest(1, "latest", "sha256:aaaa", "application/vnd.oci.image.manifest.v1+json", content) - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/myrepo/manifests/sha256:aaaa", nil) @@ -67,7 +67,7 @@ func TestManifestHead(t *testing.T) { content := []byte(`{"schemaVersion":2}`) fdb.addManifest(1, "latest", "sha256:aaaa", "application/vnd.oci.image.manifest.v1+json", content) - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("HEAD", "/v2/myrepo/manifests/latest", nil) @@ -95,7 +95,7 @@ func TestManifestGetRepoNotFound(t *testing.T) { fdb := newFakeDB() // No repos added. - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/nosuchrepo/manifests/latest", nil) @@ -120,7 +120,7 @@ func TestManifestGetManifestNotFoundByTag(t *testing.T) { fdb.addRepo("myrepo", 1) // No manifests added. - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/myrepo/manifests/nonexistent", nil) @@ -145,7 +145,7 @@ func TestManifestGetManifestNotFoundByDigest(t *testing.T) { fdb.addRepo("myrepo", 1) // No manifests added. - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/myrepo/manifests/sha256:nonexistent", nil) @@ -171,7 +171,7 @@ func TestManifestGetMultiSegmentRepo(t *testing.T) { content := []byte(`{"layers":[]}`) fdb.addManifest(1, "v1.0", "sha256:cccc", "application/vnd.oci.image.manifest.v1+json", content) - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/org/team/app/manifests/v1.0", nil) diff --git a/internal/oci/push_test.go b/internal/oci/push_test.go index 8a00515..63e6bfd 100644 --- a/internal/oci/push_test.go +++ b/internal/oci/push_test.go @@ -32,7 +32,7 @@ func TestManifestPushByTag(t *testing.T) { fdb.addGlobalBlob("sha256:config1") fdb.addGlobalBlob("sha256:layer1") - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) content := makeManifest("sha256:config1", []string{"sha256:layer1"}) @@ -79,7 +79,7 @@ func TestManifestPushByDigest(t *testing.T) { fdb.addRepo("myrepo", 1) fdb.addGlobalBlob("sha256:config1") - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) content := makeManifest("sha256:config1", nil) @@ -107,7 +107,7 @@ func TestManifestPushDigestMismatch(t *testing.T) { fdb := newFakeDB() fdb.addRepo("myrepo", 1) - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) content := []byte(`{"schemaVersion":2}`) @@ -137,7 +137,7 @@ func TestManifestPushMissingBlob(t *testing.T) { // Config blob exists but layer blob does not. fdb.addGlobalBlob("sha256:config1") - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) content := makeManifest("sha256:config1", []string{"sha256:missing_layer"}) @@ -164,7 +164,7 @@ func TestManifestPushMalformed(t *testing.T) { fdb := newFakeDB() fdb.addRepo("myrepo", 1) - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedPushRequest("PUT", "/v2/myrepo/manifests/latest", []byte("not valid json")) @@ -189,7 +189,7 @@ func TestManifestPushEmpty(t *testing.T) { fdb := newFakeDB() fdb.addRepo("myrepo", 1) - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedPushRequest("PUT", "/v2/myrepo/manifests/latest", nil) @@ -207,7 +207,7 @@ func TestManifestPushUpdatesTag(t *testing.T) { fdb.addRepo("myrepo", 1) fdb.addGlobalBlob("sha256:config1") - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) // First push with tag "latest". @@ -248,7 +248,7 @@ func TestManifestPushRepushIdempotent(t *testing.T) { fdb.addRepo("myrepo", 1) fdb.addGlobalBlob("sha256:config1") - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) content := makeManifest("sha256:config1", nil) diff --git a/internal/oci/tags.go b/internal/oci/tags.go index 5df524f..a8b64b7 100644 --- a/internal/oci/tags.go +++ b/internal/oci/tags.go @@ -28,6 +28,7 @@ func (h *Handler) handleTagsList(w http.ResponseWriter, r *http.Request, repo st fmt.Sprintf("repository %q not found", repo)) return } + h.log.Error("tags list: lookup repository", "error", err, "repo", repo) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -47,6 +48,7 @@ func (h *Handler) handleTagsList(w http.ResponseWriter, r *http.Request, repo st if n == 0 { tags, err := h.db.ListTags(repoID, last, 10000) if err != nil { + h.log.Error("tags list: list tags", "error", err, "repo", repo) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -61,6 +63,7 @@ func (h *Handler) handleTagsList(w http.ResponseWriter, r *http.Request, repo st // Request n+1 to detect if there are more results. tags, err := h.db.ListTags(repoID, last, n+1) if err != nil { + h.log.Error("tags list: list tags (paginated)", "error", err, "repo", repo) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } diff --git a/internal/oci/tags_test.go b/internal/oci/tags_test.go index 6ac8418..e1c5583 100644 --- a/internal/oci/tags_test.go +++ b/internal/oci/tags_test.go @@ -14,7 +14,7 @@ func TestTagsList(t *testing.T) { fdb.addTag(1, "v1.0") fdb.addTag(1, "v2.0") - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/myrepo/tags/list", nil) @@ -50,7 +50,7 @@ func TestTagsListPagination(t *testing.T) { fdb.addTag(1, "beta") fdb.addTag(1, "gamma") - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) // First page: n=2. @@ -109,7 +109,7 @@ func TestTagsListEmpty(t *testing.T) { fdb.addRepo("myrepo", 1) // No tags. - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/myrepo/tags/list", nil) @@ -133,7 +133,7 @@ func TestTagsListRepoNotFound(t *testing.T) { fdb := newFakeDB() // No repos. - h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) + h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil) router := testRouter(h) req := authedRequest("GET", "/v2/nosuchrepo/tags/list", nil) diff --git a/internal/oci/upload.go b/internal/oci/upload.go index 50a8ce1..f332236 100644 --- a/internal/oci/upload.go +++ b/internal/oci/upload.go @@ -64,18 +64,21 @@ func (h *Handler) handleUploadInitiate(w http.ResponseWriter, r *http.Request, r // Create repository if it doesn't exist (implicit creation). repoID, err := h.db.GetOrCreateRepository(repo) if err != nil { + h.log.Error("upload initiate: get or create repository", "error", err, "repo", repo) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } uuid, err := generateUUID() if err != nil { + h.log.Error("upload initiate: generate uuid", "error", err, "repo", repo) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } // Insert upload row in DB. if err := h.db.CreateUpload(uuid, repoID); err != nil { + h.log.Error("upload initiate: create upload in database", "error", err, "repo", repo, "uuid", uuid) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -85,12 +88,15 @@ func (h *Handler) handleUploadInitiate(w http.ResponseWriter, r *http.Request, r if err != nil { // Clean up DB row on storage failure. _ = h.db.DeleteUpload(uuid) + h.log.Error("upload initiate: start upload in storage", "error", err, "repo", repo, "uuid", uuid) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } h.uploads.set(uuid, bw) + h.log.Info("upload initiated", "repo", repo, "uuid", uuid) + w.Header().Set("Location", fmt.Sprintf("/v2/%s/blobs/uploads/%s", repo, uuid)) w.Header().Set("Docker-Upload-UUID", uuid) w.Header().Set("Range", "0-0") @@ -112,6 +118,7 @@ func (h *Handler) handleUploadChunk(w http.ResponseWriter, r *http.Request, repo // Append request body to upload file. n, err := io.Copy(bw, r.Body) if err != nil { + h.log.Error("upload chunk: write to storage", "error", err, "repo", repo, "uuid", uuid) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "write failed") return } @@ -119,6 +126,7 @@ func (h *Handler) handleUploadChunk(w http.ResponseWriter, r *http.Request, repo // Update offset in DB. newOffset := bw.BytesWritten() if err := h.db.UpdateUploadOffset(uuid, newOffset); err != nil { + h.log.Error("upload chunk: update offset in database", "error", err, "repo", repo, "uuid", uuid, "offset", newOffset) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -152,6 +160,7 @@ func (h *Handler) handleUploadComplete(w http.ResponseWriter, r *http.Request, r // If request body is non-empty, append it first (monolithic upload). if r.ContentLength != 0 { if _, err := io.Copy(bw, r.Body); err != nil { + h.log.Error("upload complete: write final chunk to storage", "error", err, "repo", repo, "uuid", uuid) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "write failed") return } @@ -172,6 +181,7 @@ func (h *Handler) handleUploadComplete(w http.ResponseWriter, r *http.Request, r writeOCIError(w, "DIGEST_INVALID", http.StatusBadRequest, "invalid digest format") return } + h.log.Error("upload complete: commit blob", "error", err, "repo", repo, "uuid", uuid, "digest", digest) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "commit failed") return } @@ -180,6 +190,7 @@ func (h *Handler) handleUploadComplete(w http.ResponseWriter, r *http.Request, r // Insert blob row (no-op if already exists — content-addressed dedup). if err := h.db.InsertBlob(digest, size); err != nil { + h.log.Error("upload complete: insert blob in database", "error", err, "repo", repo, "digest", digest, "size", size) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -189,6 +200,8 @@ func (h *Handler) handleUploadComplete(w http.ResponseWriter, r *http.Request, r h.audit(r, "blob_uploaded", repo, digest) + h.log.Info("blob upload complete", "repo", repo, "digest", digest, "size", size) + w.Header().Set("Location", fmt.Sprintf("/v2/%s/blobs/%s", repo, digest)) w.Header().Set("Docker-Content-Digest", digest) w.WriteHeader(http.StatusCreated) @@ -206,6 +219,7 @@ func (h *Handler) handleUploadStatus(w http.ResponseWriter, r *http.Request, rep writeOCIError(w, "BLOB_UPLOAD_UNKNOWN", http.StatusNotFound, "upload not found") return } + h.log.Error("upload status: lookup upload", "error", err, "repo", repo, "uuid", uuid) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } @@ -233,6 +247,7 @@ func (h *Handler) handleUploadCancel(w http.ResponseWriter, r *http.Request, rep writeOCIError(w, "BLOB_UPLOAD_UNKNOWN", http.StatusNotFound, "upload not found") return } + h.log.Error("upload cancel: delete upload from database", "error", err, "repo", repo, "uuid", uuid) writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") return } diff --git a/internal/oci/upload_test.go b/internal/oci/upload_test.go index 4d524df..b85a3c9 100644 --- a/internal/oci/upload_test.go +++ b/internal/oci/upload_test.go @@ -21,7 +21,7 @@ func testHandlerWithStorage(t *testing.T, fdb *fakeDB) (*Handler, *chi.Mux) { t.Helper() dir := t.TempDir() store := storage.New(dir+"/layers", dir+"/uploads") - h := NewHandler(fdb, store, allowAll(), nil) + h := NewHandler(fdb, store, allowAll(), nil, nil) router := chi.NewRouter() router.Mount("/v2", h.Router()) return h, router