diff --git a/README.md b/README.md index 6e98da6..793ff09 100644 --- a/README.md +++ b/README.md @@ -26,6 +26,8 @@ variable. | GET | `/{code}` | Redirect to the original URL | | GET | `/healthz` | Health check | +All requests are logged with their method, path, status code, and latency. + Example: ```sh diff --git a/internal/shortener/handler.go b/internal/shortener/handler.go index 6f6693a..c0bd216 100644 --- a/internal/shortener/handler.go +++ b/internal/shortener/handler.go @@ -24,7 +24,7 @@ func NewHandler(svc *Service) http.Handler { mux.HandleFunc("GET /healthz", func(w http.ResponseWriter, _ *http.Request) { w.WriteHeader(http.StatusOK) }) - return mux + return LoggingMiddleware(mux) } func handleShorten(svc *Service) http.HandlerFunc { diff --git a/internal/shortener/middleware.go b/internal/shortener/middleware.go new file mode 100644 index 0000000..af51191 --- /dev/null +++ b/internal/shortener/middleware.go @@ -0,0 +1,30 @@ +package shortener + +import ( + "log" + "net/http" + "time" +) + +// statusRecorder wraps http.ResponseWriter to capture the status code written +// to the response. +type statusRecorder struct { + http.ResponseWriter + status int +} + +func (r *statusRecorder) WriteHeader(code int) { + r.status = code + r.ResponseWriter.WriteHeader(code) +} + +// LoggingMiddleware logs the method, path, status code, and duration of each +// request. +func LoggingMiddleware(next http.Handler) http.Handler { + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + start := time.Now() + rec := &statusRecorder{ResponseWriter: w, status: http.StatusOK} + next.ServeHTTP(rec, r) + log.Printf("%s %s %d %s", r.Method, r.URL.Path, rec.status, time.Since(start)) + }) +} diff --git a/internal/shortener/middleware_test.go b/internal/shortener/middleware_test.go new file mode 100644 index 0000000..3e1bfac --- /dev/null +++ b/internal/shortener/middleware_test.go @@ -0,0 +1,45 @@ +package shortener + +import ( + "net/http" + "net/http/httptest" + "testing" +) + +func TestLoggingMiddlewarePassesThrough(t *testing.T) { + called := false + next := http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + called = true + w.WriteHeader(http.StatusTeapot) + w.Write([]byte("ok")) + }) + + rec := httptest.NewRecorder() + req := httptest.NewRequest(http.MethodGet, "/anything", nil) + + LoggingMiddleware(next).ServeHTTP(rec, req) + + if !called { + t.Fatal("next handler was not called") + } + if rec.Code != http.StatusTeapot { + t.Errorf("status = %d, want %d", rec.Code, http.StatusTeapot) + } + if rec.Body.String() != "ok" { + t.Errorf("body = %q, want %q", rec.Body.String(), "ok") + } +} + +func TestStatusRecorderCapturesCode(t *testing.T) { + rec := httptest.NewRecorder() + sr := &statusRecorder{ResponseWriter: rec, status: http.StatusOK} + + sr.WriteHeader(http.StatusNotFound) + + if sr.status != http.StatusNotFound { + t.Errorf("recorded status = %d, want %d", sr.status, http.StatusNotFound) + } + if rec.Code != http.StatusNotFound { + t.Errorf("underlying status = %d, want %d", rec.Code, http.StatusNotFound) + } +}