From 097fce3bb24d73a0c82225ebf43bb5f644453341 Mon Sep 17 00:00:00 2001 From: Stephen J Day Date: Thu, 29 Jan 2015 21:26:35 -0800 Subject: [PATCH] Address server errors received during layer upload This changeset addresses intermittent internal server errors encountered during pushes. The root cause has been isolated to layers that result in identical, empty filesystems but may have some path declarations (imaginge "./"), resulting in different tarsums. The main error message reported during these upload problems was a 500 error, which was not correct. Further investigation showed the errors to be rooted in digest verification when finishing uploads. Inspection of the surrounding code also identified a few issues. PutLayerChunk was slightly refactered into PutLayerUploadComplete. Helper methods were avoided to make handler less confusing. This simplification leveraged an earlier change in the spec that moved non-complete chunk uploads to the PATCH method. Simple logging was also added in the unknown error case that should help to avoid mysterious 500 errors in the future. At the same time, the glaring omission of a proper layer upload cancel method was rectified. This has been added in this change so it is not missed in the future. In the future, we may want to refactor the handler code to be more straightforward, hopefully letting us avoid these problems in the future. Added test cases that reproduce these errors and drove these changes include the following: 1. Push a layer with an empty body results in invalid blob upload. 2. Push a layer with a different tarsum (in this case, empty tar) 3. Deleting a layer upload works. 4. Getting status on a deleted layer upload returns 404. Common functionality was grouped into shared functions to remove repitition. The API tests will still require future love. Signed-off-by: Stephen J Day --- registry/api_test.go | 208 ++++++++++++++++++++++------------------ registry/layerupload.go | 169 ++++++++++++++++---------------- 2 files changed, 198 insertions(+), 179 deletions(-) diff --git a/registry/api_test.go b/registry/api_test.go index b0f3bb2b..68254920 100644 --- a/registry/api_test.go +++ b/registry/api_test.go @@ -11,6 +11,7 @@ import ( "net/http/httputil" "net/url" "os" + "reflect" "testing" "github.com/docker/distribution/api/v2" @@ -120,29 +121,59 @@ func TestLayerAPI(t *testing.T) { checkResponse(t, "checking head on non-existent layer", resp, http.StatusNotFound) // ------------------------------------------ - // Upload a layer - layerUploadURL, err := builder.BuildBlobUploadURL(imageName) + // Start an upload and cancel + uploadURLBase := startPushLayer(t, builder, imageName) + + req, err := http.NewRequest("DELETE", uploadURLBase, nil) if err != nil { - t.Fatalf("error building upload url: %v", err) + t.Fatalf("unexpected error creating delete request: %v", err) } - resp, err = http.Post(layerUploadURL, "", nil) + resp, err = http.DefaultClient.Do(req) if err != nil { - t.Fatalf("error starting layer upload: %v", err) + t.Fatalf("unexpected error sending delete request: %v", err) } - checkResponse(t, "starting layer upload", resp, http.StatusAccepted) - checkHeaders(t, resp, http.Header{ - "Location": []string{"*"}, - "Content-Length": []string{"0"}, - }) + checkResponse(t, "deleting upload", resp, http.StatusNoContent) + // A status check should result in 404 + resp, err = http.Get(uploadURLBase) + if err != nil { + t.Fatalf("unexpected error getting upload status: %v", err) + } + checkResponse(t, "status of deleted upload", resp, http.StatusNotFound) + + // ----------------------------------------- + // Do layer push with an empty body + uploadURLBase = startPushLayer(t, builder, imageName) + resp, err = doPushLayer(t, builder, imageName, layerDigest, uploadURLBase, bytes.NewReader([]byte{})) + if err != nil { + t.Fatalf("unexpected error doing bad layer push: %v", err) + } + + checkResponse(t, "bad layer push", resp, http.StatusBadRequest) + checkBodyHasErrorCodes(t, "bad layer push", resp, v2.ErrorCodeBlobUploadInvalid) + + // ----------------------------------------- + // Do layer push with an invalid body + + // This is a valid but empty tarfile! + badTar := bytes.Repeat([]byte("\x00"), 1024) + uploadURLBase = startPushLayer(t, builder, imageName) + resp, err = doPushLayer(t, builder, imageName, layerDigest, uploadURLBase, bytes.NewReader(badTar)) + if err != nil { + t.Fatalf("unexpected error doing bad layer push: %v", err) + } + + checkResponse(t, "bad layer push", resp, http.StatusBadRequest) + checkBodyHasErrorCodes(t, "bad layer push", resp, v2.ErrorCodeDigestInvalid) + + // ------------------------------------------ + // Now, actually do successful upload. layerLength, _ := layerFile.Seek(0, os.SEEK_END) layerFile.Seek(0, os.SEEK_SET) - // TODO(sday): Cancel the layer upload here and restart. - - uploadURLBase := startPushLayer(t, builder, imageName) + uploadURLBase = startPushLayer(t, builder, imageName) pushLayer(t, builder, imageName, layerDigest, uploadURLBase, layerFile) // ------------------------ @@ -218,27 +249,7 @@ func TestManifestAPI(t *testing.T) { defer resp.Body.Close() checkResponse(t, "getting non-existent manifest", resp, http.StatusNotFound) - - // TODO(stevvooe): Shoot. The error setup is not working out. The content- - // type headers are being set after writing the status code. - // if resp.Header.Get("Content-Type") != "application/json; charset=utf-8" { - // t.Fatalf("unexpected content type: %v != 'application/json'", - // resp.Header.Get("Content-Type")) - // } - dec := json.NewDecoder(resp.Body) - - var respErrs v2.Errors - if err := dec.Decode(&respErrs); err != nil { - t.Fatalf("unexpected error decoding error response: %v", err) - } - - if len(respErrs.Errors) == 0 { - t.Fatalf("expected errors in response") - } - - if respErrs.Errors[0].Code != v2.ErrorCodeManifestUnknown { - t.Fatalf("expected manifest unknown error: got %v", respErrs) - } + checkBodyHasErrorCodes(t, "getting non-existent manifest", resp, v2.ErrorCodeManifestUnknown) tagsURL, err := builder.BuildTagsURL(imageName) if err != nil { @@ -253,18 +264,7 @@ func TestManifestAPI(t *testing.T) { // Check that we get an unknown repository error when asking for tags checkResponse(t, "getting unknown manifest tags", resp, http.StatusNotFound) - dec = json.NewDecoder(resp.Body) - if err := dec.Decode(&respErrs); err != nil { - t.Fatalf("unexpected error decoding error response: %v", err) - } - - if len(respErrs.Errors) == 0 { - t.Fatalf("expected errors in response") - } - - if respErrs.Errors[0].Code != v2.ErrorCodeNameUnknown { - t.Fatalf("expected respository unknown error: got %v", respErrs) - } + checkBodyHasErrorCodes(t, "getting unknown manifest tags", resp, v2.ErrorCodeNameUnknown) // -------------------------------- // Attempt to push unsigned manifest with missing layers @@ -284,41 +284,17 @@ func TestManifestAPI(t *testing.T) { resp = putManifest(t, "putting unsigned manifest", manifestURL, unsignedManifest) defer resp.Body.Close() checkResponse(t, "posting unsigned manifest", resp, http.StatusBadRequest) + _, p, counts := checkBodyHasErrorCodes(t, "getting unknown manifest tags", resp, + v2.ErrorCodeManifestUnverified, v2.ErrorCodeBlobUnknown, v2.ErrorCodeDigestInvalid) - dec = json.NewDecoder(resp.Body) - if err := dec.Decode(&respErrs); err != nil { - t.Fatalf("unexpected error decoding error response: %v", err) + expectedCounts := map[v2.ErrorCode]int{ + v2.ErrorCodeManifestUnverified: 1, + v2.ErrorCodeBlobUnknown: 2, + v2.ErrorCodeDigestInvalid: 2, } - var unverified int - var missingLayers int - var invalidDigests int - - for _, err := range respErrs.Errors { - switch err.Code { - case v2.ErrorCodeManifestUnverified: - unverified++ - case v2.ErrorCodeBlobUnknown: - missingLayers++ - case v2.ErrorCodeDigestInvalid: - // TODO(stevvooe): This error isn't quite descriptive enough -- - // the layer with an invalid digest isn't identified. - invalidDigests++ - default: - t.Fatalf("unexpected error: %v", err) - } - } - - if unverified != 1 { - t.Fatalf("should have received one unverified manifest error: %v", respErrs) - } - - if missingLayers != 2 { - t.Fatalf("should have received two missing layer errors: %v", respErrs) - } - - if invalidDigests != 2 { - t.Fatalf("should have received two invalid digest errors: %v", respErrs) + if !reflect.DeepEqual(counts, expectedCounts) { + t.Fatalf("unexpected number of error codes encountered: %v\n!=\n%v\n---\n%s", counts, expectedCounts, string(p)) } // TODO(stevvooe): Add a test case where we take a mostly valid registry, @@ -363,7 +339,7 @@ func TestManifestAPI(t *testing.T) { checkResponse(t, "fetching uploaded manifest", resp, http.StatusOK) var fetchedManifest manifest.SignedManifest - dec = json.NewDecoder(resp.Body) + dec := json.NewDecoder(resp.Body) if err := dec.Decode(&fetchedManifest); err != nil { t.Fatalf("error decoding fetched manifest: %v", err) } @@ -448,11 +424,9 @@ func startPushLayer(t *testing.T, ub *v2.URLBuilder, name string) string { return resp.Header.Get("Location") } -// pushLayer pushes the layer content returning the url on success. -func pushLayer(t *testing.T, ub *v2.URLBuilder, name string, dgst digest.Digest, uploadURLBase string, rs io.ReadSeeker) string { - rsLength, _ := rs.Seek(0, os.SEEK_END) - rs.Seek(0, os.SEEK_SET) - +// doPushLayer pushes the layer content returning the url on success returning +// the response. If you're only expecting a successful response, use pushLayer. +func doPushLayer(t *testing.T, ub *v2.URLBuilder, name string, dgst digest.Digest, uploadURLBase string, body io.Reader) (*http.Response, error) { u, err := url.Parse(uploadURLBase) if err != nil { t.Fatalf("unexpected error parsing pushLayer url: %v", err) @@ -462,23 +436,24 @@ func pushLayer(t *testing.T, ub *v2.URLBuilder, name string, dgst digest.Digest, "_state": u.Query()["_state"], "digest": []string{dgst.String()}, - - // TODO(stevvooe): Layer upload can be completed with and without size - // argument. We'll need to add a test that checks the latter path. - "size": []string{fmt.Sprint(rsLength)}, }.Encode() uploadURL := u.String() // Just do a monolithic upload - req, err := http.NewRequest("PUT", uploadURL, rs) + req, err := http.NewRequest("PUT", uploadURL, body) if err != nil { t.Fatalf("unexpected error creating new request: %v", err) } - resp, err := http.DefaultClient.Do(req) + return http.DefaultClient.Do(req) +} + +// pushLayer pushes the layer content returning the url on success. +func pushLayer(t *testing.T, ub *v2.URLBuilder, name string, dgst digest.Digest, uploadURLBase string, body io.Reader) string { + resp, err := doPushLayer(t, ub, name, dgst, uploadURLBase, body) if err != nil { - t.Fatalf("unexpected error doing put: %v", err) + t.Fatalf("unexpected error doing push layer request: %v", err) } defer resp.Body.Close() @@ -506,6 +481,57 @@ func checkResponse(t *testing.T, msg string, resp *http.Response, expectedStatus } } +// checkBodyHasErrorCodes ensures the body is an error body and has the +// expected error codes, returning the error structure, the json slice and a +// count of the errors by code. +func checkBodyHasErrorCodes(t *testing.T, msg string, resp *http.Response, errorCodes ...v2.ErrorCode) (v2.Errors, []byte, map[v2.ErrorCode]int) { + p, err := ioutil.ReadAll(resp.Body) + if err != nil { + t.Fatalf("unexpected error reading body %s: %v", msg, err) + } + + var errs v2.Errors + if err := json.Unmarshal(p, &errs); err != nil { + t.Fatalf("unexpected error decoding error response: %v", err) + } + + if len(errs.Errors) == 0 { + t.Fatalf("expected errors in response") + } + + // TODO(stevvooe): Shoot. The error setup is not working out. The content- + // type headers are being set after writing the status code. + // if resp.Header.Get("Content-Type") != "application/json; charset=utf-8" { + // t.Fatalf("unexpected content type: %v != 'application/json'", + // resp.Header.Get("Content-Type")) + // } + + expected := map[v2.ErrorCode]struct{}{} + counts := map[v2.ErrorCode]int{} + + // Initialize map with zeros for expected + for _, code := range errorCodes { + expected[code] = struct{}{} + counts[code] = 0 + } + + for _, err := range errs.Errors { + if _, ok := expected[err.Code]; !ok { + t.Fatalf("unexpected error code %v encountered: %s ", err.Code, string(p)) + } + counts[err.Code]++ + } + + // Ensure that counts of expected errors were all non-zero + for code := range expected { + if counts[code] == 0 { + t.Fatalf("expected error code %v not encounterd: %s", code, string(p)) + } + } + + return errs, p, counts +} + func maybeDumpResponse(t *testing.T, resp *http.Response) { if d, err := httputil.DumpResponse(resp, true); err != nil { t.Logf("error dumping response: %v", err) diff --git a/registry/layerupload.go b/registry/layerupload.go index 5cd445a5..e9585b0e 100644 --- a/registry/layerupload.go +++ b/registry/layerupload.go @@ -23,10 +23,12 @@ func layerUploadDispatcher(ctx *Context, r *http.Request) http.Handler { } handler := http.Handler(handlers.MethodHandler{ - "POST": http.HandlerFunc(luh.StartLayerUpload), - "GET": http.HandlerFunc(luh.GetUploadStatus), - "HEAD": http.HandlerFunc(luh.GetUploadStatus), - "PUT": http.HandlerFunc(luh.PutLayerChunk), + "POST": http.HandlerFunc(luh.StartLayerUpload), + "GET": http.HandlerFunc(luh.GetUploadStatus), + "HEAD": http.HandlerFunc(luh.GetUploadStatus), + // TODO(stevvooe): Must implement patch support. + // "PATCH": http.HandlerFunc(luh.PutLayerChunk), + "PUT": http.HandlerFunc(luh.PutLayerUploadComplete), "DELETE": http.HandlerFunc(luh.CancelLayerUpload), }) @@ -158,55 +160,80 @@ func (luh *layerUploadHandler) GetUploadStatus(w http.ResponseWriter, r *http.Re w.WriteHeader(http.StatusNoContent) } -// PutLayerChunk receives a layer chunk during the layer upload process, -// possible completing the upload with a checksum and length. -func (luh *layerUploadHandler) PutLayerChunk(w http.ResponseWriter, r *http.Request) { +// PutLayerUploadComplete takes the final request of a layer upload. The final +// chunk may include all the layer data, the final chunk of layer data or no +// layer data. Any data provided is received and verified. If successful, the +// layer is linked into the blob store and 201 Created is returned with the +// canonical url of the layer. +func (luh *layerUploadHandler) PutLayerUploadComplete(w http.ResponseWriter, r *http.Request) { if luh.Upload == nil { w.WriteHeader(http.StatusNotFound) luh.Errors.Push(v2.ErrorCodeBlobUploadUnknown) - } - - var finished bool - - // TODO(stevvooe): This is woefully incomplete. Missing stuff: - // - // 1. Extract information from range header, if present. - // 2. Check offset of current layer. - // 3. Emit correct error responses. - - // Read in the chunk - io.Copy(luh.Upload, r.Body) - - if err := luh.maybeCompleteUpload(w, r); err != nil { - if err != errNotReadyToComplete { - switch err := err.(type) { - case storage.ErrLayerInvalidSize: - w.WriteHeader(http.StatusBadRequest) - luh.Errors.Push(v2.ErrorCodeSizeInvalid, err) - return - case storage.ErrLayerInvalidDigest: - w.WriteHeader(http.StatusBadRequest) - luh.Errors.Push(v2.ErrorCodeDigestInvalid, err) - return - default: - w.WriteHeader(http.StatusInternalServerError) - luh.Errors.Push(v2.ErrorCodeUnknown, err) - return - } - } - } - - if err := luh.layerUploadResponse(w, r); err != nil { - w.WriteHeader(http.StatusInternalServerError) // Error conditions here? - luh.Errors.Push(v2.ErrorCodeUnknown, err) return } - if finished { - w.WriteHeader(http.StatusCreated) - } else { - w.WriteHeader(http.StatusAccepted) + dgstStr := r.FormValue("digest") // TODO(stevvooe): Support multiple digest parameters! + + if dgstStr == "" { + // no digest? return error, but allow retry. + w.WriteHeader(http.StatusNotFound) + luh.Errors.Push(v2.ErrorCodeDigestInvalid, "digest missing") + return } + + dgst, err := digest.ParseDigest(dgstStr) + if err != nil { + // no digest? return error, but allow retry. + w.WriteHeader(http.StatusNotFound) + luh.Errors.Push(v2.ErrorCodeDigestInvalid, "digest parsing failed") + return + } + + // TODO(stevvooe): Check the incoming range header here, per the + // specification. LayerUpload should be seeked (sought?) to that position. + + // Read in the final chunk, if any. + io.Copy(luh.Upload, r.Body) + + layer, err := luh.Upload.Finish(dgst) + if err != nil { + switch err := err.(type) { + case storage.ErrLayerUploadUnavailable: + w.WriteHeader(http.StatusBadRequest) + // TODO(stevvooe): Arguably, we may want to add an error code to + // cover this condition. It is not always a client error but it + // may be. For now, we effectively throw out the upload and have + // them start over. + luh.Errors.Push(v2.ErrorCodeBlobUploadInvalid, err.Err) + case storage.ErrLayerInvalidDigest: + w.WriteHeader(http.StatusBadRequest) + luh.Errors.Push(v2.ErrorCodeDigestInvalid, err) + default: + luh.log.Errorf("unknown error completing upload: %#v", err) + w.WriteHeader(http.StatusInternalServerError) + luh.Errors.Push(v2.ErrorCodeUnknown, err) + } + + // Clean up the backend layer data if there was an error. + if err := luh.Upload.Cancel(); err != nil { + // If the cleanup fails, all we can do is observe and report. + luh.log.Errorf("error canceling upload after error: %v", err) + } + + return + } + + // Build our canonical layer url + layerURL, err := luh.urlBuilder.BuildBlobURL(layer.Name(), layer.Digest()) + if err != nil { + luh.Errors.Push(v2.ErrorCodeUnknown, err) + w.WriteHeader(http.StatusInternalServerError) + return + } + + w.Header().Set("Location", layerURL) + w.Header().Set("Content-Length", "0") + w.WriteHeader(http.StatusCreated) } // CancelLayerUpload cancels an in-progress upload of a layer. @@ -214,8 +241,16 @@ func (luh *layerUploadHandler) CancelLayerUpload(w http.ResponseWriter, r *http. if luh.Upload == nil { w.WriteHeader(http.StatusNotFound) luh.Errors.Push(v2.ErrorCodeBlobUploadUnknown) + return } + if err := luh.Upload.Cancel(); err != nil { + luh.log.Errorf("error encountered canceling upload: %v", err) + w.WriteHeader(http.StatusInternalServerError) + luh.Errors.PushErr(err) + } + + w.WriteHeader(http.StatusNoContent) } // layerUploadResponse provides a standard request for uploading layers and @@ -257,45 +292,3 @@ func (luh *layerUploadHandler) layerUploadResponse(w http.ResponseWriter, r *htt return nil } - -var errNotReadyToComplete = fmt.Errorf("not ready to complete upload") - -// maybeCompleteUpload tries to complete the upload if the correct parameters -// are available. Returns errNotReadyToComplete if not ready to complete. -func (luh *layerUploadHandler) maybeCompleteUpload(w http.ResponseWriter, r *http.Request) error { - // If we get a digest and length, we can finish the upload. - dgstStr := r.FormValue("digest") // TODO(stevvooe): Support multiple digest parameters! - - if dgstStr == "" { - return errNotReadyToComplete - } - - dgst, err := digest.ParseDigest(dgstStr) - if err != nil { - return err - } - - luh.completeUpload(w, r, dgst) - return nil -} - -// completeUpload finishes out the upload with the correct response. -func (luh *layerUploadHandler) completeUpload(w http.ResponseWriter, r *http.Request, dgst digest.Digest) { - layer, err := luh.Upload.Finish(dgst) - if err != nil { - luh.Errors.Push(v2.ErrorCodeUnknown, err) - w.WriteHeader(http.StatusInternalServerError) - return - } - - layerURL, err := luh.urlBuilder.BuildBlobURL(layer.Name(), layer.Digest()) - if err != nil { - luh.Errors.Push(v2.ErrorCodeUnknown, err) - w.WriteHeader(http.StatusInternalServerError) - return - } - - w.Header().Set("Location", layerURL) - w.Header().Set("Content-Length", "0") - w.WriteHeader(http.StatusCreated) -}