Skip to content

Commit 185d00d

Browse files
PLT-287: Harden HTTP logging and header limits (#191)
* PLT-287: Harden HTTP logging and header limits Skip body logging for compressed responses (gzip, br, deflate) in both logResponse() and handleFileLogging() — log headers with a [body omitted] notice instead of dumping garbled binary bytes to structured logs. Cap MaxBodyLogSize default to 10KB when LogBody is enabled and no explicit limit is set, preventing unbounded body logging. Add MaxHeaderBytes to httpserver (default 32KB) to reject oversized request headers with 431 before reaching application code. * Address Copilot PR feedback on MaxHeaderBytes tests - Validate MaxHeaderBytes <= 0 (not just == 0) so negative values cannot silently bypass the 32KB default - Replace NUL-byte header payload with valid ASCII; the original test was passing due to client-side rejection, not server-side enforcement - Account for Go's 4096-byte internal overhead in MaxHeaderBytes check - Assert network error type on connection-reset path instead of silently passing on unexpected errors * Fix gosec lint findings in httpclient logger - Sanitize id parameter in LogRequest, LogResponse, and LogTransactionToFile before using in file paths (G703) - Add nolint directives for G705 false positives — fmt.Fprintf writes to local log files, not HTTP responses * Potential fix for code scanning alert no. 224: Log entries created from user input Co-authored-by: Copilot Autofix powered by AI <62310815+github-advanced-security[bot]@users.noreply.github.com> * Lower MaxBodyLogSize default to 1KB; omit binary content types from logs - Reduce MaxBodyLogSize default from 10KB to 1KB to keep structured log entries reasonable for log aggregators - Extract shouldOmitResponseBody() helper to check both Content-Encoding and Content-Type, used by logResponse and handleFileLogging - Omit body for binary content types (images, PDFs, protobuf, octet-stream, etc.) even without Content-Encoding - Allow text-based types: text/*, application/json, +json, +xml, etc. * Add E2E integration test for gzip body logging with httpclient proxy Add an integration test in examples/http-client that bootstraps the httpclient module through the modular framework with verbose logging and DisableCompression enabled, then exercises the transport through an httputil.ReverseProxy — the same wiring reverseproxy uses at module.go:1581. Asserts that log output contains the body-omission notice for gzip responses and does not contain raw binary bytes. * Fix gosec lint findings in reverseproxy module Add nolint annotations for: - G704 (SSRF) in composite.go and dryrun.go: URLs are built from configured backend addresses, not user input - G118 (context leak) in health_checker.go: cancel func is stored on the struct and called in Stop() * Fix flaky TestAffiliateBackendOverrideRouting test The test captured the first HandleFunc("/*") from the mock router, but setupBackendRoutes registers one per backend using map iteration (random order). When the "chimera" handler was captured instead of "legacy", the proxy tried to reach bing.com and failed with 500. Fix by capturing the last "/*" handler, which is the catch-all from registerBasicRoutes that properly routes all paths via pattern matching. --------- Co-authored-by: Copilot Autofix powered by AI <62310815+github-advanced-security[bot]@users.noreply.github.com>
1 parent d84294f commit 185d00d

File tree

15 files changed

+771
-64
lines changed

15 files changed

+771
-64
lines changed

examples/http-client/go.mod

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,18 +10,21 @@ require (
1010
github.com/CrisisTextLine/modular/modules/httpclient v0.1.0
1111
github.com/CrisisTextLine/modular/modules/httpserver v0.1.1
1212
github.com/CrisisTextLine/modular/modules/reverseproxy v1.1.0
13+
github.com/stretchr/testify v1.11.1
1314
)
1415

1516
require (
1617
github.com/BurntSushi/toml v1.6.0 // indirect
1718
github.com/cloudevents/sdk-go/v2 v2.16.2 // indirect
19+
github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc // indirect
1820
github.com/go-chi/chi/v5 v5.2.2 // indirect
1921
github.com/gobwas/glob v0.2.3 // indirect
2022
github.com/golobby/cast v1.3.3 // indirect
2123
github.com/google/uuid v1.6.0 // indirect
2224
github.com/json-iterator/go v1.1.12 // indirect
2325
github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd // indirect
2426
github.com/modern-go/reflect2 v1.0.2 // indirect
27+
github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 // indirect
2528
go.uber.org/multierr v1.11.0 // indirect
2629
go.uber.org/zap v1.27.0 // indirect
2730
gopkg.in/yaml.v3 v3.0.1 // indirect
Lines changed: 121 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,121 @@
1+
package main
2+
3+
import (
4+
"bytes"
5+
"compress/gzip"
6+
"io"
7+
"log/slog"
8+
"net/http"
9+
"net/http/httptest"
10+
"net/http/httputil"
11+
"net/url"
12+
"strings"
13+
"testing"
14+
15+
"github.com/CrisisTextLine/modular"
16+
"github.com/CrisisTextLine/modular/modules/httpclient"
17+
"github.com/stretchr/testify/assert"
18+
"github.com/stretchr/testify/require"
19+
)
20+
21+
// TestGzipBodyOmittedInLogsWhenProxied is an end-to-end integration test
22+
// verifying that when a gzip-compressed response passes through a reverse
23+
// proxy using the httpclient module's transport (with verbose logging), the
24+
// log output contains the body-omission notice instead of raw binary bytes.
25+
//
26+
// This mirrors the real wiring: reverseproxy.module.go:1581 sets
27+
// proxy.Transport = m.httpClient.Transport, so the httpclient's
28+
// loggingTransport wraps every proxied request.
29+
func TestGzipBodyOmittedInLogsWhenProxied(t *testing.T) {
30+
// 1. Create a gzip-compressed payload and a backend that serves it.
31+
const payload = `{"status":"ok","data":"hello gzip integration"}`
32+
var gzBuf bytes.Buffer
33+
gw := gzip.NewWriter(&gzBuf)
34+
_, err := gw.Write([]byte(payload))
35+
require.NoError(t, err)
36+
require.NoError(t, gw.Close())
37+
gzBody := gzBuf.Bytes()
38+
39+
backend := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
40+
w.Header().Set("Content-Type", "application/json")
41+
w.Header().Set("Content-Encoding", "gzip")
42+
w.WriteHeader(http.StatusOK)
43+
_, _ = w.Write(gzBody)
44+
}))
45+
defer backend.Close()
46+
47+
// 2. Create a log-capturing buffer wired to a slog logger.
48+
var logBuf bytes.Buffer
49+
logger := slog.New(slog.NewTextHandler(&logBuf, &slog.HandlerOptions{Level: slog.LevelDebug}))
50+
51+
// 3. Bootstrap the modular app with the httpclient module.
52+
app := modular.NewStdApplication(
53+
modular.NewStdConfigProvider(struct{}{}),
54+
logger,
55+
)
56+
57+
// The httpclient module's RegisterConfig registers default values that
58+
// overwrite any pre-registered config section. Use OnConfigLoaded to
59+
// inject our test config after defaults are loaded but before Init.
60+
stdApp := app.(*modular.StdApplication)
61+
stdApp.OnConfigLoaded(func(_ modular.Application) error {
62+
app.RegisterConfigSection("httpclient", modular.NewStdConfigProvider(&httpclient.Config{
63+
Verbose: true,
64+
DisableCompression: true,
65+
VerboseOptions: &httpclient.VerboseOptions{
66+
LogHeaders: true,
67+
LogBody: true,
68+
},
69+
}))
70+
return nil
71+
})
72+
73+
app.RegisterModule(httpclient.NewHTTPClientModule())
74+
75+
// 4. Init wires the httpclient module (builds the loggingTransport).
76+
err = app.Init()
77+
require.NoError(t, err)
78+
79+
// 5. Retrieve the *http.Client from the service registry — this is the
80+
// same client that reverseproxy receives via Constructor and uses as
81+
// proxy.Transport = m.httpClient.Transport (module.go:1581).
82+
var client *http.Client
83+
err = stdApp.GetService("httpclient", &client)
84+
require.NoError(t, err)
85+
require.NotNil(t, client, "httpclient service should provide *http.Client")
86+
require.NotNil(t, client.Transport, "httpclient should configure a custom transport")
87+
88+
// Verify the transport is NOT a plain *http.Transport (should be loggingTransport).
89+
_, isPlainTransport := client.Transport.(*http.Transport)
90+
require.False(t, isPlainTransport,
91+
"expected httpclient to wrap the transport with loggingTransport when Verbose is true")
92+
93+
// 6. Build a reverse proxy that uses the httpclient's transport, exactly
94+
// as the reverseproxy module does in createReverseProxyForBackend.
95+
backendURL, err := url.Parse(backend.URL)
96+
require.NoError(t, err)
97+
proxy := httputil.NewSingleHostReverseProxy(backendURL)
98+
proxy.Transport = client.Transport
99+
100+
// 7. Serve a request through the proxy.
101+
rec := httptest.NewRecorder()
102+
req := httptest.NewRequest(http.MethodGet, "/", nil)
103+
proxy.ServeHTTP(rec, req)
104+
105+
assert.Equal(t, http.StatusOK, rec.Code)
106+
107+
// 8. Verify the response body is the raw gzip bytes (DisableCompression
108+
// ensures the transport does not auto-decompress).
109+
respBody, err := io.ReadAll(rec.Body)
110+
require.NoError(t, err)
111+
assert.Equal(t, gzBody, respBody, "proxy must pass gzip bytes through unchanged")
112+
113+
// 9. Assert the log buffer contains the body-omission notice.
114+
logOutput := logBuf.String()
115+
assert.Contains(t, logOutput, "[body omitted: Content-Encoding=gzip",
116+
"expected gzip body-omission notice in logs")
117+
118+
// 10. Assert the log buffer does NOT contain gzip magic bytes (\x1f\x8b).
119+
assert.False(t, strings.Contains(logOutput, "\x1f\x8b"),
120+
"log output must not contain raw gzip magic bytes")
121+
}

