Skip to content

Commit

Permalink
g
Browse files Browse the repository at this point in the history
  • Loading branch information
@komuw
komuw committed Aug 17, 2024
1 parent 6e311a6 commit c0b9021
Show file tree
Hide file tree
Showing 2 changed files with 23 additions and 52 deletions.
57 changes: 10 additions & 47 deletions middleware/log_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,7 @@ import (
"context"
"fmt"
"io"
mathRand "math/rand/v2"
"log/slog"
"net/http"
"net/http/httptest"
"sync"
Expand All @@ -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.
Expand All @@ -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)
Expand All @@ -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)
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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()

Expand Down Expand Up @@ -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()
Expand Down
18 changes: 13 additions & 5 deletions middleware/recoverer_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2,14 +2,18 @@ package middleware

import (
"bytes"
"context"
"fmt"
"io"
"log/slog"
"net/http"
"net/http/httptest"
"strings"
"sync"
"testing"

"github.com/komuw/ong/errors"
"github.com/komuw/ong/log"

"go.akshayshah.org/attest"
)
Expand Down Expand Up @@ -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)
Expand All @@ -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)
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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)
Expand All @@ -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()
Expand Down

0 comments on commit c0b9021

Please sign in to comment.