Skip to content

Commit bca1a01

Browse files
ReneWerner87claude
andcommitted
fix: address PR review feedback (Copilot + CodeRabbit)
Address four substantive review findings on the contextual-logs work. 1. log/default.go writeContext error sanitization (Copilot) The render-error marker piped err.Error() through fmt.Fprintf, which could carry CR/LF/ANSI bytes from a tag wrapping attacker-controlled data. Route the message through writeSanitizedString — the same sanitiser ${value:KEY} already uses — so a misconfigured tag cannot become a log-injection vector. Test_WithContextRenderError now embeds CR/LF in the error and asserts they are stripped. 2. docs/api/log.md KeyValueFormat consistency (Copilot) Both the Go-block snippet and the Context Formats table referenced the bare ${requestid} tag while the actual KeyValueFormat constant uses the dashed ${request-id} alias. Align both to the constant. 3. log/default.go newRetainedContext typed-nil handling (CodeRabbit) `value != nil` does not catch typed nils such as `(*fasthttp.RequestCtx)(nil)` stored in an `any`; the interface header carries a non-nil type descriptor and the renderer would dereference a nil receiver. Use reflect.Value.IsNil() on the nilable kinds (Chan, Func, Interface, Map, Pointer, Slice) to collapse typed nils to retainedContext{}. Reflection runs once per WithContext call (not per log line), so the cost is irrelevant to the hot path. Test_NewRetainedContext_TypedNil locks in coverage for untyped nil, typed-nil pointer/map/slice/chan, and non-nil variants of the same. 4. middleware/csrf csrf-token redaction shape (CodeRabbit) Switch the csrf-token tag from the package-local "[redacted]" constant to redact.Prefix(token), aligning the masking shape with keyauth and session (4-byte clear prefix + "****"). Log consumers now see a uniform redaction format across every security-sensitive tag the framework registers. csrf_test assertions move from exact match against redactedKey to shape-based assertions on the redact.Mask suffix. The package-internal redactedKey constant is retained for storage-manager redaction (unchanged behavior). Also document the intentional-by-design decisions: - middleware/basicauth basicauth.go: ${username} is written in clear text for audit-log use cases. Add a godoc block on registerLogContextTags pointing developers to UsernameFromContext if full usernames count as PII in their jurisdiction. Mirror the callout in docs/api/log.md. Verified locally with golangci-lint v2.6.0 (CI-matching), modernize@latest, and `go test -race -shuffle=on` on the affected packages. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
1 parent 132fcd9 commit bca1a01

6 files changed

Lines changed: 99 additions & 18 deletions

File tree

