fix: redact free-text credentials and observe readable HTTP bodies

This commit is contained in:
2026-10-10 01:15:40 +08:00
parent 56fd1e11cf
commit 6ee95e4bfb
6 changed files with 308 additions and 9 deletions
+1 -1
View File
@@ -20,6 +20,7 @@ require (
github.com/sirupsen/logrus v1.9.4 github.com/sirupsen/logrus v1.9.4
github.com/spf13/cobra v1.10.1 github.com/spf13/cobra v1.10.1
github.com/zaf/g711 v1.4.0 github.com/zaf/g711 v1.4.0
golang.org/x/net v0.58.0
golang.org/x/sys v0.47.0 golang.org/x/sys v0.47.0
google.golang.org/genproto/googleapis/rpc v0.0.0-20260526163538-3dc84a4a5aaa google.golang.org/genproto/googleapis/rpc v0.0.0-20260526163538-3dc84a4a5aaa
google.golang.org/grpc v1.83.2 google.golang.org/grpc v1.83.2
@@ -55,7 +56,6 @@ require (
github.com/tklauser/go-sysconf v0.3.16 // indirect github.com/tklauser/go-sysconf v0.3.16 // indirect
github.com/tklauser/numcpus v0.11.0 // indirect github.com/tklauser/numcpus v0.11.0 // indirect
github.com/yusufpapurcu/wmi v1.2.4 // indirect github.com/yusufpapurcu/wmi v1.2.4 // indirect
golang.org/x/net v0.58.0 // indirect
golang.org/x/sync v0.22.0 // indirect golang.org/x/sync v0.22.0 // indirect
golang.org/x/text v0.41.0 // indirect golang.org/x/text v0.41.0 // indirect
golang.org/x/time v0.4.0 // indirect golang.org/x/time v0.4.0 // indirect
+10 -2
View File
@@ -100,6 +100,7 @@ type observedBody struct {
message string message string
attrs []any attrs []any
collect bool collect bool
text bool
mu sync.Mutex mu sync.Mutex
data bytes.Buffer data bytes.Buffer
count int64 count int64
@@ -110,11 +111,14 @@ type observedBody struct {
func newObservedBody(ctx context.Context, source io.ReadCloser, contentType, message string, attrs ...any) *observedBody { func newObservedBody(ctx context.Context, source io.ReadCloser, contentType, message string, attrs ...any) *observedBody {
media, _, err := mime.ParseMediaType(contentType) media, _, err := mime.ParseMediaType(contentType)
isJSON := err == nil && (media == "application/json" || strings.HasSuffix(media, "+json")) isJSON := err == nil && (media == "application/json" || strings.HasSuffix(media, "+json"))
isText := err == nil && (strings.HasPrefix(media, "text/") || media == "application/xml" || strings.HasSuffix(media, "+xml") || media == "application/x-www-form-urlencoded")
mode := "binary_omitted" mode := "binary_omitted"
if isJSON { if isJSON {
mode = "json" mode = "json"
} else if isText {
mode = "text"
} }
return &observedBody{source: source, ctx: ctx, message: message, attrs: append(append([]any{}, attrs...), "content_type", contentType, "body_mode", mode), collect: isJSON && slog.Default().Enabled(ctx, slog.LevelDebug), started: time.Now()} return &observedBody{source: source, ctx: ctx, message: message, attrs: append(append([]any{}, attrs...), "content_type", contentType, "body_mode", mode), collect: (isJSON || isText) && slog.Default().Enabled(ctx, slog.LevelDebug), text: isText && !isJSON, started: time.Now()}
} }
func (r *observedBody) Read(p []byte) (int, error) { func (r *observedBody) Read(p []byte) (int, error) {
n, err := r.source.Read(p) n, err := r.source.Read(p)
@@ -160,7 +164,11 @@ func (r *observedBody) finishLocked(complete bool, err error) {
// A decoder may close after consuming a valid JSON value without reading // A decoder may close after consuming a valid JSON value without reading
// EOF. Log observed bytes without claiming a complete wire body; malformed // EOF. Log observed bytes without claiming a complete wire body; malformed
// prefixes still produce an explicit safe redaction diagnostic. // prefixes still produce an explicit safe redaction diagnostic.
Body(r.ctx, r.message, r.data.Bytes(), append(attrs, "body_complete", complete)...) if r.text {
TextBody(r.ctx, r.message, r.data.Bytes(), append(attrs, "body_complete", complete)...)
} else {
Body(r.ctx, r.message, r.data.Bytes(), append(attrs, "body_complete", complete)...)
}
} }
r.data.Reset() r.data.Reset()
} }
+14 -2
View File
@@ -104,11 +104,23 @@ func Body(ctx context.Context, message string, body []byte, attrs ...any) {
return return
} }
attrs = append(append([]any{}, attrs...), "body_bytes", len(body), "body_sha256", fmt.Sprintf("%x", sha256.Sum256(body))) attrs = append(append([]any{}, attrs...), "body_bytes", len(body), "body_sha256", fmt.Sprintf("%x", sha256.Sum256(body)))
safe, err := RedactJSON(body) logObservedBody(ctx, message, body, "json", RedactJSON, attrs...)
}
func TextBody(ctx context.Context, message string, body []byte, attrs ...any) {
if !slog.Default().Enabled(ctx, slog.LevelDebug) {
return
}
attrs = append(append([]any{}, attrs...), "body_bytes", len(body), "body_sha256", fmt.Sprintf("%x", sha256.Sum256(body)))
logObservedBody(ctx, message, body, "utf-8", RedactText, attrs...)
}
func logObservedBody(ctx context.Context, message string, body []byte, encoding string, redact func([]byte) (string, error), attrs ...any) {
safe, err := redact(body)
if err != nil { if err != nil {
attrs = append(attrs, "redaction_error", err.Error(), "body", "[OMITTED: unsafe or invalid JSON]") attrs = append(attrs, "redaction_error", err.Error(), "body", "[OMITTED: unsafe or invalid JSON]")
} else { } else {
attrs = append(attrs, "body", safe, "body_encoding", "json") attrs = append(attrs, "body", safe, "body_encoding", encoding)
} }
slog.DebugContext(ctx, message, attrs...) slog.DebugContext(ctx, message, attrs...)
} }
+41 -4
View File
@@ -11,6 +11,7 @@ import (
"sort" "sort"
"strings" "strings"
"unicode" "unicode"
"unicode/utf8"
) )
const redacted = "[REDACTED]" const redacted = "[REDACTED]"
@@ -139,9 +140,12 @@ func RedactJSON(body []byte) (string, error) {
} }
var ( var (
urlInText = regexp.MustCompile(`(?:https?|wss?)://[^\s<>"']+`) urlInText = regexp.MustCompile(`(?:https?|wss?)://[^\s<>"']+`)
bearerInText = regexp.MustCompile(`(?i)\bBearer\s+[^\s,;"']+`) authHeaderInText = regexp.MustCompile(`(?im)\b(?:proxy-authorization|authorization|set-cookie|cookie)["']?\s*[=:]\s*[^\r\n]+`)
secretInText = regexp.MustCompile(`(?i)\b(api[_-]?key|private[_-]?key(?:[_-]?pem)?|client[_-]?key(?:[_-]?pem)?|access[_-]?key[_-]?(secret|id)|password|token|secret|signature|prompt|system[_-]?prompt|content|transcript|text)["']?\s*[=:]\s*(?:"(?:\\.|[^"\\])*"|'(?:\\.|[^'\\])*'|[^\s,;"']+)`) privatePEMInText = regexp.MustCompile(`(?s)-----BEGIN [A-Z0-9 ]*PRIVATE KEY-----.*?(?:-----END [A-Z0-9 ]*PRIVATE KEY-----|$)`)
sensitiveTextLine = regexp.MustCompile(`(?im)\b(?:prompt|system[_-]?prompt|messages|transcript|text|content|audio|closing[_-]?remark)\s*[=:]\s*[^\r\n]+`)
bearerInText = regexp.MustCompile(`(?i)\bBearer\s+[^\s,;"']+`)
secretInText = regexp.MustCompile(`(?i)\b(api[_-]?key|private[_-]?key(?:[_-]?pem)?|client[_-]?key(?:[_-]?pem)?|access[_-]?key[_-]?(secret|id)|password|token|secret|signature|prompt|system[_-]?prompt|content|transcript|text)["']?\s*[=:]\s*(?:"(?:\\.|[^"\\])*"|'(?:\\.|[^'\\])*'|[^\s,;"']+)`)
) )
// Error messages can contain a provider's JSON response after a text prefix. // Error messages can contain a provider's JSON response after a text prefix.
@@ -180,7 +184,18 @@ func redactErrorJSON(s string) string {
} }
func cleanString(s string) string { func cleanString(s string) string {
s = privatePEMInText.ReplaceAllString(s, redacted)
s = redactErrorJSON(s) s = redactErrorJSON(s)
s = authHeaderInText.ReplaceAllStringFunc(s, func(header string) string {
index := strings.IndexAny(header, ":=")
if index >= 0 {
value := strings.TrimSpace(header[index+1:])
if strings.HasPrefix(value, `"[REDACTED]"`) || strings.HasPrefix(value, redacted) {
return header
}
}
return "[REDACTED_AUTH_HEADER]"
})
s = urlInText.ReplaceAllStringFunc(s, func(raw string) string { s = urlInText.ReplaceAllStringFunc(s, func(raw string) string {
u, err := url.Parse(raw) u, err := url.Parse(raw)
if err != nil { if err != nil {
@@ -195,7 +210,29 @@ func cleanString(s string) string {
return raw return raw
}) })
s = bearerInText.ReplaceAllString(s, "Bearer "+redacted) s = bearerInText.ReplaceAllString(s, "Bearer "+redacted)
return secretInText.ReplaceAllString(s, "$1="+redacted) s = secretInText.ReplaceAllString(s, "$1="+redacted)
return s
}
// RedactText is used only for readable textual HTTP content. JSON objects
// inside free text use structural redaction; labelled conversational lines are
// excluded while unrelated business lines and original bytes stay untouched.
func RedactText(body []byte) (string, error) {
if !utf8.Valid(body) {
return "", errors.New("HTTP text is not valid UTF-8")
}
for _, r := range string(body) {
if unicode.IsControl(r) && r != '\n' && r != '\r' && r != '\t' {
return "", errors.New("HTTP content contains binary control data")
}
}
safe := redactMarkup(string(body))
if form, ok := redactForm(safe); ok {
return form, nil
}
safe = cleanString(redactConversationLines(safe))
safe = sensitiveTextLine.ReplaceAllString(safe, "[REDACTED_CONVERSATION]")
return safe, nil
} }
func safeValue(key string, v any) any { func safeValue(key string, v any) any {
+136
View File
@@ -0,0 +1,136 @@
package logging
import (
"bytes"
"io"
"net/url"
"regexp"
"strings"
"golang.org/x/net/html"
)
// The HTML tokenizer also accepts XML-shaped response fragments. Raw token
// bytes are retained; only explicitly sensitive tags/attributes are replaced.
func redactMarkup(body string) string {
if !strings.Contains(body, "<") {
return body
}
z := html.NewTokenizer(strings.NewReader(body))
var out strings.Builder
hiddenTag := ""
depth := 0
for {
kind := z.Next()
raw := bytes.Clone(z.Raw())
if kind == html.ErrorToken {
if z.Err() == io.EOF {
out.Write(raw)
}
break
}
token := z.Token()
if hiddenTag != "" {
if kind == html.StartTagToken && token.Data == hiddenTag {
depth++
}
if kind == html.EndTagToken && token.Data == hiddenTag {
depth--
if depth == 0 {
hiddenTag = ""
out.Write(raw)
}
}
continue
}
if kind == html.StartTagToken || kind == html.SelfClosingTagToken {
tag := string(raw)
hideValue := false
for _, a := range token.Attr {
if (a.Key == "name" && sensitive(a.Val)) || (a.Key == "type" && strings.EqualFold(a.Val, "password")) {
hideValue = true
}
}
for _, a := range token.Attr {
if sensitive(a.Key) || (hideValue && a.Key == "value") {
pattern := regexp.MustCompile(`(?i)(\b` + regexp.QuoteMeta(a.Key) + `\s*=\s*)(?:"[^"]*"|'[^']*'|[^\s>]+)`)
tag = pattern.ReplaceAllString(tag, `${1}"[REDACTED]"`)
}
}
out.WriteString(tag)
if kind == html.StartTagToken && sensitive(token.Data) {
out.WriteString(redacted)
hiddenTag = token.Data
depth = 1
}
} else {
out.Write(raw)
}
}
return out.String()
}
// A form can be identified without guessing semantic values. Untouched pairs
// preserve their original encoding and order, including duplicate field names.
func redactForm(body string) (string, bool) {
if strings.ContainsAny(body, "\r\n<>") || !strings.Contains(body, "&") || !strings.Contains(body, "=") {
return body, false
}
parts := strings.Split(body, "&")
for i, part := range parts {
key, value, ok := strings.Cut(part, "=")
if !ok {
return body, false
}
decodedKey, err := url.QueryUnescape(key)
if err != nil {
return body, false
}
if sensitive(decodedKey) {
parts[i] = key + "=" + url.QueryEscape(redacted)
continue
}
decoded, err := url.QueryUnescape(value)
if err != nil {
return body, false
}
safe := cleanString(redactConversationLines(decoded))
if safe != decoded {
parts[i] = key + "=" + url.QueryEscape(safe)
}
}
return strings.Join(parts, "&"), true
}
var textFieldLine = regexp.MustCompile(`^\s*([A-Za-z_][A-Za-z0-9_.-]*)\s*[:=]`)
func redactConversationLines(body string) string {
lines := strings.SplitAfter(body, "\n")
hiding := false
for i, line := range lines {
trimmed := strings.TrimSpace(line)
if hiding && trimmed == "" {
hiding = false
continue
}
field := textFieldLine.FindStringSubmatch(line)
if hiding {
// Continuation lines and conversation speaker labels are not business
// fields. A distinct non-conversation key starts the next ordinary field.
speaker := len(field) > 0 && (strings.EqualFold(field[1], "user") || strings.EqualFold(field[1], "assistant") || strings.EqualFold(field[1], "system") || strings.EqualFold(field[1], "agent"))
if len(field) == 0 || speaker {
lines[i] = ""
continue
}
hiding = false
}
if len(field) > 0 && sensitive(field[1]) {
lines[i] = "[REDACTED_FIELD]"
if strings.HasSuffix(line, "\n") {
lines[i] += "\n"
}
hiding = true
}
}
return strings.Join(lines, "")
}
+106
View File
@@ -0,0 +1,106 @@
package logging
import (
"bytes"
"errors"
"io"
"log/slog"
"net/http"
"net/http/httptest"
"strings"
"testing"
)
func TestFreeTextAuthorizationAndUnlabelledPrivatePEMAreHidden(t *testing.T) {
for _, debug := range []bool{false, true} {
out := installTestLogger(t, debug)
cause := "upstream denied\nAuthorization: Basic dXNlcjpwYXNzd29yZA==\nProxy-Authorization: Digest username=private-user, response=private-response\n-----BEGIN RSA PRIVATE KEY-----\nprivate-pem-material\n-----END RSA PRIVATE KEY-----\nretry attempt failed"
slog.Error("workflow failed", "error", errors.New(cause))
for _, secret := range []string{"dXNlcjpwYXNzd29yZA==", "private-user", "private-response", "private-pem-material"} {
if strings.Contains(out.String(), secret) {
t.Fatalf("leak %s: %s", secret, out.String())
}
}
for _, keep := range []string{"upstream denied", "retry attempt failed"} {
if !strings.Contains(out.String(), keep) {
t.Fatal("failure reason lost", out.String())
}
}
}
}
func TestJSONErrorAuthorizationDoesNotHideBusinessFields(t *testing.T) {
out := installTestLogger(t, false)
slog.Error("request failed", "error", errors.New(`denied: {"Authorization":"Basic dXNlcjpwYXNzd29yZA==","task_id":"4","reason":"quota full"}`))
text := out.String()
if strings.Contains(text, "dXNlcjpwYXNzd29yZA==") || !strings.Contains(text, "quota full") || !strings.Contains(text, "task_id") {
t.Fatal(text)
}
}
func TestReadableMarkupFormAndMultilineConversationAreSanitized(t *testing.T) {
cases := []struct {
body string
keep string
secrets []string
}{
{`<task><status>ready</status><api_key>private-markup-key</api_key><prompt>private-markup-prompt</prompt><input name="password" value="private-input-password"><count>27</count></task>`, "<count>27</count>", []string{"private-markup-key", "private-markup-prompt", "private-input-password"}},
{"status=ready&api_key=private-form-key&remaining=27", "remaining=27", []string{"private-form-key"}},
{"status=ready\nprompt:\n private-multiline-prompt\n still-private\n\nremaining=27", "remaining=27", []string{"private-multiline-prompt", "still-private"}},
}
for _, tc := range cases {
safe, err := RedactText([]byte(tc.body))
if err != nil {
t.Fatal(err)
}
if !strings.Contains(safe, tc.keep) {
t.Fatal("business content lost", safe)
}
for _, s := range tc.secrets {
if strings.Contains(safe, s) {
t.Fatalf("leaked %s: %s", s, safe)
}
}
}
}
func TestReadablePlainHTTPBodiesAreObservedSafelyWithoutChangingBytes(t *testing.T) {
body := "status=ready\ntask_id=4\nremaining=27\nAuthorization: Basic dXNlcjpwYXNzd29yZA==\napi_key=private-key\n-----BEGIN PRIVATE KEY-----\nprivate-pem-material\n-----END PRIVATE KEY-----\nretry_after=60\n" + strings.Repeat("business-data ", 12000)
for _, debug := range []bool{false, true} {
out := installTestLogger(t, debug)
server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
b, _ := io.ReadAll(r.Body)
if string(b) != body {
t.Error("request changed")
}
w.Header().Set("Content-Type", "text/plain; charset=utf-8")
io.WriteString(w, body)
}))
req, _ := http.NewRequest(http.MethodPost, server.URL, strings.NewReader(body))
req.Header.Set("Content-Type", "text/plain")
res, err := HTTPClient(server.Client(), "dispatcher", "saas").Do(req)
if err != nil {
t.Fatal(err)
}
got, err := io.ReadAll(res.Body)
res.Body.Close()
server.Close()
if err != nil || !bytes.Equal(got, []byte(body)) {
t.Fatal("response changed", err)
}
text := out.String()
for _, secret := range []string{"dXNlcjpwYXNzd29yZA==", "private-key", "private-pem-material"} {
if strings.Contains(text, secret) {
t.Fatalf("leak %s", secret)
}
}
for _, keep := range []string{"remaining=27", "retry_after=60", "business-data"} {
if strings.Contains(text, keep) != debug {
t.Fatalf("body absent/truncated or exposed in normal mode: %v %s", debug, keep)
}
}
if debug && !strings.Contains(text, `"body_encoding":"utf-8"`) {
t.Fatal("text not identified", text)
}
}
}