From 8fbc1de08140fce66690fc7b498a9028a8458966 Mon Sep 17 00:00:00 2001 From: Aaron Lehmann Date: Mon, 27 Jul 2015 10:00:00 -0700 Subject: [PATCH 1/3] Use CloseNotifier to supress spurious HTTP 400 errors on early disconnect When a client disconnects without completing a HTTP request, we were attempting to process the partial request, which usually leads to a 400 error. These errors can pollute the logs and make it more difficult to track down real bugs. This change uses CloseNotifier to detect disconnects. In combination with checking Content-Length, we can detect a disconnect before sending the full payload, and avoid logging a 400 error. This logic is only applied to PUT, POST, and PATCH endpoints, as these are the places where disconnects during a request are most likely to happen. Signed-off-by: Aaron Lehmann --- docs/handlers/blobupload.go | 44 +++++++++++++++++++++++++++++++++++-- docs/handlers/images.go | 30 +++++++++++++++++++++++-- 2 files changed, 70 insertions(+), 4 deletions(-) diff --git a/docs/handlers/blobupload.go b/docs/handlers/blobupload.go index 8dc417ba..84bf26c5 100644 --- a/docs/handlers/blobupload.go +++ b/docs/handlers/blobupload.go @@ -170,8 +170,28 @@ func (buh *blobUploadHandler) PatchBlobData(w http.ResponseWriter, r *http.Reque // TODO(dmcgowan): support Content-Range header to seek and write range + // Get a channel that tells us if the client disconnects + var clientClosed <-chan bool + if notifier, ok := w.(http.CloseNotifier); ok { + clientClosed = notifier.CloseNotify() + } else { + panic("the ResponseWriter does not implement CloseNotifier") + } + // Copy the data - if _, err := io.Copy(buh.Upload, r.Body); err != nil { + copied, err := io.Copy(buh.Upload, r.Body) + if clientClosed != nil && (err != nil || (r.ContentLength > 0 && copied < r.ContentLength)) { + // Didn't recieve as much content as expected. Did the client + // disconnect during the request? If so, avoid returning a 400 + // error to keep the logs cleaner. + select { + case <-clientClosed: + ctxu.GetLogger(buh).Error("client disconnected during blob PATCH") + return + default: + } + } + if err != nil { ctxu.GetLogger(buh).Errorf("unknown error copying into upload: %v", err) buh.Errors = append(buh.Errors, errcode.ErrorCodeUnknown.WithDetail(err)) return @@ -211,8 +231,28 @@ func (buh *blobUploadHandler) PutBlobUploadComplete(w http.ResponseWriter, r *ht return } + // Get a channel that tells us if the client disconnects + var clientClosed <-chan bool + if notifier, ok := w.(http.CloseNotifier); ok { + clientClosed = notifier.CloseNotify() + } else { + panic("the ResponseWriter does not implement CloseNotifier") + } + // Read in the data, if any. - if _, err := io.Copy(buh.Upload, r.Body); err != nil { + copied, err := io.Copy(buh.Upload, r.Body) + if clientClosed != nil && (err != nil || (r.ContentLength > 0 && copied < r.ContentLength)) { + // Didn't recieve as much content as expected. Did the client + // disconnect during the request? If so, avoid returning a 400 + // error to keep the logs cleaner. + select { + case <-clientClosed: + ctxu.GetLogger(buh).Error("client disconnected during blob PUT") + return + default: + } + } + if err != nil { ctxu.GetLogger(buh).Errorf("unknown error copying into upload: %v", err) buh.Errors = append(buh.Errors, errcode.ErrorCodeUnknown.WithDetail(err)) return diff --git a/docs/handlers/images.go b/docs/handlers/images.go index 01f9b7a2..42b2ea48 100644 --- a/docs/handlers/images.go +++ b/docs/handlers/images.go @@ -3,6 +3,7 @@ package handlers import ( "encoding/json" "fmt" + "io/ioutil" "net/http" "strings" @@ -112,10 +113,35 @@ func (imh *imageManifestHandler) PutImageManifest(w http.ResponseWriter, r *http return } - dec := json.NewDecoder(r.Body) + // Get a channel that tells us if the client disconnects + var clientClosed <-chan bool + if notifier, ok := w.(http.CloseNotifier); ok { + clientClosed = notifier.CloseNotify() + } else { + panic("the ResponseWriter does not implement CloseNotifier") + } + + // Copy the data + jsonBytes, err := ioutil.ReadAll(r.Body) + if clientClosed != nil && (err != nil || (r.ContentLength > 0 && int64(len(jsonBytes)) < r.ContentLength)) { + // Didn't recieve as much content as expected. Did the client + // disconnect during the request? If so, avoid returning a 400 + // error to keep the logs cleaner. + select { + case <-clientClosed: + ctxu.GetLogger(imh).Error("client disconnected during image manifest PUT") + return + default: + } + } + if err != nil { + ctxu.GetLogger(imh).Errorf("unknown error reading payload: %v", err) + imh.Errors = append(imh.Errors, errcode.ErrorCodeUnknown.WithDetail(err)) + return + } var manifest manifest.SignedManifest - if err := dec.Decode(&manifest); err != nil { + if err := json.Unmarshal(jsonBytes, &manifest); err != nil { imh.Errors = append(imh.Errors, v2.ErrorCodeManifestInvalid.WithDetail(err)) return } From b0d133045d3bbdb45bafe8c1fc37a8d6682036b5 Mon Sep 17 00:00:00 2001 From: Aaron Lehmann Date: Wed, 29 Jul 2015 18:18:50 -0700 Subject: [PATCH 2/3] Factor CloseNotifier use into a new function Signed-off-by: Aaron Lehmann --- docs/handlers/blobupload.go | 53 +++---------------------------------- docs/handlers/helpers.go | 39 +++++++++++++++++++++++++++ docs/handlers/images.go | 31 ++++------------------ 3 files changed, 48 insertions(+), 75 deletions(-) diff --git a/docs/handlers/blobupload.go b/docs/handlers/blobupload.go index 84bf26c5..1d1c1009 100644 --- a/docs/handlers/blobupload.go +++ b/docs/handlers/blobupload.go @@ -2,7 +2,6 @@ package handlers import ( "fmt" - "io" "net/http" "net/url" "os" @@ -170,30 +169,8 @@ func (buh *blobUploadHandler) PatchBlobData(w http.ResponseWriter, r *http.Reque // TODO(dmcgowan): support Content-Range header to seek and write range - // Get a channel that tells us if the client disconnects - var clientClosed <-chan bool - if notifier, ok := w.(http.CloseNotifier); ok { - clientClosed = notifier.CloseNotify() - } else { - panic("the ResponseWriter does not implement CloseNotifier") - } - - // Copy the data - copied, err := io.Copy(buh.Upload, r.Body) - if clientClosed != nil && (err != nil || (r.ContentLength > 0 && copied < r.ContentLength)) { - // Didn't recieve as much content as expected. Did the client - // disconnect during the request? If so, avoid returning a 400 - // error to keep the logs cleaner. - select { - case <-clientClosed: - ctxu.GetLogger(buh).Error("client disconnected during blob PATCH") - return - default: - } - } - if err != nil { - ctxu.GetLogger(buh).Errorf("unknown error copying into upload: %v", err) - buh.Errors = append(buh.Errors, errcode.ErrorCodeUnknown.WithDetail(err)) + if err := copyFullPayload(w, r, buh.Upload, buh, "blob PATCH", &buh.Errors); err != nil { + // copyFullPayload reports the error if necessary return } @@ -231,30 +208,8 @@ func (buh *blobUploadHandler) PutBlobUploadComplete(w http.ResponseWriter, r *ht return } - // Get a channel that tells us if the client disconnects - var clientClosed <-chan bool - if notifier, ok := w.(http.CloseNotifier); ok { - clientClosed = notifier.CloseNotify() - } else { - panic("the ResponseWriter does not implement CloseNotifier") - } - - // Read in the data, if any. - copied, err := io.Copy(buh.Upload, r.Body) - if clientClosed != nil && (err != nil || (r.ContentLength > 0 && copied < r.ContentLength)) { - // Didn't recieve as much content as expected. Did the client - // disconnect during the request? If so, avoid returning a 400 - // error to keep the logs cleaner. - select { - case <-clientClosed: - ctxu.GetLogger(buh).Error("client disconnected during blob PUT") - return - default: - } - } - if err != nil { - ctxu.GetLogger(buh).Errorf("unknown error copying into upload: %v", err) - buh.Errors = append(buh.Errors, errcode.ErrorCodeUnknown.WithDetail(err)) + if err := copyFullPayload(w, r, buh.Upload, buh, "blob PUT", &buh.Errors); err != nil { + // copyFullPayload reports the error if necessary return } diff --git a/docs/handlers/helpers.go b/docs/handlers/helpers.go index e2d220c2..abbcb1be 100644 --- a/docs/handlers/helpers.go +++ b/docs/handlers/helpers.go @@ -1,8 +1,12 @@ package handlers import ( + "errors" "io" "net/http" + + ctxu "github.com/docker/distribution/context" + "github.com/docker/distribution/registry/api/errcode" ) // closeResources closes all the provided resources after running the target @@ -15,3 +19,38 @@ func closeResources(handler http.Handler, closers ...io.Closer) http.Handler { handler.ServeHTTP(w, r) }) } + +// copyFullPayload copies the payload of a HTTP request to destWriter. If it +// receives less content than expected, and the client disconnected during the +// upload, it avoids sending a 400 error to keep the logs cleaner. +func copyFullPayload(responseWriter http.ResponseWriter, r *http.Request, destWriter io.Writer, context ctxu.Context, action string, errSlice *errcode.Errors) error { + // Get a channel that tells us if the client disconnects + var clientClosed <-chan bool + if notifier, ok := responseWriter.(http.CloseNotifier); ok { + clientClosed = notifier.CloseNotify() + } else { + panic("the ResponseWriter does not implement CloseNotifier") + } + + // Read in the data, if any. + copied, err := io.Copy(destWriter, r.Body) + if clientClosed != nil && (err != nil || (r.ContentLength > 0 && copied < r.ContentLength)) { + // Didn't recieve as much content as expected. Did the client + // disconnect during the request? If so, avoid returning a 400 + // error to keep the logs cleaner. + select { + case <-clientClosed: + ctxu.GetLogger(context).Error("client disconnected during " + action) + return errors.New("client disconnected") + default: + } + } + + if err != nil { + ctxu.GetLogger(context).Errorf("unknown error reading request payload: %v", err) + *errSlice = append(*errSlice, errcode.ErrorCodeUnknown.WithDetail(err)) + return err + } + + return nil +} diff --git a/docs/handlers/images.go b/docs/handlers/images.go index 42b2ea48..dbe7b706 100644 --- a/docs/handlers/images.go +++ b/docs/handlers/images.go @@ -1,9 +1,9 @@ package handlers import ( + "bytes" "encoding/json" "fmt" - "io/ioutil" "net/http" "strings" @@ -113,35 +113,14 @@ func (imh *imageManifestHandler) PutImageManifest(w http.ResponseWriter, r *http return } - // Get a channel that tells us if the client disconnects - var clientClosed <-chan bool - if notifier, ok := w.(http.CloseNotifier); ok { - clientClosed = notifier.CloseNotify() - } else { - panic("the ResponseWriter does not implement CloseNotifier") - } - - // Copy the data - jsonBytes, err := ioutil.ReadAll(r.Body) - if clientClosed != nil && (err != nil || (r.ContentLength > 0 && int64(len(jsonBytes)) < r.ContentLength)) { - // Didn't recieve as much content as expected. Did the client - // disconnect during the request? If so, avoid returning a 400 - // error to keep the logs cleaner. - select { - case <-clientClosed: - ctxu.GetLogger(imh).Error("client disconnected during image manifest PUT") - return - default: - } - } - if err != nil { - ctxu.GetLogger(imh).Errorf("unknown error reading payload: %v", err) - imh.Errors = append(imh.Errors, errcode.ErrorCodeUnknown.WithDetail(err)) + var jsonBuf bytes.Buffer + if err := copyFullPayload(w, r, &jsonBuf, imh, "image manifest PUT", &imh.Errors); err != nil { + // copyFullPayload reports the error if necessary return } var manifest manifest.SignedManifest - if err := json.Unmarshal(jsonBytes, &manifest); err != nil { + if err := json.Unmarshal(jsonBuf.Bytes(), &manifest); err != nil { imh.Errors = append(imh.Errors, v2.ErrorCodeManifestInvalid.WithDetail(err)) return } From b51913f6198ccacdc408c0d2af583f15f2889820 Mon Sep 17 00:00:00 2001 From: Aaron Lehmann Date: Fri, 31 Jul 2015 17:39:30 -0700 Subject: [PATCH 3/3] Set the response code to 499 when a client disconnects during an upload The response code isn't actually sent to the client, because the connection has already closed by this point. But it causes the status code to appear as 499 in the logs instead of 0. Signed-off-by: Aaron Lehmann --- docs/handlers/helpers.go | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/docs/handlers/helpers.go b/docs/handlers/helpers.go index abbcb1be..1f9a8ee1 100644 --- a/docs/handlers/helpers.go +++ b/docs/handlers/helpers.go @@ -40,6 +40,12 @@ func copyFullPayload(responseWriter http.ResponseWriter, r *http.Request, destWr // error to keep the logs cleaner. select { case <-clientClosed: + // Set the response code to "499 Client Closed Request" + // Even though the connection has already been closed, + // this causes the logger to pick up a 499 error + // instead of showing 0 for the HTTP status. + responseWriter.WriteHeader(499) + ctxu.GetLogger(context).Error("client disconnected during " + action) return errors.New("client disconnected") default: