diff --git a/cmd/crc/cmd/custom_response_writer.go b/cmd/crc/cmd/custom_response_writer.go new file mode 100644 index 0000000000..7489c5b4f3 --- /dev/null +++ b/cmd/crc/cmd/custom_response_writer.go @@ -0,0 +1,49 @@ +package cmd + +import ( + "bytes" + "net/http" +) + +// CustomResponseWriter wraps the standard http.ResponseWriter and captures the response body +type CustomResponseWriter struct { + http.ResponseWriter + statusCode int + body *bytes.Buffer +} + +// NewCustomResponseWriter creates a new CustomResponseWriter +func NewCustomResponseWriter(w http.ResponseWriter) *CustomResponseWriter { + return &CustomResponseWriter{ + ResponseWriter: w, + statusCode: http.StatusOK, + body: &bytes.Buffer{}, + } +} + +// WriteHeader allows capturing and modifying the status code +func (rw *CustomResponseWriter) WriteHeader(statusCode int) { + rw.statusCode = statusCode + rw.ResponseWriter.WriteHeader(statusCode) +} + +// Write captures the response body and logs it +func (rw *CustomResponseWriter) Write(p []byte) (int, error) { + bufferLen, err := rw.body.Write(p) + if err != nil { + return bufferLen, err + } + + return rw.ResponseWriter.Write(p) +} + +// interceptResponseBodyMiddleware injects the custom bodyConsumer function (received as second argument) into +// http.HandleFunc logic that allows users to intercept response body as per their requirements (e.g. logging) +// and returns updated http.Handler +func interceptResponseBodyMiddleware(next http.Handler, bodyConsumer func(statusCode int, buffer *bytes.Buffer, r *http.Request)) http.Handler { + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + responseWriter := NewCustomResponseWriter(w) + next.ServeHTTP(responseWriter, r) + bodyConsumer(responseWriter.statusCode, responseWriter.body, r) + }) +} diff --git a/cmd/crc/cmd/custom_response_writer_test.go b/cmd/crc/cmd/custom_response_writer_test.go new file mode 100644 index 0000000000..13efa81dfe --- /dev/null +++ b/cmd/crc/cmd/custom_response_writer_test.go @@ -0,0 +1,51 @@ +package cmd + +import ( + "bytes" + "fmt" + "net/http" + "net/http/httptest" + "testing" + + "github.com/stretchr/testify/assert" +) + +type TestHandler struct { +} + +func (t *TestHandler) ServeHTTP(w http.ResponseWriter, _ *http.Request) { + _, err := fmt.Fprint(w, "Testing!") + if err != nil { + return + } +} + +func TestLogResponseBodyMiddlewareCapturesResponseAsExpected(t *testing.T) { + // Given + interceptedResponseStatusCode := -1 + interceptedResponseBody := "" + responseBodyConsumer := func(statusCode int, buffer *bytes.Buffer, _ *http.Request) { + interceptedResponseStatusCode = statusCode + interceptedResponseBody = buffer.String() + } + testHandler := &TestHandler{} + server := httptest.NewServer(interceptResponseBodyMiddleware(http.StripPrefix("/", testHandler), responseBodyConsumer)) + defer server.Close() + // When + resp, err := http.Get(server.URL) + if err != nil { + t.Fatal(err) + } + + // Then + responseBody := new(bytes.Buffer) + bytesRead, err := responseBody.ReadFrom(resp.Body) + if err != nil { + t.Fatal(err) + } + assert.Equal(t, 200, resp.StatusCode) + assert.Equal(t, 200, interceptedResponseStatusCode) + assert.Equal(t, int64(8), bytesRead) + assert.Equal(t, "Testing!", responseBody.String()) + assert.Equal(t, "Testing!", interceptedResponseBody) +} diff --git a/cmd/crc/cmd/daemon.go b/cmd/crc/cmd/daemon.go index 1c3826a219..6863f872cd 100644 --- a/cmd/crc/cmd/daemon.go +++ b/cmd/crc/cmd/daemon.go @@ -1,6 +1,7 @@ package cmd import ( + "bytes" "encoding/json" "fmt" "io" @@ -142,10 +143,10 @@ func run(configuration *types.Configuration) error { return } mux := http.NewServeMux() - mux.Handle("/network/", http.StripPrefix("/network", vn.Mux())) + mux.Handle("/network/", interceptResponseBodyMiddleware(http.StripPrefix("/network", vn.Mux()), logResponseBodyConditionally)) machineClient := newMachine() - mux.Handle("/api/", http.StripPrefix("/api", api.NewMux(config, machineClient, logging.Memory, segmentClient))) - mux.Handle("/events", http.StripPrefix("/events", events.NewEventServer(machineClient))) + mux.Handle("/api/", interceptResponseBodyMiddleware(http.StripPrefix("/api", api.NewMux(config, machineClient, logging.Memory, segmentClient)), logResponseBodyConditionally)) + mux.Handle("/events", interceptResponseBodyMiddleware(http.StripPrefix("/events", events.NewEventServer(machineClient)), logResponseBodyConditionally)) s := &http.Server{ Handler: handlers.LoggingHandler(os.Stderr, mux), ReadHeaderTimeout: 10 * time.Second, @@ -271,3 +272,11 @@ func acceptJSONStringArray(w http.ResponseWriter, r *http.Request, fun func(host } w.WriteHeader(http.StatusOK) } + +func logResponseBodyConditionally(statusCode int, buffer *bytes.Buffer, r *http.Request) { + responseBody := buffer.String() + if statusCode != http.StatusOK && responseBody != "" { + log.Errorf("[%s] \"%s %s\" Response Body: %s\n", time.Now().Format("02/Jan/2006:15:04:05 -0700"), + r.Method, r.URL.Path, buffer.String()) + } +} diff --git a/cmd/crc/cmd/daemon_test.go b/cmd/crc/cmd/daemon_test.go new file mode 100644 index 0000000000..f494585450 --- /dev/null +++ b/cmd/crc/cmd/daemon_test.go @@ -0,0 +1,55 @@ +package cmd + +import ( + "bytes" + "net/http" + "net/url" + "os" + "testing" + + "github.com/sirupsen/logrus" + "github.com/stretchr/testify/assert" +) + +func TestLogResponseBodyLogsResponseBodyForFailedResponseCodes(t *testing.T) { + // Given + var logBuffer bytes.Buffer + var responseBuffer bytes.Buffer + responseBuffer.WriteString("{\"status\": \"FAILURE\"}") + logrus.SetOutput(&logBuffer) + defer logrus.SetOutput(os.Stdout) + requestURL, err := url.Parse("http://127.0.0.1/log") + assert.NoError(t, err) + httpRequest := &http.Request{ + Method: "GET", + URL: requestURL, + } + + // When + logResponseBodyConditionally(500, &responseBuffer, httpRequest) + + // Then + assert.Greater(t, logBuffer.Len(), 0) + assert.Contains(t, logBuffer.String(), ("\\\"GET /log\\\" Response Body: {\\\"status\\\": \\\"FAILURE\\\"}")) +} + +func TestLogResponseBodyLogsNothingWhenResponseSuccessful(t *testing.T) { + // Given + var logBuffer bytes.Buffer + var responseBuffer bytes.Buffer + responseBuffer.WriteString("{\"status\": \"SUCCESS\"}") + logrus.SetOutput(&logBuffer) + defer logrus.SetOutput(os.Stdout) + requestURL, err := url.Parse("http://127.0.0.1/log") + assert.NoError(t, err) + httpRequest := &http.Request{ + Method: "GET", + URL: requestURL, + } + + // When + logResponseBodyConditionally(200, &responseBuffer, httpRequest) + + // Then + assert.Equal(t, logBuffer.Len(), 0) +}