fix(backend): cut request log fields to the log bound (closes #60)
check / check (push) Successful in 1m4s
check / check (push) Successful in 1m4s
The request log wrote the URL, User-Agent, Referer and other request-supplied strings with no length limit, and the server accepts headers up to 1 MiB, so one request could put about 1 MiB per field into a log line. Every string the request log takes from the request, including the request ID chi copies from X-Request-Id, is now cut to the 128-byte bound the report handler already used. That bound and its helper moved from the handlers package to the logger package so both use the one copy. Model: opus-5-5
This commit is contained in:
@@ -2,9 +2,6 @@ package handlers
|
||||
|
||||
import "log/slog"
|
||||
|
||||
// MaxLoggedFieldBytes exposes the log bound to the external tests.
|
||||
const MaxLoggedFieldBytes = maxLoggedFieldBytes
|
||||
|
||||
// NewForTest builds a Handlers around a report sink and logger,
|
||||
// bypassing the fx graph so handler behaviour (including the
|
||||
// storage failure path) is exercisable in unit tests.
|
||||
|
||||
@@ -5,14 +5,10 @@ import (
|
||||
"errors"
|
||||
"net/http"
|
||||
|
||||
"sneak.berlin/go/netwatch/internal/logger"
|
||||
"sneak.berlin/go/netwatch/internal/reportbuf"
|
||||
)
|
||||
|
||||
// maxLoggedFieldBytes bounds untrusted text (string fields,
|
||||
// decode error text) before it is logged, so a caller cannot
|
||||
// inflate log volume with an oversized value.
|
||||
const maxLoggedFieldBytes = 128
|
||||
|
||||
type reportSample struct {
|
||||
T int64 `json:"t"`
|
||||
Latency *int `json:"latency"`
|
||||
@@ -83,7 +79,7 @@ func (s *Handlers) decodeErrorStatus(err error) int {
|
||||
// The decoder's error text can quote request bytes (a whole
|
||||
// oversized number, for example), so it is bounded too.
|
||||
s.log.Error("failed to decode report",
|
||||
"error", boundedForLog(err.Error()),
|
||||
"error", logger.BoundedForLog(err.Error()),
|
||||
)
|
||||
|
||||
return http.StatusBadRequest
|
||||
@@ -115,20 +111,10 @@ func (s *Handlers) logReportReceived(rpt report) {
|
||||
}
|
||||
|
||||
s.log.Info("report received",
|
||||
"client_id", boundedForLog(rpt.ClientID),
|
||||
"timestamp", boundedForLog(rpt.Timestamp),
|
||||
"client_id", logger.BoundedForLog(rpt.ClientID),
|
||||
"timestamp", logger.BoundedForLog(rpt.Timestamp),
|
||||
"host_count", len(rpt.Hosts),
|
||||
"total_samples", totalSamples,
|
||||
"geo_bytes", len(rpt.Geo),
|
||||
)
|
||||
}
|
||||
|
||||
// boundedForLog truncates an untrusted string to a fixed byte
|
||||
// bound so an attacker-controlled field cannot dominate the log.
|
||||
func boundedForLog(s string) string {
|
||||
if len(s) > maxLoggedFieldBytes {
|
||||
return s[:maxLoggedFieldBytes]
|
||||
}
|
||||
|
||||
return s
|
||||
}
|
||||
|
||||
@@ -12,6 +12,7 @@ import (
|
||||
"testing"
|
||||
|
||||
"sneak.berlin/go/netwatch/internal/handlers"
|
||||
"sneak.berlin/go/netwatch/internal/logger"
|
||||
"sneak.berlin/go/netwatch/internal/middleware"
|
||||
"sneak.berlin/go/netwatch/internal/reportbuf"
|
||||
)
|
||||
@@ -174,7 +175,7 @@ func TestHandleReportDoesNotLogRawGeo(t *testing.T) {
|
||||
func TestHandleReportLogsClientIDCutToBound(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
long := strings.Repeat("c", 2*handlers.MaxLoggedFieldBytes)
|
||||
long := strings.Repeat("c", 2*logger.MaxLoggedFieldBytes)
|
||||
|
||||
var logbuf bytes.Buffer
|
||||
|
||||
@@ -197,16 +198,16 @@ func TestHandleReportLogsClientIDCutToBound(t *testing.T) {
|
||||
t.Fatalf("log line not JSON: %v (%q)", err, logbuf.String())
|
||||
}
|
||||
|
||||
want := long[:handlers.MaxLoggedFieldBytes]
|
||||
want := long[:logger.MaxLoggedFieldBytes]
|
||||
|
||||
if logged["client_id"] != want {
|
||||
t.Fatalf("logged client_id not cut to %d bytes: %q",
|
||||
handlers.MaxLoggedFieldBytes, logged["client_id"])
|
||||
logger.MaxLoggedFieldBytes, logged["client_id"])
|
||||
}
|
||||
|
||||
if logged["timestamp"] != want {
|
||||
t.Fatalf("logged timestamp not cut to %d bytes: %q",
|
||||
handlers.MaxLoggedFieldBytes, logged["timestamp"])
|
||||
logger.MaxLoggedFieldBytes, logged["timestamp"])
|
||||
}
|
||||
}
|
||||
|
||||
@@ -215,7 +216,7 @@ func TestHandleReportDecodeErrorLogIsBounded(t *testing.T) {
|
||||
|
||||
// A number too large for its int64 field makes the decoder's
|
||||
// error text quote the whole number.
|
||||
huge := strings.Repeat("9", 2*handlers.MaxLoggedFieldBytes)
|
||||
huge := strings.Repeat("9", 2*logger.MaxLoggedFieldBytes)
|
||||
|
||||
var logbuf bytes.Buffer
|
||||
|
||||
|
||||
Reference in New Issue
Block a user