From 1788ae4870de784407df7ceabd47b7f3da5baaef Mon Sep 17 00:00:00 2001 From: Aaron Lehmann Date: Mon, 27 Jul 2015 10:07:11 -0700 Subject: [PATCH 1/4] Update github.com/gorilla/handlers dependency Support for exposing the CloseNotifier interface was just recently added to its logging handler wrappers. This is needed for #597. Signed-off-by: Aaron Lehmann --- Godeps/Godeps.json | 2 +- .../github.com/gorilla/handlers/.travis.yml | 2 +- .../src/github.com/gorilla/handlers/README.md | 52 ++++++++++++++++-- .../github.com/gorilla/handlers/compress.go | 17 ++++++ .../github.com/gorilla/handlers/handlers.go | 54 +++++++++++++------ 5 files changed, 106 insertions(+), 21 deletions(-) diff --git a/Godeps/Godeps.json b/Godeps/Godeps.json index 17428002..dc5ea6aa 100644 --- a/Godeps/Godeps.json +++ b/Godeps/Godeps.json @@ -67,7 +67,7 @@ }, { "ImportPath": "github.com/gorilla/handlers", - "Rev": "0e84b7d810c16aed432217e330206be156bafae0" + "Rev": "60c7bfde3e33c201519a200a4507a158cc03a17b" }, { "ImportPath": "github.com/gorilla/mux", diff --git a/Godeps/_workspace/src/github.com/gorilla/handlers/.travis.yml b/Godeps/_workspace/src/github.com/gorilla/handlers/.travis.yml index 825dc3f2..354b7f8b 100644 --- a/Godeps/_workspace/src/github.com/gorilla/handlers/.travis.yml +++ b/Godeps/_workspace/src/github.com/gorilla/handlers/.travis.yml @@ -1,8 +1,8 @@ language: go go: - - 1.0 - 1.1 - 1.2 - 1.3 + - 1.4 - tip diff --git a/Godeps/_workspace/src/github.com/gorilla/handlers/README.md b/Godeps/_workspace/src/github.com/gorilla/handlers/README.md index 9be93705..a340abe0 100644 --- a/Godeps/_workspace/src/github.com/gorilla/handlers/README.md +++ b/Godeps/_workspace/src/github.com/gorilla/handlers/README.md @@ -1,6 +1,52 @@ gorilla/handlers ================ -[![Build Status](https://travis-ci.org/gorilla/handlers.png?branch=master)](https://travis-ci.org/gorilla/handlers) +[![GoDoc](https://godoc.org/github.com/gorilla/handlers?status.svg)](https://godoc.org/github.com/gorilla/handlers) [![Build Status](https://travis-ci.org/gorilla/handlers.svg?branch=master)](https://travis-ci.org/gorilla/handlers) + +Package handlers is a collection of handlers (aka "HTTP middleware") for use +with Go's `net/http` package (or any framework supporting `http.Handler`), including: + +* `LoggingHandler` for logging HTTP requests in the Apache [Common Log + Format](http://httpd.apache.org/docs/2.2/logs.html#common). +* `CombinedLoggingHandler` for logging HTTP requests in the Apache [Combined Log + Format](http://httpd.apache.org/docs/2.2/logs.html#combined) commonly used by + both Apache and nginx. +* `CompressHandler` for gzipping responses. +* `ContentTypeHandler` for validating requests against a list of accepted + content types. +* `MethodHandler` for matching HTTP methods against handlers in a + `map[string]http.Handler` +* `ProxyHeaders` for populating `r.RemoteAddr` and `r.URL.Scheme` based on the + `X-Forwarded-For`, `X-Real-IP`, `X-Forwarded-Proto` and RFC7239 `Forwarded` + headers when running a Go server behind a HTTP reverse proxy. +* `CanonicalHost` for re-directing to the preferred host when handling multiple + domains (i.e. multiple CNAME aliases). + +Other handlers are documented [on the Gorilla +website](http://www.gorillatoolkit.org/pkg/handlers). + +## Example + +A simple example using `handlers.LoggingHandler` and `handlers.CompressHandler`: + +```go +import ( + "net/http" + "github.com/gorilla/handlers" +) + +func main() { + r := http.NewServeMux() + + // Only log requests to our admin dashboard to stdout + r.Handle("/admin", handlers.LoggingHandler(os.Stdout, http.HandlerFunc(ShowAdminDashboard))) + r.HandleFunc("/", ShowIndex) + + // Wrap our server with our gzip handler to gzip compress all responses. + http.ListenAndServe(":8000", handlers.CompressHandler(r)) +} +``` + +## License + +BSD licensed. See the included LICENSE file for details. -*Warning:* This package is a work in progress and the APIs are subject to change. -Consider this a v0 project. diff --git a/Godeps/_workspace/src/github.com/gorilla/handlers/compress.go b/Godeps/_workspace/src/github.com/gorilla/handlers/compress.go index 81202bbc..3d90e191 100644 --- a/Godeps/_workspace/src/github.com/gorilla/handlers/compress.go +++ b/Godeps/_workspace/src/github.com/gorilla/handlers/compress.go @@ -15,6 +15,7 @@ import ( type compressResponseWriter struct { io.Writer http.ResponseWriter + http.Hijacker } func (w *compressResponseWriter) Header() http.Header { @@ -30,6 +31,8 @@ func (w *compressResponseWriter) Write(b []byte) (int, error) { return w.Writer.Write(b) } +// CompressHandler gzip compresses HTTP responses for clients that support it +// via the 'Accept-Encoding' header. func CompressHandler(h http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { L: @@ -42,10 +45,17 @@ func CompressHandler(h http.Handler) http.Handler { gw := gzip.NewWriter(w) defer gw.Close() + h, hok := w.(http.Hijacker) + if !hok { /* w is not Hijacker... oh well... */ + h = nil + } + w = &compressResponseWriter{ Writer: gw, ResponseWriter: w, + Hijacker: h, } + break L case "deflate": w.Header().Set("Content-Encoding", "deflate") @@ -54,10 +64,17 @@ func CompressHandler(h http.Handler) http.Handler { fw, _ := flate.NewWriter(w, flate.DefaultCompression) defer fw.Close() + h, hok := w.(http.Hijacker) + if !hok { /* w is not Hijacker... oh well... */ + h = nil + } + w = &compressResponseWriter{ Writer: fw, ResponseWriter: w, + Hijacker: h, } + break L } } diff --git a/Godeps/_workspace/src/github.com/gorilla/handlers/handlers.go b/Godeps/_workspace/src/github.com/gorilla/handlers/handlers.go index 23a738da..c3c20e5b 100644 --- a/Godeps/_workspace/src/github.com/gorilla/handlers/handlers.go +++ b/Godeps/_workspace/src/github.com/gorilla/handlers/handlers.go @@ -2,9 +2,6 @@ // Use of this source code is governed by a BSD-style // license that can be found in the LICENSE file. -/* -Package handlers is a collection of handlers for use with Go's net/http package. -*/ package handlers import ( @@ -29,7 +26,7 @@ import ( // available methods. // // If the request's method doesn't match any of its keys the handler responds with -// a status of 406, Method not allowed and sets the Allow header to a comma-separated list +// a status of 405, Method not allowed and sets the Allow header to a comma-separated list // of available methods. type MethodHandler map[string]http.Handler @@ -65,12 +62,7 @@ type combinedLoggingHandler struct { func (h loggingHandler) ServeHTTP(w http.ResponseWriter, req *http.Request) { t := time.Now() - var logger loggingResponseWriter - if _, ok := w.(http.Hijacker); ok { - logger = &hijackLogger{responseLogger: responseLogger{w: w}} - } else { - logger = &responseLogger{w: w} - } + logger := makeLogger(w) url := *req.URL h.handler.ServeHTTP(logger, req) writeLog(h.writer, req, url, t, logger.Status(), logger.Size()) @@ -78,19 +70,31 @@ func (h loggingHandler) ServeHTTP(w http.ResponseWriter, req *http.Request) { func (h combinedLoggingHandler) ServeHTTP(w http.ResponseWriter, req *http.Request) { t := time.Now() - var logger loggingResponseWriter - if _, ok := w.(http.Hijacker); ok { - logger = &hijackLogger{responseLogger: responseLogger{w: w}} - } else { - logger = &responseLogger{w: w} - } + logger := makeLogger(w) url := *req.URL h.handler.ServeHTTP(logger, req) writeCombinedLog(h.writer, req, url, t, logger.Status(), logger.Size()) } +func makeLogger(w http.ResponseWriter) loggingResponseWriter { + var logger loggingResponseWriter = &responseLogger{w: w} + if _, ok := w.(http.Hijacker); ok { + logger = &hijackLogger{responseLogger{w: w}} + } + h, ok1 := logger.(http.Hijacker) + c, ok2 := w.(http.CloseNotifier) + if ok1 && ok2 { + return hijackCloseNotifier{logger, h, c} + } + if ok2 { + return &closeNotifyWriter{logger, c} + } + return logger +} + type loggingResponseWriter interface { http.ResponseWriter + http.Flusher Status() int Size() int } @@ -130,6 +134,13 @@ func (l *responseLogger) Size() int { return l.size } +func (l *responseLogger) Flush() { + f, ok := l.w.(http.Flusher) + if ok { + f.Flush() + } +} + type hijackLogger struct { responseLogger } @@ -144,6 +155,17 @@ func (l *hijackLogger) Hijack() (net.Conn, *bufio.ReadWriter, error) { return conn, rw, err } +type closeNotifyWriter struct { + loggingResponseWriter + http.CloseNotifier +} + +type hijackCloseNotifier struct { + loggingResponseWriter + http.Hijacker + http.CloseNotifier +} + const lowerhex = "0123456789abcdef" func appendQuoted(buf []byte, s string) []byte { From 6cb5670ba5f2ea9789f5e51154c24baac53b1b99 Mon Sep 17 00:00:00 2001 From: Aaron Lehmann Date: Mon, 27 Jul 2015 10:00:00 -0700 Subject: [PATCH 2/4] 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 --- context/http.go | 6 +++++ context/http_test.go | 7 ++++++ registry/handlers/blobupload.go | 44 +++++++++++++++++++++++++++++++-- registry/handlers/images.go | 30 ++++++++++++++++++++-- 4 files changed, 83 insertions(+), 4 deletions(-) diff --git a/context/http.go b/context/http.go index 8413a146..f61e3bc2 100644 --- a/context/http.go +++ b/context/http.go @@ -103,8 +103,13 @@ func GetRequestID(ctx Context) string { // WithResponseWriter returns a new context and response writer that makes // interesting response statistics available within the context. func WithResponseWriter(ctx Context, w http.ResponseWriter) (Context, http.ResponseWriter) { + closeNotifier, ok := w.(http.CloseNotifier) + if !ok { + panic("the ResponseWriter does not implement CloseNotifier") + } irw := &instrumentedResponseWriter{ ResponseWriter: w, + CloseNotifier: closeNotifier, Context: ctx, } @@ -262,6 +267,7 @@ func (ctx *muxVarsContext) Value(key interface{}) interface{} { // context. type instrumentedResponseWriter struct { http.ResponseWriter + http.CloseNotifier Context mu sync.Mutex diff --git a/context/http_test.go b/context/http_test.go index 3d4b3c8e..bbcd5fe2 100644 --- a/context/http_test.go +++ b/context/http_test.go @@ -110,6 +110,13 @@ func (trw *testResponseWriter) Header() http.Header { return trw.header } +// CloseNotify is only here to make the testResponseWriter implement the +// http.CloseNotifier interface, which WithResponseWriter expects to be +// implemented. +func (trw *testResponseWriter) CloseNotify() <-chan bool { + return nil +} + func (trw *testResponseWriter) Write(p []byte) (n int, err error) { if trw.status == 0 { trw.status = http.StatusOK diff --git a/registry/handlers/blobupload.go b/registry/handlers/blobupload.go index 8dc417ba..84bf26c5 100644 --- a/registry/handlers/blobupload.go +++ b/registry/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/registry/handlers/images.go b/registry/handlers/images.go index 01f9b7a2..42b2ea48 100644 --- a/registry/handlers/images.go +++ b/registry/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 9c58954a6ec26c8349fb45f360fbddac307f1ab7 Mon Sep 17 00:00:00 2001 From: Aaron Lehmann Date: Wed, 29 Jul 2015 18:18:50 -0700 Subject: [PATCH 3/4] Factor CloseNotifier use into a new function Signed-off-by: Aaron Lehmann --- registry/handlers/blobupload.go | 53 +++------------------------------ registry/handlers/helpers.go | 39 ++++++++++++++++++++++++ registry/handlers/images.go | 31 ++++--------------- 3 files changed, 48 insertions(+), 75 deletions(-) diff --git a/registry/handlers/blobupload.go b/registry/handlers/blobupload.go index 84bf26c5..1d1c1009 100644 --- a/registry/handlers/blobupload.go +++ b/registry/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/registry/handlers/helpers.go b/registry/handlers/helpers.go index e2d220c2..abbcb1be 100644 --- a/registry/handlers/helpers.go +++ b/registry/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/registry/handlers/images.go b/registry/handlers/images.go index 42b2ea48..dbe7b706 100644 --- a/registry/handlers/images.go +++ b/registry/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 609efa79e47a651337a1ced15eb4c183059747ce Mon Sep 17 00:00:00 2001 From: Aaron Lehmann Date: Fri, 31 Jul 2015 17:39:30 -0700 Subject: [PATCH 4/4] 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 --- registry/handlers/helpers.go | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/registry/handlers/helpers.go b/registry/handlers/helpers.go index abbcb1be..1f9a8ee1 100644 --- a/registry/handlers/helpers.go +++ b/registry/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: