Skip to content
Merged
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
148 changes: 147 additions & 1 deletion httpclient/logging_improvements_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -178,7 +178,10 @@ func TestLoggingImprovements(t *testing.T) {

details := fmt.Sprintf("%v", requestEntry.KeyVals["details"])
assert.Contains(t, details, "POST", "Should show method")
assert.Contains(t, details, "Authorization", "Should show authorization header")
// The Authorization header NAME should still be visible for observability,
// but its secret VALUE must be redacted (go/clear-text-logging).
assert.Contains(t, details, "Authorization", "Should show authorization header name")
assert.NotContains(t, details, "token123", "Authorization secret value must be redacted")

case "truncated_with_content":
// Should show truncated content with [truncated] marker
Expand Down Expand Up @@ -302,3 +305,146 @@ func TestNoUselessDotDotDotLogs(t *testing.T) {
// Ensure we actually have some log entries to test
assert.GreaterOrEqual(t, len(entries), 2, "Should have generated some log entries to test")
}

// TestSensitiveHeadersRedacted verifies that Authorization and other sensitive headers are
// redacted in both request and response important_headers logging (go/clear-text-logging fix).
func TestSensitiveHeadersRedacted(t *testing.T) {
t.Parallel()

server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
w.Header().Set("Set-Cookie", "session=abc123; HttpOnly")
w.Header().Set("Authorization", "Bearer server-token") // unusual but tests redaction
w.WriteHeader(http.StatusOK)
_, _ = w.Write([]byte(`{}`))
}))
defer server.Close()

testLogger := &TestLogger{}

// Use non-detailed logging path (LogHeaders=false, LogBody=false) so the
// important_headers map is populated and can be inspected.
transport := &loggingTransport{
Transport: http.DefaultTransport,
Logger: testLogger,
LogHeaders: false,
LogBody: false,
LogToFile: false,
}
client := &http.Client{Transport: transport}

req, err := http.NewRequestWithContext(context.Background(), "GET", server.URL+"/", nil)
require.NoError(t, err)
req.Header.Set("Authorization", "Bearer secret-token-value")
req.Header.Set("Cookie", "session=hunter2")
req.Header.Set("Content-Type", "application/json")

resp, err := client.Do(req)
require.NoError(t, err)
defer resp.Body.Close()

entries := testLogger.GetEntries()
require.GreaterOrEqual(t, len(entries), 2)

// Find request entry
var reqEntry, respEntry *LogEntry
for i := range entries {
if strings.Contains(entries[i].Message, "Outgoing request") {
reqEntry = &entries[i]
}
if strings.Contains(entries[i].Message, "Received response") {
respEntry = &entries[i]
}
}

// Check request headers: Authorization and Cookie must be redacted
require.NotNil(t, reqEntry, "must have request log entry")
reqHeaders, ok := reqEntry.KeyVals["important_headers"]
require.True(t, ok, "request entry must have important_headers key")
reqHeadersStr := fmt.Sprintf("%v", reqHeaders)
assert.NotContains(t, reqHeadersStr, "secret-token-value", "Authorization value must not appear in logs")
assert.NotContains(t, reqHeadersStr, "hunter2", "Cookie value must not appear in logs")
// The key name may appear (that's fine), but the value must be masked
if strings.Contains(reqHeadersStr, "Authorization") || strings.Contains(reqHeadersStr, "authorization") {
assert.Contains(t, reqHeadersStr, "***", "masked sentinel must be present")
}

// Check response headers: Set-Cookie must be redacted
require.NotNil(t, respEntry, "must have response log entry")
respHeaders, ok := respEntry.KeyVals["important_headers"]
require.True(t, ok, "response entry must have important_headers key")
respHeadersStr := fmt.Sprintf("%v", respHeaders)
assert.NotContains(t, respHeadersStr, "abc123", "Set-Cookie value must not appear in logs")
}

