Add structured error logging to OCI handlers

Every 500 response in the OCI package silently discarded the actual
error, making production debugging impossible. Add slog.Error before
each 500 response with the error and relevant context (repo, digest,
tag, uuid). Add slog.Info for state-mutating successes (manifest push,
blob upload complete, deletions).

Logger is injected into the OCI Handler via constructor, falling back
to slog.Default() if nil.

Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com>
This commit is contained in:
2026-03-26 12:47:44 -07:00
parent 61b8c2fcef
commit ef39152f4e
15 changed files with 86 additions and 39 deletions

View File

@@ -121,7 +121,7 @@ func runServer(configPath string) error {
} }
// Create OCI handler and HTTP router. // 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()) router := server.NewRouter(authClient, authClient, cfg.MCIAS.ServiceName, ociHandler.Router())
// Mount admin REST endpoints. // Mount admin REST endpoints.

View File

@@ -23,12 +23,14 @@ func (h *Handler) handleBlobGet(w http.ResponseWriter, r *http.Request, repo, di
fmt.Sprintf("repository %q not found", repo)) fmt.Sprintf("repository %q not found", repo))
return return
} }
h.log.Error("blob get: lookup repository", "error", err, "repo", repo)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
exists, err := h.db.BlobExistsInRepo(repoID, digest) exists, err := h.db.BlobExistsInRepo(repoID, digest)
if err != nil { 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") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
@@ -40,12 +42,14 @@ func (h *Handler) handleBlobGet(w http.ResponseWriter, r *http.Request, repo, di
size, err := h.blobs.Stat(digest) size, err := h.blobs.Stat(digest)
if err != nil { 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") writeOCIError(w, "BLOB_UNKNOWN", http.StatusNotFound, "blob not found in storage")
return return
} }
rc, err := h.blobs.Open(digest) rc, err := h.blobs.Open(digest)
if err != nil { 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") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
@@ -70,12 +74,14 @@ func (h *Handler) handleBlobHead(w http.ResponseWriter, r *http.Request, repo, d
fmt.Sprintf("repository %q not found", repo)) fmt.Sprintf("repository %q not found", repo))
return return
} }
h.log.Error("blob head: lookup repository", "error", err, "repo", repo)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
exists, err := h.db.BlobExistsInRepo(repoID, digest) exists, err := h.db.BlobExistsInRepo(repoID, digest)
if err != nil { 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") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
@@ -87,6 +93,7 @@ func (h *Handler) handleBlobHead(w http.ResponseWriter, r *http.Request, repo, d
size, err := h.blobs.Stat(digest) size, err := h.blobs.Stat(digest)
if err != nil { 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") writeOCIError(w, "BLOB_UNKNOWN", http.StatusNotFound, "blob not found in storage")
return return
} }

View File

@@ -15,7 +15,7 @@ func TestBlobGet(t *testing.T) {
blobs := newFakeBlobs() blobs := newFakeBlobs()
blobs.data["sha256:layerdigest"] = []byte("layer-content-bytes") blobs.data["sha256:layerdigest"] = []byte("layer-content-bytes")
h := NewHandler(fdb, blobs, allowAll(), nil) h := NewHandler(fdb, blobs, allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("GET", "/v2/myrepo/blobs/sha256:layerdigest", nil) req := authedRequest("GET", "/v2/myrepo/blobs/sha256:layerdigest", nil)
@@ -47,7 +47,7 @@ func TestBlobHead(t *testing.T) {
blobs := newFakeBlobs() blobs := newFakeBlobs()
blobs.data["sha256:layerdigest"] = []byte("layer-content-bytes") blobs.data["sha256:layerdigest"] = []byte("layer-content-bytes")
h := NewHandler(fdb, blobs, allowAll(), nil) h := NewHandler(fdb, blobs, allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("HEAD", "/v2/myrepo/blobs/sha256:layerdigest", nil) req := authedRequest("HEAD", "/v2/myrepo/blobs/sha256:layerdigest", nil)
@@ -79,7 +79,7 @@ func TestBlobGetNotInRepo(t *testing.T) {
blobs := newFakeBlobs() blobs := newFakeBlobs()
blobs.data["sha256:orphan"] = []byte("data") blobs.data["sha256:orphan"] = []byte("data")
h := NewHandler(fdb, blobs, allowAll(), nil) h := NewHandler(fdb, blobs, allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("GET", "/v2/myrepo/blobs/sha256:orphan", nil) req := authedRequest("GET", "/v2/myrepo/blobs/sha256:orphan", nil)
@@ -103,7 +103,7 @@ func TestBlobGetRepoNotFound(t *testing.T) {
fdb := newFakeDB() fdb := newFakeDB()
// No repos. // No repos.
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("GET", "/v2/nosuchrepo/blobs/sha256:abc", nil) req := authedRequest("GET", "/v2/nosuchrepo/blobs/sha256:abc", nil)
@@ -131,7 +131,7 @@ func TestBlobGetMultiSegmentRepo(t *testing.T) {
blobs := newFakeBlobs() blobs := newFakeBlobs()
blobs.data["sha256:layerdigest"] = []byte("data") blobs.data["sha256:layerdigest"] = []byte("data")
h := NewHandler(fdb, blobs, allowAll(), nil) h := NewHandler(fdb, blobs, allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("GET", "/v2/org/team/app/blobs/sha256:layerdigest", nil) req := authedRequest("GET", "/v2/org/team/app/blobs/sha256:layerdigest", nil)

View File

@@ -32,6 +32,7 @@ func (h *Handler) handleCatalog(w http.ResponseWriter, r *http.Request) {
if n == 0 { if n == 0 {
repos, err := h.db.ListRepositoryNames(last, 10000) repos, err := h.db.ListRepositoryNames(last, 10000)
if err != nil { if err != nil {
h.log.Error("catalog: list repository names", "error", err)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
@@ -45,6 +46,7 @@ func (h *Handler) handleCatalog(w http.ResponseWriter, r *http.Request) {
repos, err := h.db.ListRepositoryNames(last, n+1) repos, err := h.db.ListRepositoryNames(last, n+1)
if err != nil { if err != nil {
h.log.Error("catalog: list repository names (paginated)", "error", err)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }

View File

@@ -13,7 +13,7 @@ func TestCatalog(t *testing.T) {
fdb.addRepo("bravo/svc", 2) fdb.addRepo("bravo/svc", 2)
fdb.addRepo("charlie/app", 3) fdb.addRepo("charlie/app", 3)
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("GET", "/v2/_catalog", nil) req := authedRequest("GET", "/v2/_catalog", nil)
@@ -46,7 +46,7 @@ func TestCatalogPagination(t *testing.T) {
fdb.addRepo("bravo/svc", 2) fdb.addRepo("bravo/svc", 2)
fdb.addRepo("charlie/app", 3) fdb.addRepo("charlie/app", 3)
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
// First page: n=2. // First page: n=2.
@@ -103,7 +103,7 @@ func TestCatalogPagination(t *testing.T) {
func TestCatalogEmpty(t *testing.T) { func TestCatalogEmpty(t *testing.T) {
fdb := newFakeDB() fdb := newFakeDB()
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("GET", "/v2/_catalog", nil) req := authedRequest("GET", "/v2/_catalog", nil)

View File

@@ -30,6 +30,7 @@ func (h *Handler) handleManifestDelete(w http.ResponseWriter, r *http.Request, r
fmt.Sprintf("repository %q not found", repo)) fmt.Sprintf("repository %q not found", repo))
return return
} }
h.log.Error("manifest delete: lookup repository", "error", err, "repo", repo)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
@@ -40,12 +41,15 @@ func (h *Handler) handleManifestDelete(w http.ResponseWriter, r *http.Request, r
fmt.Sprintf("manifest %q not found", reference)) fmt.Sprintf("manifest %q not found", reference))
return return
} }
h.log.Error("manifest delete: delete from database", "error", err, "repo", repo, "digest", reference)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
h.audit(r, "manifest_deleted", repo, reference) h.audit(r, "manifest_deleted", repo, reference)
h.log.Info("manifest deleted", "repo", repo, "digest", reference)
w.WriteHeader(http.StatusAccepted) 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)) fmt.Sprintf("repository %q not found", repo))
return return
} }
h.log.Error("blob delete: lookup repository", "error", err, "repo", repo)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return 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)) fmt.Sprintf("blob %q not found in repository", digest))
return return
} }
h.log.Error("blob delete: delete from database", "error", err, "repo", repo, "digest", digest)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
h.audit(r, "blob_deleted", repo, digest) h.audit(r, "blob_deleted", repo, digest)
h.log.Info("blob deleted", "repo", repo, "digest", digest)
w.WriteHeader(http.StatusAccepted) w.WriteHeader(http.StatusAccepted)
} }

View File

@@ -13,7 +13,7 @@ func TestManifestDeleteByDigest(t *testing.T) {
content := []byte(`{"schemaVersion":2}`) content := []byte(`{"schemaVersion":2}`)
fdb.addManifest(1, "latest", "sha256:aaaa", "application/vnd.oci.image.manifest.v1+json", content) 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) router := testRouter(h)
req := authedRequest("DELETE", "/v2/myrepo/manifests/sha256:aaaa", nil) req := authedRequest("DELETE", "/v2/myrepo/manifests/sha256:aaaa", nil)
@@ -37,7 +37,7 @@ func TestManifestDeleteByTagUnsupported(t *testing.T) {
content := []byte(`{"schemaVersion":2}`) content := []byte(`{"schemaVersion":2}`)
fdb.addManifest(1, "latest", "sha256:aaaa", "application/vnd.oci.image.manifest.v1+json", content) 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) router := testRouter(h)
req := authedRequest("DELETE", "/v2/myrepo/manifests/latest", nil) req := authedRequest("DELETE", "/v2/myrepo/manifests/latest", nil)
@@ -62,7 +62,7 @@ func TestManifestDeleteNotFound(t *testing.T) {
fdb.addRepo("myrepo", 1) fdb.addRepo("myrepo", 1)
// No manifests added. // No manifests added.
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("DELETE", "/v2/myrepo/manifests/sha256:nonexistent", nil) req := authedRequest("DELETE", "/v2/myrepo/manifests/sha256:nonexistent", nil)
@@ -85,7 +85,7 @@ func TestManifestDeleteNotFound(t *testing.T) {
func TestManifestDeleteRepoNotFound(t *testing.T) { func TestManifestDeleteRepoNotFound(t *testing.T) {
fdb := newFakeDB() fdb := newFakeDB()
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("DELETE", "/v2/nosuchrepo/manifests/sha256:aaaa", nil) req := authedRequest("DELETE", "/v2/nosuchrepo/manifests/sha256:aaaa", nil)
@@ -111,7 +111,7 @@ func TestManifestDeleteCascadesTag(t *testing.T) {
content := []byte(`{"schemaVersion":2}`) content := []byte(`{"schemaVersion":2}`)
fdb.addManifest(1, "latest", "sha256:aaaa", "application/vnd.oci.image.manifest.v1+json", content) 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) router := testRouter(h)
req := authedRequest("DELETE", "/v2/myrepo/manifests/sha256:aaaa", nil) req := authedRequest("DELETE", "/v2/myrepo/manifests/sha256:aaaa", nil)
@@ -134,7 +134,7 @@ func TestBlobDelete(t *testing.T) {
fdb.addRepo("myrepo", 1) fdb.addRepo("myrepo", 1)
fdb.addBlob(1, "sha256:b1") fdb.addBlob(1, "sha256:b1")
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("DELETE", "/v2/myrepo/blobs/sha256:b1", nil) req := authedRequest("DELETE", "/v2/myrepo/blobs/sha256:b1", nil)
@@ -157,7 +157,7 @@ func TestBlobDeleteNotInRepo(t *testing.T) {
fdb.addRepo("myrepo", 1) fdb.addRepo("myrepo", 1)
// Blob not added to this repo. // Blob not added to this repo.
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("DELETE", "/v2/myrepo/blobs/sha256:nonexistent", nil) req := authedRequest("DELETE", "/v2/myrepo/blobs/sha256:nonexistent", nil)
@@ -180,7 +180,7 @@ func TestBlobDeleteNotInRepo(t *testing.T) {
func TestBlobDeleteRepoNotFound(t *testing.T) { func TestBlobDeleteRepoNotFound(t *testing.T) {
fdb := newFakeDB() fdb := newFakeDB()
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("DELETE", "/v2/nosuchrepo/blobs/sha256:b1", nil) req := authedRequest("DELETE", "/v2/nosuchrepo/blobs/sha256:b1", nil)

View File

@@ -2,6 +2,7 @@ package oci
import ( import (
"io" "io"
"log/slog"
"net/http" "net/http"
"strings" "strings"
@@ -61,16 +62,21 @@ type Handler struct {
policy PolicyEval policy PolicyEval
auditFn AuditFunc auditFn AuditFunc
uploads *uploadManager uploads *uploadManager
log *slog.Logger
} }
// NewHandler creates a new OCI 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) *Handler { func NewHandler(querier DBQuerier, blobs BlobStore, pol PolicyEval, auditFn AuditFunc, logger *slog.Logger) *Handler {
if logger == nil {
logger = slog.Default()
}
return &Handler{ return &Handler{
db: querier, db: querier,
blobs: blobs, blobs: blobs,
policy: pol, policy: pol,
auditFn: auditFn, auditFn: auditFn,
uploads: newUploadManager(), uploads: newUploadManager(),
log: logger.With("component", "oci"),
} }
} }

View File

@@ -59,6 +59,7 @@ func (h *Handler) resolveManifest(w http.ResponseWriter, repo, reference string)
fmt.Sprintf("repository %q not found", repo)) fmt.Sprintf("repository %q not found", repo))
return nil, false return nil, false
} }
h.log.Error("manifest resolve: lookup repository", "error", err, "repo", repo)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return nil, false return nil, false
} }
@@ -75,6 +76,7 @@ func (h *Handler) resolveManifest(w http.ResponseWriter, repo, reference string)
fmt.Sprintf("manifest %q not found", reference)) fmt.Sprintf("manifest %q not found", reference))
return nil, false return nil, false
} }
h.log.Error("manifest resolve: lookup manifest", "error", err, "repo", repo, "reference", reference)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return nil, false return nil, false
} }
@@ -175,6 +177,7 @@ func (h *Handler) handleManifestPut(w http.ResponseWriter, r *http.Request, repo
for _, bd := range blobDigests { for _, bd := range blobDigests {
exists, err := h.db.BlobExists(bd) exists, err := h.db.BlobExists(bd)
if err != nil { 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") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
@@ -197,6 +200,7 @@ func (h *Handler) handleManifestPut(w http.ResponseWriter, r *http.Request, repo
BlobDigests: blobDigests, BlobDigests: blobDigests,
} }
if err := h.db.PushManifest(params); err != nil { 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") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return 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.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("Location", fmt.Sprintf("/v2/%s/manifests/%s", repo, computedDigest))
w.Header().Set("Docker-Content-Digest", computedDigest) w.Header().Set("Docker-Content-Digest", computedDigest)
w.Header().Set("Content-Type", mediaType) w.Header().Set("Content-Type", mediaType)

View File

@@ -13,7 +13,7 @@ func TestManifestGetByTag(t *testing.T) {
content := []byte(`{"schemaVersion":2}`) content := []byte(`{"schemaVersion":2}`)
fdb.addManifest(1, "latest", "sha256:aaaa", "application/vnd.oci.image.manifest.v1+json", content) 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) router := testRouter(h)
req := authedRequest("GET", "/v2/myrepo/manifests/latest", nil) req := authedRequest("GET", "/v2/myrepo/manifests/latest", nil)
@@ -43,7 +43,7 @@ func TestManifestGetByDigest(t *testing.T) {
content := []byte(`{"schemaVersion":2}`) content := []byte(`{"schemaVersion":2}`)
fdb.addManifest(1, "latest", "sha256:aaaa", "application/vnd.oci.image.manifest.v1+json", content) 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) router := testRouter(h)
req := authedRequest("GET", "/v2/myrepo/manifests/sha256:aaaa", nil) req := authedRequest("GET", "/v2/myrepo/manifests/sha256:aaaa", nil)
@@ -67,7 +67,7 @@ func TestManifestHead(t *testing.T) {
content := []byte(`{"schemaVersion":2}`) content := []byte(`{"schemaVersion":2}`)
fdb.addManifest(1, "latest", "sha256:aaaa", "application/vnd.oci.image.manifest.v1+json", content) 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) router := testRouter(h)
req := authedRequest("HEAD", "/v2/myrepo/manifests/latest", nil) req := authedRequest("HEAD", "/v2/myrepo/manifests/latest", nil)
@@ -95,7 +95,7 @@ func TestManifestGetRepoNotFound(t *testing.T) {
fdb := newFakeDB() fdb := newFakeDB()
// No repos added. // No repos added.
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("GET", "/v2/nosuchrepo/manifests/latest", nil) req := authedRequest("GET", "/v2/nosuchrepo/manifests/latest", nil)
@@ -120,7 +120,7 @@ func TestManifestGetManifestNotFoundByTag(t *testing.T) {
fdb.addRepo("myrepo", 1) fdb.addRepo("myrepo", 1)
// No manifests added. // No manifests added.
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("GET", "/v2/myrepo/manifests/nonexistent", nil) req := authedRequest("GET", "/v2/myrepo/manifests/nonexistent", nil)
@@ -145,7 +145,7 @@ func TestManifestGetManifestNotFoundByDigest(t *testing.T) {
fdb.addRepo("myrepo", 1) fdb.addRepo("myrepo", 1)
// No manifests added. // No manifests added.
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("GET", "/v2/myrepo/manifests/sha256:nonexistent", nil) req := authedRequest("GET", "/v2/myrepo/manifests/sha256:nonexistent", nil)
@@ -171,7 +171,7 @@ func TestManifestGetMultiSegmentRepo(t *testing.T) {
content := []byte(`{"layers":[]}`) content := []byte(`{"layers":[]}`)
fdb.addManifest(1, "v1.0", "sha256:cccc", "application/vnd.oci.image.manifest.v1+json", content) 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) router := testRouter(h)
req := authedRequest("GET", "/v2/org/team/app/manifests/v1.0", nil) req := authedRequest("GET", "/v2/org/team/app/manifests/v1.0", nil)

View File

@@ -32,7 +32,7 @@ func TestManifestPushByTag(t *testing.T) {
fdb.addGlobalBlob("sha256:config1") fdb.addGlobalBlob("sha256:config1")
fdb.addGlobalBlob("sha256:layer1") fdb.addGlobalBlob("sha256:layer1")
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
content := makeManifest("sha256:config1", []string{"sha256:layer1"}) content := makeManifest("sha256:config1", []string{"sha256:layer1"})
@@ -79,7 +79,7 @@ func TestManifestPushByDigest(t *testing.T) {
fdb.addRepo("myrepo", 1) fdb.addRepo("myrepo", 1)
fdb.addGlobalBlob("sha256:config1") fdb.addGlobalBlob("sha256:config1")
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
content := makeManifest("sha256:config1", nil) content := makeManifest("sha256:config1", nil)
@@ -107,7 +107,7 @@ func TestManifestPushDigestMismatch(t *testing.T) {
fdb := newFakeDB() fdb := newFakeDB()
fdb.addRepo("myrepo", 1) fdb.addRepo("myrepo", 1)
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
content := []byte(`{"schemaVersion":2}`) content := []byte(`{"schemaVersion":2}`)
@@ -137,7 +137,7 @@ func TestManifestPushMissingBlob(t *testing.T) {
// Config blob exists but layer blob does not. // Config blob exists but layer blob does not.
fdb.addGlobalBlob("sha256:config1") fdb.addGlobalBlob("sha256:config1")
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
content := makeManifest("sha256:config1", []string{"sha256:missing_layer"}) content := makeManifest("sha256:config1", []string{"sha256:missing_layer"})
@@ -164,7 +164,7 @@ func TestManifestPushMalformed(t *testing.T) {
fdb := newFakeDB() fdb := newFakeDB()
fdb.addRepo("myrepo", 1) fdb.addRepo("myrepo", 1)
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedPushRequest("PUT", "/v2/myrepo/manifests/latest", []byte("not valid json")) req := authedPushRequest("PUT", "/v2/myrepo/manifests/latest", []byte("not valid json"))
@@ -189,7 +189,7 @@ func TestManifestPushEmpty(t *testing.T) {
fdb := newFakeDB() fdb := newFakeDB()
fdb.addRepo("myrepo", 1) fdb.addRepo("myrepo", 1)
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedPushRequest("PUT", "/v2/myrepo/manifests/latest", nil) req := authedPushRequest("PUT", "/v2/myrepo/manifests/latest", nil)
@@ -207,7 +207,7 @@ func TestManifestPushUpdatesTag(t *testing.T) {
fdb.addRepo("myrepo", 1) fdb.addRepo("myrepo", 1)
fdb.addGlobalBlob("sha256:config1") fdb.addGlobalBlob("sha256:config1")
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
// First push with tag "latest". // First push with tag "latest".
@@ -248,7 +248,7 @@ func TestManifestPushRepushIdempotent(t *testing.T) {
fdb.addRepo("myrepo", 1) fdb.addRepo("myrepo", 1)
fdb.addGlobalBlob("sha256:config1") fdb.addGlobalBlob("sha256:config1")
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
content := makeManifest("sha256:config1", nil) content := makeManifest("sha256:config1", nil)

View File

@@ -28,6 +28,7 @@ func (h *Handler) handleTagsList(w http.ResponseWriter, r *http.Request, repo st
fmt.Sprintf("repository %q not found", repo)) fmt.Sprintf("repository %q not found", repo))
return return
} }
h.log.Error("tags list: lookup repository", "error", err, "repo", repo)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
@@ -47,6 +48,7 @@ func (h *Handler) handleTagsList(w http.ResponseWriter, r *http.Request, repo st
if n == 0 { if n == 0 {
tags, err := h.db.ListTags(repoID, last, 10000) tags, err := h.db.ListTags(repoID, last, 10000)
if err != nil { if err != nil {
h.log.Error("tags list: list tags", "error", err, "repo", repo)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return 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. // Request n+1 to detect if there are more results.
tags, err := h.db.ListTags(repoID, last, n+1) tags, err := h.db.ListTags(repoID, last, n+1)
if err != nil { if err != nil {
h.log.Error("tags list: list tags (paginated)", "error", err, "repo", repo)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }

View File

@@ -14,7 +14,7 @@ func TestTagsList(t *testing.T) {
fdb.addTag(1, "v1.0") fdb.addTag(1, "v1.0")
fdb.addTag(1, "v2.0") fdb.addTag(1, "v2.0")
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("GET", "/v2/myrepo/tags/list", nil) req := authedRequest("GET", "/v2/myrepo/tags/list", nil)
@@ -50,7 +50,7 @@ func TestTagsListPagination(t *testing.T) {
fdb.addTag(1, "beta") fdb.addTag(1, "beta")
fdb.addTag(1, "gamma") fdb.addTag(1, "gamma")
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
// First page: n=2. // First page: n=2.
@@ -109,7 +109,7 @@ func TestTagsListEmpty(t *testing.T) {
fdb.addRepo("myrepo", 1) fdb.addRepo("myrepo", 1)
// No tags. // No tags.
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("GET", "/v2/myrepo/tags/list", nil) req := authedRequest("GET", "/v2/myrepo/tags/list", nil)
@@ -133,7 +133,7 @@ func TestTagsListRepoNotFound(t *testing.T) {
fdb := newFakeDB() fdb := newFakeDB()
// No repos. // No repos.
h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil) h := NewHandler(fdb, newFakeBlobs(), allowAll(), nil, nil)
router := testRouter(h) router := testRouter(h)
req := authedRequest("GET", "/v2/nosuchrepo/tags/list", nil) req := authedRequest("GET", "/v2/nosuchrepo/tags/list", nil)

View File

@@ -64,18 +64,21 @@ func (h *Handler) handleUploadInitiate(w http.ResponseWriter, r *http.Request, r
// Create repository if it doesn't exist (implicit creation). // Create repository if it doesn't exist (implicit creation).
repoID, err := h.db.GetOrCreateRepository(repo) repoID, err := h.db.GetOrCreateRepository(repo)
if err != nil { if err != nil {
h.log.Error("upload initiate: get or create repository", "error", err, "repo", repo)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
uuid, err := generateUUID() uuid, err := generateUUID()
if err != nil { if err != nil {
h.log.Error("upload initiate: generate uuid", "error", err, "repo", repo)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
// Insert upload row in DB. // Insert upload row in DB.
if err := h.db.CreateUpload(uuid, repoID); err != nil { 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") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
@@ -85,12 +88,15 @@ func (h *Handler) handleUploadInitiate(w http.ResponseWriter, r *http.Request, r
if err != nil { if err != nil {
// Clean up DB row on storage failure. // Clean up DB row on storage failure.
_ = h.db.DeleteUpload(uuid) _ = 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") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
h.uploads.set(uuid, bw) 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("Location", fmt.Sprintf("/v2/%s/blobs/uploads/%s", repo, uuid))
w.Header().Set("Docker-Upload-UUID", uuid) w.Header().Set("Docker-Upload-UUID", uuid)
w.Header().Set("Range", "0-0") 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. // Append request body to upload file.
n, err := io.Copy(bw, r.Body) n, err := io.Copy(bw, r.Body)
if err != nil { if err != nil {
h.log.Error("upload chunk: write to storage", "error", err, "repo", repo, "uuid", uuid)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "write failed") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "write failed")
return return
} }
@@ -119,6 +126,7 @@ func (h *Handler) handleUploadChunk(w http.ResponseWriter, r *http.Request, repo
// Update offset in DB. // Update offset in DB.
newOffset := bw.BytesWritten() newOffset := bw.BytesWritten()
if err := h.db.UpdateUploadOffset(uuid, newOffset); err != nil { 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") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return 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 request body is non-empty, append it first (monolithic upload).
if r.ContentLength != 0 { if r.ContentLength != 0 {
if _, err := io.Copy(bw, r.Body); err != nil { 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") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "write failed")
return 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") writeOCIError(w, "DIGEST_INVALID", http.StatusBadRequest, "invalid digest format")
return return
} }
h.log.Error("upload complete: commit blob", "error", err, "repo", repo, "uuid", uuid, "digest", digest)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "commit failed") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "commit failed")
return 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). // Insert blob row (no-op if already exists — content-addressed dedup).
if err := h.db.InsertBlob(digest, size); err != nil { 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") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }
@@ -189,6 +200,8 @@ func (h *Handler) handleUploadComplete(w http.ResponseWriter, r *http.Request, r
h.audit(r, "blob_uploaded", repo, digest) 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("Location", fmt.Sprintf("/v2/%s/blobs/%s", repo, digest))
w.Header().Set("Docker-Content-Digest", digest) w.Header().Set("Docker-Content-Digest", digest)
w.WriteHeader(http.StatusCreated) 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") writeOCIError(w, "BLOB_UPLOAD_UNKNOWN", http.StatusNotFound, "upload not found")
return return
} }
h.log.Error("upload status: lookup upload", "error", err, "repo", repo, "uuid", uuid)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return 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") writeOCIError(w, "BLOB_UPLOAD_UNKNOWN", http.StatusNotFound, "upload not found")
return return
} }
h.log.Error("upload cancel: delete upload from database", "error", err, "repo", repo, "uuid", uuid)
writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error") writeOCIError(w, "UNKNOWN", http.StatusInternalServerError, "internal error")
return return
} }

View File

@@ -21,7 +21,7 @@ func testHandlerWithStorage(t *testing.T, fdb *fakeDB) (*Handler, *chi.Mux) {
t.Helper() t.Helper()
dir := t.TempDir() dir := t.TempDir()
store := storage.New(dir+"/layers", dir+"/uploads") store := storage.New(dir+"/layers", dir+"/uploads")
h := NewHandler(fdb, store, allowAll(), nil) h := NewHandler(fdb, store, allowAll(), nil, nil)
router := chi.NewRouter() router := chi.NewRouter()
router.Mount("/v2", h.Router()) router.Mount("/v2", h.Router())
return h, router return h, router