diff --git a/middleware/log_test.go b/middleware/log_test.go index 178b6028..c61bc1ae 100644 --- a/middleware/log_test.go +++ b/middleware/log_test.go @@ -5,7 +5,7 @@ import ( "context" "fmt" "io" - mathRand "math/rand/v2" + "log/slog" "net/http" "net/http/httptest" "sync" @@ -23,47 +23,6 @@ const ( someLatencyMS = 3 ) -func toLog(t *testing.T, buf *bytes.Buffer) func(w http.ResponseWriter, r http.Request, statusCode int, fields []any) { - t.Helper() - - const ( - msg = "http_server" - // rateShedSamplePercent is the percentage of rate limited or loadshed responses that will be logged as errors, by default. - rateShedSamplePercent = 10 - ) - - l := log.New(context.Background(), buf, 500) - - return func(w http.ResponseWriter, r http.Request, statusCode int, fields []any) { - // Each request should get its own context. That's why we call `log.WithID` for every request. - reqL := log.WithID(r.Context(), l) - - if (statusCode == http.StatusServiceUnavailable || statusCode == http.StatusTooManyRequests) && w.Header().Get(retryAfterHeader) != "" { - // We are either in load shedding or rate-limiting. - // Only log (rateShedSamplePercent)% of the errors. - shouldLog := mathRand.IntN(100) <= rateShedSamplePercent - if shouldLog { - reqL.Error(msg, fields...) - return - } - } - - if statusCode >= http.StatusBadRequest { - // Both client and server errors. - if statusCode == http.StatusNotFound || statusCode == http.StatusMethodNotAllowed || statusCode == http.StatusTeapot { - // These ones are more of an annoyance, than been actual errors. - reqL.Info(msg, fields...) - return - } - - reqL.Error(msg, fields...) - return - } - - reqL.Info(msg, fields...) - } -} - func someLogHandler(successMsg string) http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { // sleep so that the log middleware has some useful duration metrics to report. @@ -85,12 +44,16 @@ func someLogHandler(successMsg string) http.HandlerFunc { func TestLogMiddleware(t *testing.T) { t.Parallel() + getLogger := func(w io.Writer) *slog.Logger { + return log.New(context.Background(), w, 500) + } + t.Run("success", func(t *testing.T) { t.Parallel() logOutput := &bytes.Buffer{} successMsg := "hello" - wrappedHandler := logger(someLogHandler(successMsg), toLog(t, logOutput), nil) + wrappedHandler := logger(someLogHandler(successMsg), nil, getLogger(logOutput)) rec := httptest.NewRecorder() req := httptest.NewRequest(http.MethodHead, "/someUri", nil) @@ -113,7 +76,7 @@ func TestLogMiddleware(t *testing.T) { logOutput := &bytes.Buffer{} errorMsg := "someLogHandler failed" successMsg := "hello" - wrappedHandler := logger(someLogHandler(successMsg), toLog(t, logOutput), nil) + wrappedHandler := logger(someLogHandler(successMsg), nil, getLogger(logOutput)) rec := httptest.NewRecorder() req := httptest.NewRequest(http.MethodHead, "/someUri", nil) @@ -149,7 +112,7 @@ func TestLogMiddleware(t *testing.T) { logOutput := &bytes.Buffer{} successMsg := "hello" errorMsg := "someLogHandler failed" - wrappedHandler := logger(someLogHandler(successMsg), toLog(t, logOutput), nil) + wrappedHandler := logger(someLogHandler(successMsg), nil, getLogger(logOutput)) { // first request that succeds @@ -228,7 +191,7 @@ func TestLogMiddleware(t *testing.T) { logOutput := &bytes.Buffer{} successMsg := "hello" - wrappedHandler := logger(someLogHandler(successMsg), toLog(t, logOutput), nil) + wrappedHandler := logger(someLogHandler(successMsg), nil, getLogger(logOutput)) someLogID := "hey-some-log-id:" + id.New() @@ -258,7 +221,7 @@ func TestLogMiddleware(t *testing.T) { successMsg := "hello" // for this concurrency test, we have to re-use the same wrappedHandler // so that state is shared and thus we can see if there is any state which is not handled correctly. - wrappedHandler := logger(someLogHandler(successMsg), toLog(t, logOutput), nil) + wrappedHandler := logger(someLogHandler(successMsg), nil, getLogger(logOutput)) runhandler := func() { rec := httptest.NewRecorder() diff --git a/middleware/recoverer_test.go b/middleware/recoverer_test.go index 64f77d77..bb527268 100644 --- a/middleware/recoverer_test.go +++ b/middleware/recoverer_test.go @@ -2,7 +2,10 @@ package middleware import ( "bytes" + "context" "fmt" + "io" + "log/slog" "net/http" "net/http/httptest" "strings" @@ -10,6 +13,7 @@ import ( "testing" "github.com/komuw/ong/errors" + "github.com/komuw/ong/log" "go.akshayshah.org/attest" ) @@ -43,12 +47,16 @@ func anotherHandlerThatPanics() http.HandlerFunc { func TestPanic(t *testing.T) { t.Parallel() + getLogger := func(w io.Writer) *slog.Logger { + return log.New(context.Background(), w, 500) + } + t.Run("ok if no panic", func(t *testing.T) { t.Parallel() logOutput := &bytes.Buffer{} msg := "hello" - wrappedHandler := recoverer(handlerThatPanics(msg, false, nil), toLog(t, logOutput), nil) + wrappedHandler := recoverer(handlerThatPanics(msg, false, nil), nil, getLogger(logOutput)) rec := httptest.NewRecorder() req := httptest.NewRequest(http.MethodGet, "/someUri", nil) @@ -65,7 +73,7 @@ func TestPanic(t *testing.T) { logOutput := &bytes.Buffer{} msg := "hello" - wrappedHandler := recoverer(handlerThatPanics(msg, true, nil), toLog(t, logOutput), nil) + wrappedHandler := recoverer(handlerThatPanics(msg, true, nil), nil, getLogger(logOutput)) rec := httptest.NewRecorder() req := httptest.NewRequest(http.MethodGet, "/someUri", nil) @@ -95,7 +103,7 @@ func TestPanic(t *testing.T) { msg := "hello" errMsg := "99 problems" err := errors.New(errMsg) - wrappedHandler := recoverer(handlerThatPanics(msg, false, err), toLog(t, logOutput), nil) + wrappedHandler := recoverer(handlerThatPanics(msg, false, err), nil, getLogger(logOutput)) rec := httptest.NewRecorder() req := httptest.NewRequest(http.MethodGet, "/someUri", nil) @@ -123,7 +131,7 @@ func TestPanic(t *testing.T) { t.Parallel() logOutput := &bytes.Buffer{} - wrappedHandler := recoverer(anotherHandlerThatPanics(), toLog(t, logOutput), nil) + wrappedHandler := recoverer(anotherHandlerThatPanics(), nil, getLogger(logOutput)) rec := httptest.NewRecorder() req := httptest.NewRequest(http.MethodGet, "/someUri", nil) @@ -144,7 +152,7 @@ func TestPanic(t *testing.T) { err := errors.New(msg) // for this concurrency test, we have to re-use the same wrappedHandler // so that state is shared and thus we can see if there is any state which is not handled correctly. - wrappedHandler := recoverer(handlerThatPanics(msg, false, err), toLog(t, logOutput), nil) + wrappedHandler := recoverer(handlerThatPanics(msg, false, err), nil, getLogger(logOutput)) runhandler := func() { rec := httptest.NewRecorder()