Skip to content
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
59 changes: 58 additions & 1 deletion middleware/logging.go
Original file line number Diff line number Diff line change
Expand Up @@ -255,12 +255,69 @@ func WithHTTPLogging(opts ...LogMiddlewareOption) fiber.Handler {
}

info.FinishRequestInfo(&rw)
logger.Log(c.UserContext(), obslog.LevelInfo, info.CLFString())

accessLogger := logger.With(obslog.String("http_client_ip", info.RemoteAddress))
if body := errorBodyForLog(c, statusCode, mid.ObfuscationDisabled); body != "" {
accessLogger = accessLogger.With(obslog.String("http_error", body))
}

accessLogger.Log(c.UserContext(), obslog.LevelInfo, info.CLFString())

return err
}
}

// maxErrorBodyLogLen caps the http_error field so a large error response body
// cannot bloat the access log entry. 2 KiB comfortably covers structured API
// error payloads while bounding log volume.
const maxErrorBodyLogLen = 2048

// errorBodyForLog returns a sanitized, length-capped copy of the response body
// suitable for the http_error log field, or "" when it should not be logged.
//
// Bodies are only logged for error responses (status >= 400). The body is
// obfuscated with the same content-type-aware redaction pipeline used for
// request bodies (unless obfuscation is disabled), so sensitive fields are not
// leaked, and is then truncated to maxErrorBodyLogLen bytes on a UTF-8 rune
// boundary.
func errorBodyForLog(c *fiber.Ctx, statusCode int, obfuscationDisabled bool) string {
if c == nil || statusCode < fiber.StatusBadRequest {
return ""
}

bodyBytes := c.Response().Body()
if len(bodyBytes) == 0 {
return ""
}

body := string(bodyBytes)
if !obfuscationDisabled {
body = getResponseBodyObfuscatedString(c, bodyBytes)
}

return truncateLogBody(body)
}

// truncateLogBody caps body at maxErrorBodyLogLen bytes, cutting on a rune
// boundary so the stored value is always valid UTF-8.
func truncateLogBody(body string) string {
if len(body) <= maxErrorBodyLogLen {
return body
}

lastFit := 0

for i := range body {
if i > maxErrorBodyLogLen {
return body[:lastFit]
}

lastFit = i
}

return body[:lastFit]
}

func httpStatusCode(c *fiber.Ctx, err error) int {
statusCode := c.Response().StatusCode()
if err == nil {
Expand Down
15 changes: 15 additions & 0 deletions middleware/logging_obfuscation.go
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,21 @@ func getBodyObfuscatedString(c *fiber.Ctx, bodyBytes []byte) string {
}
}

// getResponseBodyObfuscatedString obfuscates a response body for logging,
// keying off the response Content-Type (not the request header). JSON error
// payloads are passed through the same key-based redaction as request bodies so
// sensitive fields are never written to the http_error log field; any other
// content type is reduced to the [REDACTED] placeholder.
func getResponseBodyObfuscatedString(c *fiber.Ctx, bodyBytes []byte) string {
contentType := strings.ToLower(string(c.Response().Header.ContentType()))

if strings.Contains(contentType, "application/json") {
return handleJSONBody(bodyBytes)
}

return redactedBody
}

func obfuscateMapRecursively(data map[string]any, depth int) {
if depth >= maxObfuscationDepth {
return
Expand Down
87 changes: 87 additions & 0 deletions middleware/logging_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -250,6 +250,93 @@ func TestWithHTTPLoggingLogsErrorStatus(t *testing.T) {
assert.Contains(t, messages[0], " 500 ")
}

func TestWithHTTPLoggingAddsClientIPField(t *testing.T) {
logger := &captureLogger{}
app := fiber.New()
app.Use(WithHTTPLogging(WithCustomLogger(logger)))
app.Get("/ok", func(c *fiber.Ctx) error {
return c.SendString("ok")
})

req := httptest.NewRequest(http.MethodGet, "/ok", nil)
resp, err := app.Test(req)
require.NoError(t, err)
defer func() { require.NoError(t, resp.Body.Close()) }()

_, fields := logger.snapshot()

var clientIPFound bool

for _, f := range fields {
if f.Key != "http_client_ip" {
continue
}

clientIPFound = true

ip, ok := f.Value.(string)
require.True(t, ok, "http_client_ip should be a string")
assert.NotEmpty(t, ip)
}

assert.True(t, clientIPFound, "expected http_client_ip field on access log entry")
}

func TestWithHTTPLoggingLogsSanitizedErrorBody(t *testing.T) {
logger := &captureLogger{}
app := fiber.New()
app.Use(WithHTTPLogging(WithCustomLogger(logger)))
app.Get("/fail", func(c *fiber.Ctx) error {
c.Set(headerContentType, "application/json")

return c.Status(http.StatusBadRequest).
SendString(`{"error":"invalid request","password":"secret"}`)
})

req := httptest.NewRequest(http.MethodGet, "/fail", nil)
resp, err := app.Test(req)
require.NoError(t, err)
defer func() { require.NoError(t, resp.Body.Close()) }()

_, fields := logger.snapshot()

var errorBody string

for _, f := range fields {
if f.Key == "http_error" {
if s, ok := f.Value.(string); ok {
errorBody = s
}
}
}

require.NotEmpty(t, errorBody, "expected http_error field for 4xx response")
assert.Contains(t, errorBody, "invalid request")
assert.NotContains(t, errorBody, "secret")
}

func TestWithHTTPLoggingOmitsErrorBodyForSuccess(t *testing.T) {
logger := &captureLogger{}
app := fiber.New()
app.Use(WithHTTPLogging(WithCustomLogger(logger)))
app.Get("/ok", func(c *fiber.Ctx) error {
c.Set(headerContentType, "application/json")

return c.SendString(`{"status":"ok"}`)
})

req := httptest.NewRequest(http.MethodGet, "/ok", nil)
resp, err := app.Test(req)
require.NoError(t, err)
defer func() { require.NoError(t, resp.Body.Close()) }()

_, fields := logger.snapshot()

for _, f := range fields {
assert.NotEqual(t, "http_error", f.Key, "http_error must not be logged for 2xx responses")
}
}

func TestWithGrpcLoggingUsesBodyRequestIDAndLogsResult(t *testing.T) {
logger := &captureLogger{}
bodyRequestID := "4fbf011b-bb11-4c73-9f7c-4f8e19ca8402"
Expand Down
Loading