// TestSensitiveHeadersRedactedInDetailedDump verifies that when detailed logging is
// enabled (LogHeaders=true), the raw HTTP dump emitted as "details" has sensitive
// header VALUES redacted while header names and the body remain intact
// (go/clear-text-logging fix for the detailed-logging path).
func TestSensitiveHeadersRedactedInDetailedDump(t *testing.T) {
t.Parallel()

server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
w.Header().Set("Set-Cookie", "session=resp-secret-cookie; HttpOnly")
w.WriteHeader(http.StatusOK)
_, _ = w.Write([]byte(`{"message": "Hello, World!"}`))
}))
defer server.Close()

testLogger := &TestLogger{}

// Detailed logging enabled: dumps the full request/response including headers.
transport := &loggingTransport{
Transport: http.DefaultTransport,
Logger: testLogger,
LogHeaders: true,
LogBody: true,
MaxBodyLogSize: 4096, // large enough to avoid truncation
LogToFile: false,
}
client := &http.Client{Transport: transport}

reqBody := bytes.NewBufferString(`{"test": "data"}`)
req, err := http.NewRequestWithContext(context.Background(), "POST", server.URL+"/api/test", reqBody)
require.NoError(t, err)
req.Header.Set("Authorization", "Bearer secret-token-value")
req.Header.Set("Cookie", "session=req-secret-cookie")
req.Header.Set("X-Api-Key", "my-api-key-secret")
req.Header.Set("Content-Type", "application/json")

resp, err := client.Do(req)
require.NoError(t, err)
defer resp.Body.Close()

entries := testLogger.GetEntries()
var reqEntry, respEntry *LogEntry
for i := range entries {
if strings.Contains(entries[i].Message, "Outgoing request") {
reqEntry = &entries[i]
}
if strings.Contains(entries[i].Message, "Received response") {
respEntry = &entries[i]
}
}

require.NotNil(t, reqEntry, "must have request log entry")
reqDetails := fmt.Sprintf("%v", reqEntry.KeyVals["details"])

// Secret VALUES must never appear in the dump.
assert.NotContains(t, reqDetails, "secret-token-value", "Authorization bearer token must be redacted in dump")
assert.NotContains(t, reqDetails, "req-secret-cookie", "Cookie value must be redacted in dump")
assert.NotContains(t, reqDetails, "my-api-key-secret", "X-Api-Key value must be redacted in dump")

// Header NAMES and the body should still be present (observability preserved).
assert.Contains(t, reqDetails, "Authorization", "Authorization header name should remain")
assert.Contains(t, reqDetails, "***", "redaction sentinel must be present")
assert.Contains(t, reqDetails, `{"test": "data"}`, "request body must be preserved")
assert.Contains(t, reqDetails, "POST /api/test HTTP/1.1", "request line must be preserved")