docs/api/log.md

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -271,7 +271,7 @@ type Buffer = logtemplate.Buffer
271271
const (
272272
DefaultFormat = ""
273273
RequestIDFormat = "[${requestid}] "
274-
KeyValueFormat = "request-id=${requestid} username=${username} api-key=${api-key} csrf-token=${csrf-token} session-id=${session-id} "
274+
KeyValueFormat = "request-id=${request-id} username=${username} api-key=${api-key} csrf-token=${csrf-token} session-id=${session-id} "
275275
TagContextValue = "value:"
276276
)
277277
```
@@ -282,16 +282,16 @@ const (
282282
| :-- | :-- | :-- |
283283
| `DefaultFormat` | `""` | Disables contextual fields. |
284284
| `RequestIDFormat` | `"[${requestid}] "` | Prepends the request ID when the requestid middleware is used. |
285-
| `KeyValueFormat` | `"request-id=${requestid} username=${username} api-key=${api-key} csrf-token=${csrf-token} session-id=${session-id} "` | Prepends common middleware context values as key/value fields. Sensitive values are redacted by the registering middleware. |
285+
| `KeyValueFormat` | `"request-id=${request-id} username=${username} api-key=${api-key} csrf-token=${csrf-token} session-id=${session-id} "` | Prepends common middleware context values as key/value fields. Sensitive values are redacted by the registering middleware. |
286286

287287
### Context Tags
288288

289289
| Tag | Source |
290290
| :-- | :-- |
291291
| `${requestid}` / `${request-id}` | `requestid` middleware |
292-
| `${username}` | `basicauth` middleware |
292+
| `${username}` | `basicauth` middleware — written **in clear text** for audit-log use cases. Avoid this tag if your usernames are PII. |
293293
| `${api-key}` | `keyauth` middleware, redacted to a 4-byte prefix |
294-
| `${csrf-token}` | `csrf` middleware, redacted to a constant placeholder |
294+
| `${csrf-token}` | `csrf` middleware, redacted to a 4-byte prefix |
295295
| `${session-id}` | `session` middleware, redacted to a 4-byte prefix |
296296
| `${value:key}` | Any bound value with `Value(key)` or `UserValue(key)` lookup methods |
297297

log/default.go

Lines changed: 28 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ import (
55
"io"
66
"log"
77
"os"
8+
"reflect"
89

910
"github.com/gofiber/utils/v2"
1011
"github.com/valyala/bytebufferpool"
@@ -28,11 +29,28 @@ type retainedContext struct {
2829
ok bool
2930
}
3031

32+
// newRetainedContext wraps value, treating both untyped nil and typed-nil
33+
// pointers/interfaces/maps/slices/channels/funcs as "no context". A typed nil
34+
// (e.g. (*fasthttp.RequestCtx)(nil) stored in an `any`) compares non-nil under
35+
// `value != nil` because the interface header carries a non-nil type
36+
// descriptor; passing it through to a tag renderer would cause the renderer
37+
// to dereference a nil receiver. Reflection here is one-shot per WithContext
38+
// call — far off the per-log-line hot path.
3139
func newRetainedContext(value any) retainedContext {
32-
return retainedContext{
33-
value: value,
34-
ok: value != nil,
40+
if value == nil {
41+
return retainedContext{}
3542
}
43+
switch rv := reflect.ValueOf(value); rv.Kind() {
44+
case reflect.Chan, reflect.Func, reflect.Interface,
45+
reflect.Map, reflect.Pointer, reflect.Slice:
46+
if rv.IsNil() {
47+
return retainedContext{}
48+
}
49+
default:
50+
// Non-nilable kinds (struct, int, string, ...) cannot be typed-nil;
51+
// fall through to wrap the value as-is.
52+
}
53+
return retainedContext{value: value, ok: true}
3654
}
3755

3856
// privateLog logs a message at a given level log the default logger.
@@ -259,7 +277,13 @@ func (l *defaultLogger) writeContext(buf Buffer) {
259277
defer bytebufferpool.Put(scratch)
260278

261279
if err := tmpl.Execute(scratch, l.ctx.value, &ContextData{}); err != nil {
262-
_, _ = fmt.Fprintf(buf, "[ctx-render-error: %s] ", err.Error())
280+
// The error string can carry CR/LF/ANSI bytes derived from request data
281+
// (e.g. when a tag wraps an upstream parsing error around a header). Run
282+
// it through the same sanitiser the ${value:KEY} renderer uses so a
283+
// misconfigured tag cannot become a log-injection vector.
284+
_, _ = buf.WriteString("[ctx-render-error: ") //nolint:errcheck // best-effort marker
285+
_, _ = writeSanitizedString(buf, err.Error()) //nolint:errcheck // best-effort marker
286+
_, _ = buf.WriteString("] ") //nolint:errcheck // best-effort marker
263287
return
264288
}
265289

log/default_test.go

Lines changed: 42 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ import (
88
"log"
99
"os"
1010
"runtime"
11+
"strings"
1112
"testing"
1213

1314
"github.com/stretchr/testify/require"
@@ -96,14 +97,17 @@ func Test_WithContextNilCaller(t *testing.T) {
9697

9798
// Test_WithContextRenderError locks in M8: a misconfigured context tag must
9899
// not silently drop context — the failure should leave a visible marker in
99-
// the log line so operators notice. Calls initDefaultLogger up front because
100-
// under -shuffle=on this test may run before any other log test, in which
101-
// case the package-global logger.stdlog could still be nil.
100+
// the log line so operators notice. The error message is also sanitized for
101+
// control bytes so a tag that wraps attacker-controlled data in its error
102+
// cannot inject CR/LF into the log stream. Calls initDefaultLogger up front
103+
// because under -shuffle=on this test may run before any other log test, in
104+
// which case the package-global logger.stdlog could still be nil.
102105
func Test_WithContextRenderError(t *testing.T) {
103106
initDefaultLogger()
104107
t.Cleanup(initDefaultLogger)
105108

106-
templateErr := errors.New("tag boom")
109+
// Embed CR/LF in the error to exercise the sanitiser.
110+
templateErr := errors.New("tag\r\nboom")
107111
require.NoError(t, SetContextTemplate(ContextConfig{
108112
Format: "[${broken}] ",
109113
CustomTags: map[string]ContextTagFunc{
@@ -122,6 +126,40 @@ func Test_WithContextRenderError(t *testing.T) {
122126
out := string(w.b)
123127
require.Contains(t, out, "ctx-render-error", "expected render-error marker, got %q", out)
124128
require.Contains(t, out, "payload", "expected payload to still be emitted, got %q", out)
129+
require.NotContains(t, out, "\r", "CR in error message must be sanitized")
130+
// One trailing newline from log.Output is expected; reject any embedded ones.
131+
require.Equal(t, 1, strings.Count(out, "\n"), "embedded LF in error message must be sanitized; got %q", out)
132+
}
133+
134+
// Test_NewRetainedContext_TypedNil locks in the reflect-based nil detection
135+
// in newRetainedContext: a typed-nil pointer wrapped in `any` must be treated
136+
// as "no context" so tag renderers don't fault on a nil receiver.
137+
func Test_NewRetainedContext_TypedNil(t *testing.T) {
138+
t.Parallel()
139+
140+
type fakeCtx struct{}
141+
var typedNil *fakeCtx
142+
143+
tests := []struct {
144+
value any
145+
name string
146+
want bool
147+
}{
148+
{name: "untyped nil", value: nil, want: false},
149+
{name: "typed nil pointer", value: typedNil, want: false},
150+
{name: "typed nil map", value: map[string]string(nil), want: false},
151+
{name: "typed nil slice", value: []byte(nil), want: false},
152+
{name: "typed nil chan", value: chan int(nil), want: false},
153+
{name: "non-nil pointer", value: &fakeCtx{}, want: true},
154+
{name: "string", value: "context", want: true},
155+
{name: "non-nil map", value: map[string]string{"k": "v"}, want: true},
156+
}
157+
for _, tt := range tests {
158+
t.Run(tt.name, func(t *testing.T) {
159+
t.Parallel()
160+
require.Equal(t, tt.want, newRetainedContext(tt.value).ok)
161+
})
162+
}
125163
}
126164

127165
func Test_DefaultLogger(t *testing.T) {

middleware/basicauth/basicauth.go

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -116,6 +116,17 @@ func New(config ...Config) fiber.Handler {
116116
}
117117
}
118118

119+
// registerLogContextTags exposes the authenticated username under the
120+
// ${username} tag for both middleware/logger access logs and fiberlog
121+
// WithContext lines. The full clear-text username is intentionally written
122+
// (not redacted) because the primary use case for ${username} is auditability:
123+
// who hit which endpoint, when. Username strings have already passed
124+
// containsCTL stripping, so they are safe with respect to log injection.
125+
//
126+
// If full usernames are PII in your jurisdiction (GDPR, CCPA, etc.), do not
127+
// include ${username} in your log format and obtain the value via
128+
// UsernameFromContext at the application layer where you can hash, prefix,
129+
// or otherwise minimize it before emitting.
119130
func registerLogContextTags() {
120131
logger.RegisterContextTag("username", UsernameFromContext)
121132
}

middleware/csrf/csrf.go

Lines changed: 5 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,7 @@ import (
1414

1515
"github.com/gofiber/fiber/v3"
1616
"github.com/gofiber/fiber/v3/extractors"
17+
"github.com/gofiber/fiber/v3/internal/redact"
1718
"github.com/gofiber/fiber/v3/middleware/logger"
1819
)
1920

@@ -229,10 +230,10 @@ func New(config ...Config) fiber.Handler {
229230

230231
func registerLogContextTags() {
231232
logger.RegisterContextTag("csrf-token", func(ctx any) string {
232-
if TokenFromContext(ctx) == "" {
233-
return ""
234-
}
235-
return redactedKey
233+
// redact.Prefix matches the masking shape used by keyauth and session
234+
// (4-byte clear prefix + "****"), so log consumers see a uniform
235+
// redaction format across the framework's security-sensitive tags.
236+
return redact.Prefix(TokenFromContext(ctx))
236237
})
237238
}
238239

middleware/csrf/csrf_test.go

Lines changed: 9 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -7,13 +7,16 @@ import (
77
"net"
88
"net/http"
99
"net/http/httptest"
10+
"regexp"
11+
"strconv"
1012
"strings"
1113
"testing"
1214
"time"
1315

1416
"github.com/gofiber/fiber/v3"
1517
"github.com/gofiber/fiber/v3/extractors"
1618
"github.com/gofiber/fiber/v3/internal/loggertest"
19+
"github.com/gofiber/fiber/v3/internal/redact"
1720
fiberlog "github.com/gofiber/fiber/v3/log"
1821
"github.com/gofiber/fiber/v3/middleware/logger"
1922
"github.com/gofiber/fiber/v3/middleware/session"
@@ -652,7 +655,11 @@ func Test_CSRFLoggerTagRedactsToken(t *testing.T) {
652655
resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", http.NoBody))
653656
require.NoError(t, err)
654657
require.Equal(t, fiber.StatusOK, resp.StatusCode)
655-
require.Equal(t, redactedKey, buf.String())
658+
// CSRF tokens are randomly generated per request, so assert on the
659+
// redaction shape (4-byte prefix + Mask) rather than a fixed value.
660+
got := buf.String()
661+
require.Len(t, got, redact.PrefixLength+len(redact.Mask))
662+
require.True(t, strings.HasSuffix(got, redact.Mask), "expected suffix %q in %q", redact.Mask, got)
656663
}
657664

658665
// Test_CSRFLogContextTagRedactsToken runs serially because it mutates
@@ -670,7 +677,7 @@ func Test_CSRFLogContextTagRedactsToken(t *testing.T) {
670677
resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", http.NoBody))
671678
require.NoError(t, err)
672679
require.Equal(t, fiber.StatusOK, resp.StatusCode)
673-
require.Contains(t, buf.String(), "[Info] csrf-token="+redactedKey+" start")
680+
require.Regexp(t, `\[Info\] csrf-token=.{`+strconv.Itoa(redact.PrefixLength)+`}`+regexp.QuoteMeta(redact.Mask)+` start`, buf.String())
674681
}
675682

676683
func Test_CSRF_From_Form(t *testing.T) {

0 commit comments

Comments
 (0)