From 6c4d49f8ac7fd8fcc879d42452499c212d62603d Mon Sep 17 00:00:00 2001 From: Wei Zang Date: Thu, 14 Mar 2024 15:24:33 +0800 Subject: [PATCH 1/4] chore(examples): add one example to log request body when the status code is non 200 --- examples/internal/gateway/handlers.go | 40 ++++++++++++++++++++++++++- examples/internal/gateway/main.go | 2 +- 2 files changed, 40 insertions(+), 2 deletions(-) diff --git a/examples/internal/gateway/handlers.go b/examples/internal/gateway/handlers.go index 6fdb3cec102..977bd88fa61 100644 --- a/examples/internal/gateway/handlers.go +++ b/examples/internal/gateway/handlers.go @@ -1,7 +1,9 @@ package gateway import ( + "bytes" "fmt" + "io" "net/http" "path" "strings" @@ -27,7 +29,7 @@ func openAPIServer(dir string) http.HandlerFunc { } } -// allowCORS allows Cross Origin Resoruce Sharing from any origin. +// allowCORS allows Cross Origin Resource Sharing from any origin. // Don't do this without consideration in production systems. func allowCORS(h http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { @@ -64,3 +66,39 @@ func healthzServer(conn *grpc.ClientConn) http.HandlerFunc { fmt.Fprintln(w, "ok") } } + +type logResponseWriter struct { + http.ResponseWriter + statusCode int +} + +func (rsp *logResponseWriter) WriteHeader(code int) { + rsp.statusCode = code + rsp.ResponseWriter.WriteHeader(code) +} + +func newLogResponseWriter(w http.ResponseWriter) *logResponseWriter { + return &logResponseWriter{w, http.StatusOK} +} + +// logRequestBody logs the request body when the response status code is not 200. +// This addresses the issue of being unable to retrieve the request body in the customErrorHandler middleware. +func logRequestBody(h http.Handler) http.Handler { + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + lw := newLogResponseWriter(w) + body, err := io.ReadAll(r.Body) + if err != nil { + http.Error(w, fmt.Sprintf("grpc server read request body err %+v", err), http.StatusBadRequest) + return + } + clonedR := r.Clone(r.Context()) + r.Body = io.NopCloser(bytes.NewReader(body)) + clonedR.Body = io.NopCloser(bytes.NewReader(body)) + + h.ServeHTTP(lw, clonedR) + + if lw.statusCode != http.StatusOK { + grpclog.Errorf("http error %+v request body %+v", lw.statusCode, string(body)) + } + }) +} diff --git a/examples/internal/gateway/main.go b/examples/internal/gateway/main.go index c7035b40fc4..25f9f820a83 100644 --- a/examples/internal/gateway/main.go +++ b/examples/internal/gateway/main.go @@ -58,7 +58,7 @@ func Run(ctx context.Context, opts Options) error { s := &http.Server{ Addr: opts.Addr, - Handler: allowCORS(mux), + Handler: logRequestBody(allowCORS(mux)), } go func() { <-ctx.Done() From 38bcea226f6c07641a735e16a087e6a3fb66262d Mon Sep 17 00:00:00 2001 From: Wei Zang Date: Fri, 15 Mar 2024 11:50:32 +0800 Subject: [PATCH 2/4] chore(examples): fix typo --- examples/internal/gateway/handlers.go | 1 - 1 file changed, 1 deletion(-) diff --git a/examples/internal/gateway/handlers.go b/examples/internal/gateway/handlers.go index 977bd88fa61..a4cbb2d4cb9 100644 --- a/examples/internal/gateway/handlers.go +++ b/examples/internal/gateway/handlers.go @@ -92,7 +92,6 @@ func logRequestBody(h http.Handler) http.Handler { return } clonedR := r.Clone(r.Context()) - r.Body = io.NopCloser(bytes.NewReader(body)) clonedR.Body = io.NopCloser(bytes.NewReader(body)) h.ServeHTTP(lw, clonedR) From 0a928a9198deb8ec1b9d29c0e6f771d2c7eb067f Mon Sep 17 00:00:00 2001 From: Wei Zang Date: Sat, 16 Mar 2024 15:30:51 +0800 Subject: [PATCH 3/4] chore(deps): add logging the request body for a request doc --- docs/docs/operations/logging.md | 58 +++++++++++++++++++++++++++++++++ 1 file changed, 58 insertions(+) create mode 100644 docs/docs/operations/logging.md diff --git a/docs/docs/operations/logging.md b/docs/docs/operations/logging.md new file mode 100644 index 00000000000..f69a96cea75 --- /dev/null +++ b/docs/docs/operations/logging.md @@ -0,0 +1,58 @@ +--- +layout: default +title: Logging the request body pattern for a request +nav_order: 5 +parent: Operations +--- + +# Logging the request body pattern for a request + +If you want to log the request body in the `customErrorHandler` middleware, unfortunately the request body has been consumed in the `customErrorHandler` middleware and can't be read again. To log the request body, you can use one middleware to buffer the request body before it's consumed. + +1. `logRequestBody` middleware，which logs the request body when the response status code is not 200. + +```go +type logResponseWriter struct { + http.ResponseWriter + statusCode int +} + +func (rsp *logResponseWriter) WriteHeader(code int) { + rsp.statusCode = code + rsp.ResponseWriter.WriteHeader(code) +} + +func newLogResponseWriter(w http.ResponseWriter) *logResponseWriter { + return &logResponseWriter{w, http.StatusOK} +} + +// logRequestBody logs the request body when the response status code is not 200. +func logRequestBody(h http.Handler) http.Handler { + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + lw := newLogResponseWriter(w) + body, err := io.ReadAll(r.Body) + if err != nil { + http.Error(w, fmt.Sprintf("grpc server read request body err %+v", err), http.StatusBadRequest) + return + } + clonedR := r.Clone(r.Context()) + clonedR.Body = io.NopCloser(bytes.NewReader(body)) + + h.ServeHTTP(lw, clonedR) + + if lw.statusCode != http.StatusOK { + grpclog.Errorf("http error %+v request body %+v", lw.statusCode, string(body)) + } + }) +} +``` + +2. Wrap the `logRequestBody` middleware with the `http.ServeMux`: + +```go + mux := http.NewServeMux() + + s := &http.Server{ + Handler: logRequestBody(mux), + } +``` \ No newline at end of file From 1240cadae62eaf89ad4150ffa0d41d271b022d1a Mon Sep 17 00:00:00 2001 From: Wei Zang Date: Sun, 17 Mar 2024 09:31:27 +0800 Subject: [PATCH 4/4] chore(deps): update logging docs with some minor edits --- docs/docs/operations/logging.md | 13 ++++++++----- 1 file changed, 8 insertions(+), 5 deletions(-) diff --git a/docs/docs/operations/logging.md b/docs/docs/operations/logging.md index f69a96cea75..e099e7b5da3 100644 --- a/docs/docs/operations/logging.md +++ b/docs/docs/operations/logging.md @@ -7,9 +7,9 @@ parent: Operations # Logging the request body pattern for a request -If you want to log the request body in the `customErrorHandler` middleware, unfortunately the request body has been consumed in the `customErrorHandler` middleware and can't be read again. To log the request body, you can use one middleware to buffer the request body before it's consumed. +If you want to log the request body of incoming requests, you will need to buffer the body before it reaches the gateway. To log the request body, you can use a middleware `http.Handler` to buffer the request body before it's consumed. -1. `logRequestBody` middleware，which logs the request body when the response status code is not 200. +1. Create a `http.Handler` middleware. The `logRequestBody` example middleware logs the request body when the response status code is not 200. ```go type logResponseWriter struct { @@ -30,9 +30,11 @@ func newLogResponseWriter(w http.ResponseWriter) *logResponseWriter { func logRequestBody(h http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { lw := newLogResponseWriter(w) + + // Note that buffering the entire request body could consume a lot of memory. body, err := io.ReadAll(r.Body) if err != nil { - http.Error(w, fmt.Sprintf("grpc server read request body err %+v", err), http.StatusBadRequest) + http.Error(w, fmt.Sprintf("failed to read body: %v", err), http.StatusBadRequest) return } clonedR := r.Clone(r.Context()) @@ -47,10 +49,11 @@ func logRequestBody(h http.Handler) http.Handler { } ``` -2. Wrap the `logRequestBody` middleware with the `http.ServeMux`: +2. Wrap the gateway serve mux with the `logRequestBody` middleware: ```go - mux := http.NewServeMux() + mux := runtime.NewServeMux() + // Register generated gateway handlers s := &http.Server{ Handler: logRequestBody(mux),