modules/httpclient/README.md

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -29,7 +29,7 @@ httpclient:
2929
verbose_options: # Options for verbose logging (when verbose is true)
3030
log_headers: true # Log request and response headers
3131
log_body: true # Log request and response bodies
32-
max_body_log_size: 10000 # Maximum size of logged bodies (bytes)
32+
max_body_log_size: 1024 # Maximum size of logged bodies (bytes, default 1KB)
3333
log_to_file: false # Whether to log to files instead of application logger
3434
log_file_path: "/tmp/logs" # Directory path for log files (required when log_to_file is true)
3535
```

modules/httpclient/config.go

Lines changed: 12 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -112,9 +112,11 @@ type VerboseOptions struct {
112112
LogBody bool `yaml:"log_body" json:"log_body" env:"LOG_BODY"`
113113

114114
// MaxBodyLogSize limits the size of logged request and response bodies.
115-
// Bodies larger than this size will be truncated in logs. Set to 0 for no limit.
115+
// Bodies larger than this size will be truncated in logs.
116116
// Helps prevent log spam from large file uploads or downloads.
117-
// Default: 0 (no limit)
117+
// When LogBody is enabled and this is left at 0, Validate() applies a
118+
// safe default of 1024 (1KB) to prevent unbounded log output.
119+
// Default: 1024 (1KB) when LogBody is enabled
118120
MaxBodyLogSize int `yaml:"max_body_log_size" json:"max_body_log_size" env:"MAX_BODY_LOG_SIZE"`
119121

120122
// LogToFile enables logging to files instead of just the application logger.
@@ -159,11 +161,18 @@ func (c *Config) Validate() error {
159161
c.VerboseOptions = &VerboseOptions{
160162
LogHeaders: true,
161163
LogBody: true,
162-
MaxBodyLogSize: 10000, // 10KB
164+
MaxBodyLogSize: 1024, // 1KB
163165
LogToFile: false,
164166
}
165167
}
166168

169+
// Apply a safe default body log size when verbose options are explicitly provided
170+
// but MaxBodyLogSize is left at 0 (unlimited). Unlimited body logging can flood
171+
// structured log systems with large or binary payloads.
172+
if c.Verbose && c.VerboseOptions != nil && c.VerboseOptions.LogBody && c.VerboseOptions.MaxBodyLogSize == 0 {
173+
c.VerboseOptions.MaxBodyLogSize = 1024 // 1KB default cap
174+
}
175+
167176
// Validate verbose log file path if logging to file is enabled
168177
if c.Verbose && c.VerboseOptions != nil && c.VerboseOptions.LogToFile && c.VerboseOptions.LogFilePath == "" {
169178
return fmt.Errorf("config validation error: %w", ErrLogFilePathRequired)

modules/httpclient/logger.go

Lines changed: 20 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -92,17 +92,25 @@ func NewFileLogger(baseDir string, logger modular.Logger) (*FileLogger, error) {
9292

9393
// LogRequest writes request data to a file.
9494
func (f *FileLogger) LogRequest(id string, data []byte) error {
95-
requestFile := filepath.Join(f.requestDir, fmt.Sprintf("request_%s_%d.log", id, time.Now().UnixNano()))
96-
if err := os.WriteFile(requestFile, data, 0600); err != nil {
95+
safeID := sanitizeForFilename(id)
96+
if safeID == "" {
97+
return fmt.Errorf("request ID %q: %w", id, ErrUnsafeFilename)
98+
}
99+
requestFile := filepath.Join(f.requestDir, fmt.Sprintf("request_%s_%d.log", safeID, time.Now().UnixNano()))
100+
if err := os.WriteFile(requestFile, data, 0600); err != nil { //nolint:gosec // path components are sanitized above
97101
return fmt.Errorf("failed to write request log file %s: %w", requestFile, err)
98102
}
99103
return nil
100104
}
101105

102106
// LogResponse writes response data to a file.
103107
func (f *FileLogger) LogResponse(id string, data []byte) error {
104-
responseFile := filepath.Join(f.responseDir, fmt.Sprintf("response_%s_%d.log", id, time.Now().UnixNano()))
105-
if err := os.WriteFile(responseFile, data, 0600); err != nil {
108+
safeID := sanitizeForFilename(id)
109+
if safeID == "" {
110+
return fmt.Errorf("response ID %q: %w", id, ErrUnsafeFilename)
111+
}
112+
responseFile := filepath.Join(f.responseDir, fmt.Sprintf("response_%s_%d.log", safeID, time.Now().UnixNano()))
113+
if err := os.WriteFile(responseFile, data, 0600); err != nil { //nolint:gosec // path components are sanitized above
106114
return fmt.Errorf("failed to write response log file %s: %w", responseFile, err)
107115
}
108116
return nil
@@ -111,14 +119,18 @@ func (f *FileLogger) LogResponse(id string, data []byte) error {
111119
// LogTransactionToFile logs both request and response data to a single file for easier analysis.
112120
func (f *FileLogger) LogTransactionToFile(id string, reqData, respData []byte, duration time.Duration, url string) error {
113121
// Create a filename that's safe for the filesystem
122+
safeID := sanitizeForFilename(id)
123+
if safeID == "" {
124+
return fmt.Errorf("transaction ID %q: %w", id, ErrUnsafeFilename)
125+
}
114126
safeURL := sanitizeForFilename(url)
115127
if safeURL == "" {
116128
return fmt.Errorf("URL %q: %w", url, ErrUnsafeFilename)
117129
}
118130

119-
txnFile := filepath.Join(f.txnDir, fmt.Sprintf("txn_%s_%s_%d.log", id, safeURL, time.Now().UnixNano()))
131+
txnFile := filepath.Join(f.txnDir, fmt.Sprintf("txn_%s_%s_%d.log", safeID, safeURL, time.Now().UnixNano()))
120132

121-
file, err := os.Create(txnFile)
133+
file, err := os.Create(txnFile) //nolint:gosec // path components are sanitized above
122134
if err != nil {
123135
return fmt.Errorf("failed to create transaction log file: %w", err)
124136
}
@@ -130,7 +142,7 @@ func (f *FileLogger) LogTransactionToFile(id string, reqData, respData []byte, d
130142
}()
131143

132144
// Write transaction metadata
133-
if _, err := fmt.Fprintf(file, "Transaction ID: %s\n", id); err != nil {
145+
if _, err := fmt.Fprintf(file, "Transaction ID: %s\n", id); err != nil { //nolint:gosec // G705 false positive: writing to local file, not HTTP response
134146
return fmt.Errorf("failed to write transaction ID to log file: %w", err)
135147
}
136148
if _, err := fmt.Fprintf(file, "URL: %s\n", url); err != nil {
@@ -139,7 +151,7 @@ func (f *FileLogger) LogTransactionToFile(id string, reqData, respData []byte, d
139151
if _, err := fmt.Fprintf(file, "Time: %s\n", time.Now().Format(time.RFC3339)); err != nil {
140152
return fmt.Errorf("failed to write timestamp to log file: %w", err)
141153
}
142-
if _, err := fmt.Fprintf(file, "Duration: %d ms\n", duration.Milliseconds()); err != nil {
154+
if _, err := fmt.Fprintf(file, "Duration: %d ms\n", duration.Milliseconds()); err != nil { //nolint:gosec // G705 false positive: writing to local file, not HTTP response
143155
return fmt.Errorf("failed to write duration to log file: %w", err)
144156
}
145157
if _, err := fmt.Fprintf(file, "\n----- REQUEST -----\n\n"); err != nil {

0 commit comments

Comments
 (0)