require.NotNil(t, respEntry, "must have response log entry")
respDetails := fmt.Sprintf("%v", respEntry.KeyVals["details"])
assert.NotContains(t, respDetails, "resp-secret-cookie", "Set-Cookie value must be redacted in dump")
assert.Contains(t, respDetails, "Set-Cookie", "Set-Cookie header name should remain")
assert.Contains(t, respDetails, `{"message": "Hello, World!"}`, "response body must be preserved")
}
95 changes: 87 additions & 8 deletions httpclient/module.go
Original file line number Diff line number Diff line change
Expand Up @@ -664,9 +664,11 @@ func (t *loggingTransport) logRequest(id string, req *http.Request) {
)
}
} else {
// Log to application logger with smart truncation
dumpStr := string(reqDump)
if t.MaxBodyLogSize > 0 && len(reqDump) > t.MaxBodyLogSize {
// Log to application logger with smart truncation.
// Redact sensitive header values in the raw dump before logging so
// Authorization/Cookie/etc. are not emitted in clear text.
dumpStr := redactDump(string(reqDump))
if t.MaxBodyLogSize > 0 && len(dumpStr) > t.MaxBodyLogSize {
// Smart truncation: try to include the request line and headers
truncated := t.smartTruncateRequest(dumpStr, t.MaxBodyLogSize)
t.Logger.Info("Outgoing request",
Expand Down Expand Up @@ -696,7 +698,7 @@ func (t *loggingTransport) logRequest(id string, req *http.Request) {
"id", id,
"request", basicInfo,
"content_length", req.ContentLength,
"important_headers", headers,
"important_headers", redactHeaders(headers),
)
}
}
Expand Down Expand Up @@ -791,9 +793,11 @@ func (t *loggingTransport) logResponse(id, url string, resp *http.Response, dura
)
}
} else {
// Log to application logger with smart truncation
dumpStr := string(respDump)
if t.MaxBodyLogSize > 0 && len(respDump) > t.MaxBodyLogSize {
// Log to application logger with smart truncation.
// Redact sensitive header values in the raw dump before logging so
// Set-Cookie/Authorization/etc. are not emitted in clear text.
dumpStr := redactDump(string(respDump))
if t.MaxBodyLogSize > 0 && len(dumpStr) > t.MaxBodyLogSize {
// Smart truncation: try to include the status line and headers
truncated := t.smartTruncateResponse(dumpStr, t.MaxBodyLogSize)
t.Logger.Info("Received response",
Expand Down Expand Up @@ -829,7 +833,7 @@ func (t *loggingTransport) logResponse(id, url string, resp *http.Response, dura
"url", url,
"duration_ms", duration.Milliseconds(),
"content_length", resp.ContentLength,
"important_headers", headers,
"important_headers", redactHeaders(headers),
)
}
}
Expand Down Expand Up @@ -944,6 +948,81 @@ func (t *loggingTransport) smartTruncateResponse(dump string, maxSize int) strin
return dump[:maxSize]
}

// sensitiveHeaderPatterns lists lowercase substrings that identify headers whose values
// must be redacted before logging (go/clear-text-logging).
var sensitiveHeaderPatterns = []string{
"authorization", "proxy-authorization", "cookie", "set-cookie",
"x-api-key", "x-auth-token", "token", "secret", "password", "apikey",
}

// isSensitiveHeader reports whether a header's value must be redacted.
func isSensitiveHeader(name string) bool {
lower := strings.ToLower(name)
for _, pat := range sensitiveHeaderPatterns {
if strings.Contains(lower, pat) {
return true
}
}
return false
}

// redactHeaders returns a new map with sensitive header values replaced by "***".
func redactHeaders(headers map[string]string) map[string]string {
redacted := make(map[string]string, len(headers))
for k, v := range headers {
if isSensitiveHeader(k) {
redacted[k] = "***"
} else {
redacted[k] = v
}
}
return redacted
}

// redactDump scrubs sensitive header values from a raw HTTP request/response dump
// (as produced by httputil.DumpRequestOut / DumpResponse) before it is logged.
// It scans the header section (everything up to the first blank line that separates
// headers from the body) line by line; for any line of the form "Name: value" whose
// header name matches isSensitiveHeader, the value is replaced with "***" while the
// header name and the rest of the dump (including the body) are left intact.
func redactDump(dump string) string {
if dump == "" {
return dump
}

// Preserve the original line endings (dumps use CRLF). Split on "\n" and
// strip a trailing "\r" per line so we can match, then re-attach it.
lines := strings.Split(dump, "\n")
for i, line := range lines {
// Stop at the blank line separating headers from the body. A blank line
// is "" or just "\r".
trimmed := strings.TrimRight(line, "\r")
if trimmed == "" {
break
}

colon := strings.Index(trimmed, ":")
if colon <= 0 {
// Request/status line (e.g. "GET / HTTP/1.1") has no leading "Name:".
continue
}

name := trimmed[:colon]
if !isSensitiveHeader(name) {
continue
}

// Rebuild as "Name: ***", preserving the original CRLF if present.
suffix := ""
if strings.HasSuffix(line, "\r") {
suffix = "\r"
}
lines[i] = name + ": ***" + suffix
}

return strings.Join(lines, "\n")
}

// isImportantHeader determines if a header is important enough to show
// even when detailed logging is disabled.
func (t *loggingTransport) isImportantHeader(headerName string) bool {
Expand Down
Loading
Loading