From f792de815ad66ec1819046d0c1906057e71168a4 Mon Sep 17 00:00:00 2001 From: Lukasz Raczylo Date: Fri, 14 Aug 2026 00:01:44 +0100 Subject: [PATCH] fix(logging): bound truncateUTF8 backoff and mask secrets that straddle the cut truncateUTF8 validated the whole string each iteration. One invalid byte emptied the log line at quadratic cost. A secret whose closing quote fell past the truncation cut also leaked its leading characters, because the redaction pattern needs a terminator. Back off over the last rune only, bounded by the maximum rune width, and trim the partial rune before redaction runs. Strip a trailing unterminated quoted value after the cut. --- proxy_logging_security_test.go | 135 +++++++++++++++++++++++++++++++++ sanitization.go | 66 ++++++++++++++-- 2 files changed, 195 insertions(+), 6 deletions(-) diff --git a/proxy_logging_security_test.go b/proxy_logging_security_test.go index 657acd7..73cfbe6 100644 --- a/proxy_logging_security_test.go +++ b/proxy_logging_security_test.go @@ -649,3 +649,138 @@ func (suite *ProxyLoggingSecurityTestSuite) TestTruncateUTF8RuneBoundary() { suite.T().Fatalf("expected backoff to %d bytes, got %d", MaxLogBodySize-1, len(out)) } } + +// TestTruncateUTF8 covers the truncateUTF8 backoff logic directly: it must +// never validate the whole string (that emptied any body with a single +// invalid byte anywhere), and it must stay O(1) backoff bounded by +// utf8.UTFMax-1, not O(n) whole-string re-validation per byte removed. +func (suite *ProxyLoggingSecurityTestSuite) TestTruncateUTF8() { + const limit = 100 + + tests := []struct { + name string + input string + maxBytes int + checkFunc func(t *testing.T, out string) + }{ + { + name: "multi-byte rune straddling the cut is backed off, not split", + input: strings.Repeat("a", limit-1) + "界", // 界 is 3 bytes, starts at limit-1 + maxBytes: limit, + checkFunc: func(t *testing.T, out string) { + if !utf8.ValidString(out) { + t.Fatalf("output is not valid UTF-8: %x", out) + } + if out != strings.Repeat("a", limit-1) { + t.Fatalf("expected the partial rune dropped entirely, got %q", out) + } + }, + }, + { + name: "invalid byte early in the string cuts near the limit, not to empty", + input: strings.Repeat("a", limit-1) + string([]byte{0x80}) + strings.Repeat("b", 500), + maxBytes: limit, + checkFunc: func(t *testing.T, out string) { + if out == "" { + t.Fatalf("truncateUTF8 emptied a string with a single stray invalid byte") + } + if len(out) < limit-utf8.UTFMax { + t.Fatalf("expected cut near the %d-byte limit, got %d bytes: %q", limit, len(out), out) + } + }, + }, + { + name: "pure ASCII is cut exactly at maxBytes, unchanged behavior", + input: strings.Repeat("x", 500), + maxBytes: limit, + checkFunc: func(t *testing.T, out string) { + if len(out) != limit { + t.Fatalf("expected exact cut at %d bytes, got %d", limit, len(out)) + } + if out != strings.Repeat("x", limit) { + t.Fatalf("unexpected ASCII truncation result: %q", out) + } + }, + }, + { + name: "string shorter than maxBytes is returned unchanged", + input: "short string", + maxBytes: limit, + checkFunc: func(t *testing.T, out string) { + if out != "short string" { + t.Fatalf("expected input unchanged, got %q", out) + } + }, + }, + } + + for _, tt := range tests { + suite.Run(tt.name, func() { + out := truncateUTF8(tt.input, tt.maxBytes) + tt.checkFunc(suite.T(), out) + }) + } +} + +// TestTruncateUTF8NotQuadratic guards the O(n^2) regression: truncating a +// body that is invalid UTF-8 overall (one stray byte, otherwise huge) must +// stay fast and must not collapse the result to empty. +func (suite *ProxyLoggingSecurityTestSuite) TestTruncateUTF8NotQuadratic() { + body := string([]byte{0x80}) + strings.Repeat("a", MaxLogBodySize*10) + out := truncateUTF8(body, MaxLogBodySize) + if len(out) == 0 { + suite.T().Fatalf("truncateUTF8 collapsed an otherwise-valid large body to empty") + } + if len(out) < MaxLogBodySize-utf8.UTFMax { + suite.T().Fatalf("expected cut near %d bytes, got %d", MaxLogBodySize, len(out)) + } +} + +// TestSanitizeTruncatedBodySecretStraddlingCutNotExposed verifies that a +// sensitive field value whose closing quote falls past the MaxLogBodySize +// cut point (so the "field":"value" redaction regex cannot match it) is +// still not leaked in the truncated log line. +func (suite *ProxyLoggingSecurityTestSuite) TestSanitizeTruncatedBodySecretStraddlingCutNotExposed() { + secret := "S3cretStraddle-" + strings.Repeat("Z", 100) + head := strings.Repeat("x", MaxLogBodySize-50) + body := head + `"password": "` + secret + `"}` + suite.Greater(len(body), MaxLogBodySize, "test body must exceed MaxLogBodySize to hit the truncation path") + + // Sanity check: the opening quote of the secret value must land before + // the cut, and the closing quote after it, so the value straddles it. + openIdx := strings.Index(body, secret) + suite.Less(openIdx, MaxLogBodySize, "secret must start before the cut") + suite.Greater(openIdx+len(secret), MaxLogBodySize, "secret must extend past the cut") + + result := sanitizeForLogging([]byte(body), "text/plain") + + suite.NotContains(result, secret, "full secret leaked") + suite.NotContains(result, "S3cretStraddle", "partial secret prefix leaked") + suite.True(utf8.ValidString(result), "result must be valid UTF-8") + suite.True(strings.HasSuffix(result, TruncatedSuffix), "result must carry the truncated suffix") +} + +// TestSanitizeTruncatedBodyTrimsPartialRuneOnPlainBody verifies the +// rune-boundary trim in sanitizeTruncatedBody runs on the raw +// body[:MaxLogBodySize] cut, not only in the final truncateUTF8 call. The +// body here is plain non-JSON UTF-8 prose with no quotes and no sensitive +// field names, so redactPatternInString/stripTrailingUnterminatedQuote +// cannot match anything and cannot shrink the prefix: by the time the final +// truncateUTF8 safety-net call runs, len(prefix) is already <= +// MaxLogBodySize, so its len-guard makes it a no-op. Only trimming the raw +// cut up front (before redaction) can remove the multi-byte rune straddling +// byte MaxLogBodySize here. +func (suite *ProxyLoggingSecurityTestSuite) TestSanitizeTruncatedBodyTrimsPartialRuneOnPlainBody() { + // "界" is 3 bytes and starts at byte MaxLogBodySize-1, so it straddles + // the cut point exactly like TestTruncateUTF8RuneBoundary's input, but + // driven through the full sanitizeForLogging -> sanitizeTruncatedBody + // path instead of calling truncateUTF8 directly. + body := strings.Repeat("a", MaxLogBodySize-1) + "界" + strings.Repeat("b", 200) + suite.Greater(len(body), MaxLogBodySize, "test body must exceed MaxLogBodySize to hit the truncation path") + + result := sanitizeForLogging([]byte(body), "text/plain") + + suite.True(utf8.ValidString(result), "result must be valid UTF-8") + suite.True(strings.HasSuffix(result, TruncatedSuffix), "result must carry the truncated suffix") + suite.NotContains(result, "界", "a split multi-byte rune must not survive truncation") +} diff --git a/sanitization.go b/sanitization.go index bd71019..7aafdfe 100644 --- a/sanitization.go +++ b/sanitization.go @@ -120,24 +120,78 @@ func sanitizeForLogging(body []byte, contentType string) string { } // sanitizeTruncatedBody redacts sensitive fields within the first -// MaxLogBodySize bytes of a large body, then truncates on a UTF-8 rune -// boundary, so a truncated log line is both masked and decodable. +// MaxLogBodySize bytes of a large body, strips any dangling quoted value +// left at the tail (a secret whose closing quote fell past the cut, so the +// "field":"value" redaction regexes above could not match it), then +// truncates on a UTF-8 rune boundary, so a truncated log line is both +// masked and decodable. +// +// The rune-boundary trim runs on the raw body[:MaxLogBodySize] cut BEFORE +// redaction, not only in the final truncateUTF8 safety-net call. Redaction +// usually shrinks the prefix (a long value collapses to "[REDACTED]"), so on +// the common path len(prefix) is already <= MaxLogBodySize by the time +// truncateUTF8 runs at the end - its len-guard then makes it a no-op and it +// can no longer back off a multi-byte rune split by the byte-oriented cut. +// Trimming the raw cut up front is what actually guarantees the result ends +// on a rune boundary; the final truncateUTF8 call stays as a safety net for +// the rarer case where redaction grows the prefix back past MaxLogBodySize +// (e.g. the XML-match branch in redactPatternInString appends a trailing +// "field=[REDACTED]" marker). func sanitizeTruncatedBody(body []byte) string { - prefix := string(body[:MaxLogBodySize]) + prefix := trimPartialTrailingRune(string(body[:MaxLogBodySize])) for _, field := range sensitiveFieldPatterns { prefix = redactPatternInString(prefix, field) } + prefix = stripTrailingUnterminatedQuote(prefix) return truncateUTF8(prefix, MaxLogBodySize) + TruncatedSuffix } +// stripTrailingUnterminatedQuote drops a dangling, unterminated quoted value +// left at the end of a byte-truncated prefix. redactPatternInString's +// "field":"value" regexes require a closing quote to match, so a secret +// whose closing quote falls past the truncation point is never redacted and +// its leading bytes would otherwise leak. An odd count of a quote character +// means the tail sits inside an unterminated span for that quote style, so +// the dangling opening quote and everything after it are dropped. +func stripTrailingUnterminatedQuote(s string) string { + if strings.Count(s, `"`)%2 == 1 { + if i := strings.LastIndexByte(s, '"'); i >= 0 { + s = s[:i] + } + } + if strings.Count(s, `'`)%2 == 1 { + if i := strings.LastIndexByte(s, '\''); i >= 0 { + s = s[:i] + } + } + return s +} + // truncateUTF8 truncates s to at most maxBytes on a UTF-8 rune boundary. +// It only backs off a partial multi-byte rune split at the cut point (at +// most utf8.UTFMax-1 bytes). A string that is already invalid UTF-8 for +// reasons other than a split trailing rune is returned cut at maxBytes as +// is, not stripped down to empty. func truncateUTF8(s string, maxBytes int) string { if len(s) <= maxBytes { return s } - s = s[:maxBytes] - for len(s) > 0 && !utf8.ValidString(s) { - // Back off one byte at a time up to the lead of a partial rune. + return trimPartialTrailingRune(s[:maxBytes]) +} + +// trimPartialTrailingRune backs off at most utf8.UTFMax-1 bytes from the end +// of s to remove a multi-byte UTF-8 rune split by a byte-oriented cut, so +// the result ends on a rune boundary. Unlike truncateUTF8, it has no +// len(s) <= maxBytes guard, because it is meant to run on a string that has +// already been cut to its target length (e.g. body[:MaxLogBodySize]) - a +// guarded call would see len(s) already at the target and no-op, leaving +// the split rune's leading bytes in place. +func trimPartialTrailingRune(s string) string { + for backedOff := 0; backedOff < utf8.UTFMax-1 && len(s) > 0; backedOff++ { + r, size := utf8.DecodeLastRuneInString(s) + if r != utf8.RuneError || size != 1 { + break + } s = s[:len(s)-1] } return s