Skip to content

Commit

Permalink
improved logging with slogassert
Browse files Browse the repository at this point in the history
  • Loading branch information
jwtly10 committed Dec 26, 2024
1 parent 1b1b8d7 commit 82efea5
Show file tree
Hide file tree
Showing 2 changed files with 57 additions and 31 deletions.
4 changes: 0 additions & 4 deletions default_middlewares.go
Original file line number Diff line number Diff line change
Expand Up @@ -60,10 +60,6 @@ func newResponseWriter(w http.ResponseWriter) *responseWriter {
return &responseWriter{ResponseWriter: w}
}

func (rw *responseWriter) Status() int {
return rw.status
}

func (rw *responseWriter) WriteHeader(code int) {
if rw.wroteHeader {
return
Expand Down
84 changes: 57 additions & 27 deletions server_test.go
Original file line number Diff line number Diff line change
@@ -1,7 +1,6 @@
package fuego

import (
"bytes"
"errors"
"fmt"
"html/template"
Expand All @@ -11,6 +10,8 @@ import (
"net/http/httptest"
"testing"

"github.com/thejerf/slogassert"

"github.com/getkin/kin-openapi/openapi3"
"github.com/go-playground/validator/v10"
"github.com/stretchr/testify/assert"
Expand Down Expand Up @@ -605,9 +606,8 @@ func TestWithSecurity(t *testing.T) {
}

func TestDefaultLoggingMiddleware(t *testing.T) {
var buf bytes.Buffer
// By default request logging is Debug level
logger := slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})
handler := slogassert.New(t, slog.LevelDebug, nil)

type testCase struct {
name string
Expand Down Expand Up @@ -664,16 +664,6 @@ func TestDefaultLoggingMiddleware(t *testing.T) {
wantStatus: http.StatusOK,
wantBody: "ok",
},
{
name: "custom request ID propagation",
config: LoggingConfig{},
handler: func(c ContextNoBody) (string, error) { return "ok", nil },
requestID: "test-id",
wantRequest: true,
wantResponse: true,
wantStatus: http.StatusOK,
wantBody: "ok",
},
{
name: "error status code capture",
config: LoggingConfig{},
Expand All @@ -697,16 +687,29 @@ func TestDefaultLoggingMiddleware(t *testing.T) {
wantStatus: http.StatusCreated,
wantBody: "created",
},
{
name: "custom request id generator",
config: LoggingConfig{
RequestIDFunc: func() string {
return "custom-func-id"
},
},
handler: func(c ContextNoBody) (string, error) { return "ok", nil },
wantRequest: true,
wantResponse: true,
wantStatus: http.StatusOK,
wantBody: "ok",
},
}

for _, tc := range tests {
t.Run(tc.name, func(t *testing.T) {
buf.Reset()
s := NewServer(
WithLogHandler(logger),
WithLogHandler(handler),
WithLoggingMiddleware(tc.config),
)
Get(s, "/test", tc.handler)
handler.AssertMessage("registering controller GET /test")

rec := httptest.NewRecorder()
req := httptest.NewRequest(http.MethodGet, "/test", nil)
Expand All @@ -716,30 +719,57 @@ func TestDefaultLoggingMiddleware(t *testing.T) {

s.Mux.ServeHTTP(rec, req)

logs := buf.String()
if tc.wantRequest {
require.Contains(t, logs, "incoming request")
require.Contains(t, logs, "method=GET")
require.Contains(t, logs, "path=/test")
} else {
require.NotContains(t, logs, "incoming request")
expectedReqAttrs := map[string]any{
"method": "GET",
"path": "/test",
}

if tc.requestID != "" {
expectedReqAttrs["request_id"] = tc.requestID
}

handler.AssertPrecise(slogassert.LogMessageMatch{
Message: "incoming request",
Level: slog.LevelDebug,
Attrs: expectedReqAttrs,
})
}

if tc.wantResponse {
require.Contains(t, logs, "outgoing response")
require.Contains(t, logs, fmt.Sprintf("status_code=%d", tc.wantStatus))
require.Contains(t, logs, "duration_ms=")
} else {
require.NotContains(t, logs, "outgoing response")
expectedResAttrs := map[string]any{
"method": "GET",
"path": "/test",
"status_code": tc.wantStatus,
}

if tc.requestID != "" {
expectedResAttrs["request_id"] = tc.requestID
}

handler.AssertPrecise(slogassert.LogMessageMatch{
Message: "outgoing response",
Level: slog.LevelInfo,
Attrs: expectedResAttrs,
})
}

require.Equal(t, tc.wantStatus, rec.Code)
require.Contains(t, rec.Body.String(), tc.wantBody)

// Check request id being propagated to response
if tc.requestID != "" {
require.Contains(t, logs, fmt.Sprintf("request_id=%s", tc.requestID))
require.Equal(t, tc.requestID, rec.Header().Get("X-Request-ID"))
}

// Check case of custom request id generator is propagated to response
if tc.config.RequestIDFunc != nil {
require.Equal(t, "custom-func-id", rec.Header().Get("X-Request-ID"))
}

// all logs should be handled here
handler.AssertEmpty()
})
}

}

0 comments on commit 82efea5

Please sign in to comment.