From 6ee95e4bfbaada6b46f5967a149d1fed4134093d Mon Sep 17 00:00:00 2001 From: Rogee Date: Sat, 10 Oct 2026 01:15:40 +0800 Subject: [PATCH] fix: redact free-text credentials and observe readable HTTP bodies --- go.mod | 2 +- internal/logging/http.go | 12 ++- internal/logging/logging.go | 16 ++- internal/logging/redact.go | 45 +++++++- internal/logging/text.go | 136 +++++++++++++++++++++++++ internal/logging/text_security_test.go | 106 +++++++++++++++++++ 6 files changed, 308 insertions(+), 9 deletions(-) create mode 100644 internal/logging/text.go create mode 100644 internal/logging/text_security_test.go diff --git a/go.mod b/go.mod index 9a6c6e5..73026ce 100644 --- a/go.mod +++ b/go.mod @@ -20,6 +20,7 @@ require ( github.com/sirupsen/logrus v1.9.4 github.com/spf13/cobra v1.10.1 github.com/zaf/g711 v1.4.0 + golang.org/x/net v0.58.0 golang.org/x/sys v0.47.0 google.golang.org/genproto/googleapis/rpc v0.0.0-20260526163538-3dc84a4a5aaa google.golang.org/grpc v1.83.2 @@ -55,7 +56,6 @@ require ( github.com/tklauser/go-sysconf v0.3.16 // indirect github.com/tklauser/numcpus v0.11.0 // 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/text v0.41.0 // indirect golang.org/x/time v0.4.0 // indirect diff --git a/internal/logging/http.go b/internal/logging/http.go index 4d5ffeb..5c5fc63 100644 --- a/internal/logging/http.go +++ b/internal/logging/http.go @@ -100,6 +100,7 @@ type observedBody struct { message string attrs []any collect bool + text bool mu sync.Mutex data bytes.Buffer count int64 @@ -110,11 +111,14 @@ type observedBody struct { func newObservedBody(ctx context.Context, source io.ReadCloser, contentType, message string, attrs ...any) *observedBody { media, _, err := mime.ParseMediaType(contentType) 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" if isJSON { 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) { 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 // EOF. Log observed bytes without claiming a complete wire body; malformed // 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() } diff --git a/internal/logging/logging.go b/internal/logging/logging.go index 6c3f4f8..90098ac 100644 --- a/internal/logging/logging.go +++ b/internal/logging/logging.go @@ -104,11 +104,23 @@ func Body(ctx context.Context, message string, body []byte, attrs ...any) { return } 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 { attrs = append(attrs, "redaction_error", err.Error(), "body", "[OMITTED: unsafe or invalid JSON]") } else { - attrs = append(attrs, "body", safe, "body_encoding", "json") + attrs = append(attrs, "body", safe, "body_encoding", encoding) } slog.DebugContext(ctx, message, attrs...) } diff --git a/internal/logging/redact.go b/internal/logging/redact.go index 0682a49..b7e8a3f 100644 --- a/internal/logging/redact.go +++ b/internal/logging/redact.go @@ -11,6 +11,7 @@ import ( "sort" "strings" "unicode" + "unicode/utf8" ) const redacted = "[REDACTED]" @@ -139,9 +140,12 @@ func RedactJSON(body []byte) (string, error) { } var ( - urlInText = regexp.MustCompile(`(?:https?|wss?)://[^\s<>"']+`) - 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,;"']+)`) + urlInText = regexp.MustCompile(`(?:https?|wss?)://[^\s<>"']+`) + authHeaderInText = regexp.MustCompile(`(?im)\b(?:proxy-authorization|authorization|set-cookie|cookie)["']?\s*[=:]\s*[^\r\n]+`) + 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. @@ -180,7 +184,18 @@ func redactErrorJSON(s string) string { } func cleanString(s string) string { + s = privatePEMInText.ReplaceAllString(s, redacted) 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 { u, err := url.Parse(raw) if err != nil { @@ -195,7 +210,29 @@ func cleanString(s string) string { return raw }) 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 { diff --git a/internal/logging/text.go b/internal/logging/text.go new file mode 100644 index 0000000..b84887c --- /dev/null +++ b/internal/logging/text.go @@ -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, "") +} diff --git a/internal/logging/text_security_test.go b/internal/logging/text_security_test.go new file mode 100644 index 0000000..dc787d3 --- /dev/null +++ b/internal/logging/text_security_test.go @@ -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 + }{ + {`readyprivate-markup-keyprivate-markup-prompt27`, "27", []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) + } + } +}