Bound every slog line against client-chosen text (closes #176)
Some checks failed
check / check (push) Has been cancelled
Some checks failed
check / check (push) Has been cancelled
MaxBodySize logged r.URL.Path untruncated at WARN, and routes.go registers it ahead of RequireAuth, so an unauthenticated POST /source/<8 KB>/edit with an oversize declared Content-Length wrote attacker-chosen text of attacker-chosen length into the operator's log, for the cost of a request with no body. The 2,560-byte per-line budget from #146 did not reach it: that budget lives in the access log's field capping and this is a separate slog call. The capping mechanism moves out of internal/middleware into internal/logfield so there is one budget and one implementation rather than a second ad-hoc truncation. Truncate and EncodedBytes are unchanged; the access log now spends logfield.MaxBytes where it spent maxLogFieldBytes. The sweep the issue asked for found five more call sites of the same shape, all reachable unauthenticated, all now capped: the CSRF 403 (also registered ahead of RequireAuth), the rate limiters' 429 (the per-entrypoint receiver limiter is unauthenticated), RequireAuth's own DEBUG line, the unknown-entrypoint DEBUG line on the receiver, and the failed-login DEBUG lines. DEBUG being off by default is not a bound: an operator turning it on to diagnose a flood must not thereby hand the flood an unbounded write. Every other slog call in the tree was read and judged; the PR body lists all of them, including the ones left alone and why. Two further sites arrived in next with #171 after the first sweep was written and are capped here as well: "login failure limit exceeded" in loginguard.go and "password verification capacity exhausted" in handlers/auth.go, both WARN on the unauthenticated login POST. Neither was ever wide — chi routes that POST on a static pattern, so r.URL.Path is the 12-byte constant /pages/login and each line lands near 120 bytes, and removing either cap breaks no test. They are capped because RecordLoginFailure is exported and takes any *http.Request, so the bound rests on a routing invariant nobody wrote down, and because the same message at handlers/profile.go logs no path at all. MaxBodySize stays ahead of RequireAuth. An oversize body should be refused before the request buys a cookie decrypt and a session load, and rejecting first is what keeps an unauthenticated flood from choosing how much session work the process does. The ordering and what it costs are now written at the registration, on maxFormBodySize. MaxAccessLogLineBytes is restated as the ceiling on every slog line carrying text an UNAUTHENTICATED client supplies, not just the access log's: each of these lines carries strictly fewer client-supplied fields than the access log does, so none can be wider. That is asserted per line under both handlers rather than argued. The claim is qualified rather than universal because three kinds of writer are outside it, and the README and the constant now name all three: lines carrying an authenticated operator's own input, which are not truncated at all (the webhook name on "webhook created" reaches 600 KB on one line from a 100 KB form field, measured; the SSRF-rejection url and the target_name lines are the same shape) and are left uncapped deliberately, since truncating the operator's own configuration echoed back costs debuggability against no adversary; the log delivery target, which exists to emit the whole event; and GORM's default logger, which prints the interpolated SQL to stdout on a record-not-found and is unbounded on the receiver and login lookups. That last one is a real defect this audit turned up and is filed separately as #178, not fixed here. Tests drive 8 KB of client-chosen text at all six sites, through both handlers internal/logger can install and through each character they escape — including a bare C0 control, which costs six bytes on the line against the one it cost to send and is the case a raw-byte budget breaks on first. Each holds the encoded line to the ceiling, holds the whole flood's output to what that ceiling allows, and asserts the markers at the far end of the input are absent, so a value that merely happened to be short cannot pass. The two login lines past the username lookup, capped for uniformity rather than need, are pinned too. internal/logfield gains a test that measures the per-rune charge against what the handlers really emit over roughly 3,000 code points on each, so an undercharged rune fails a test instead of quietly falsifying the ceiling. Verified by mutation: reverting the MaxBodySize cap alone fails 28 subtests with a 16,583-byte line against the 2,560 ceiling; reverting the other five fails 70; uncapping either of the two login lines past the username lookup fails both handlers on its own, so those two are independently pinned rather than jointly; budgeting raw bytes instead of encoded ones fails 23 across three packages. The two login-throttle WARN caps are the exception and are recorded as such: reverting them fails nothing, because the constant path gives the mutation nothing to widen.
This commit is contained in:
@@ -6,11 +6,8 @@ import (
|
||||
"log/slog"
|
||||
"net"
|
||||
"net/http"
|
||||
"strings"
|
||||
"sync"
|
||||
"time"
|
||||
"unicode"
|
||||
"unicode/utf8"
|
||||
|
||||
basicauth "github.com/99designs/basicauth-go"
|
||||
"github.com/go-chi/chi"
|
||||
@@ -22,6 +19,7 @@ import (
|
||||
"go.uber.org/fx"
|
||||
"sneak.berlin/go/webhooker/internal/config"
|
||||
"sneak.berlin/go/webhooker/internal/globals"
|
||||
"sneak.berlin/go/webhooker/internal/logfield"
|
||||
"sneak.berlin/go/webhooker/internal/logger"
|
||||
"sneak.berlin/go/webhooker/internal/session"
|
||||
)
|
||||
@@ -44,16 +42,6 @@ const (
|
||||
// pick the size of the line it writes.
|
||||
redactedQuery = "?(redacted)"
|
||||
|
||||
// maxLogFieldBytes bounds each access log field whose value the
|
||||
// client supplies outright: the URL, the User-Agent and the
|
||||
// Referer. The budget is spent in ENCODED bytes (see
|
||||
// truncateLogField), so 512 still holds a real browser's User-Agent
|
||||
// whole — those are plain ASCII, which encodes one byte for one —
|
||||
// while a value built from characters the encoder escapes keeps a
|
||||
// shorter prefix. That is the intended trade: 500 quotation marks
|
||||
// are not a debugging asset.
|
||||
maxLogFieldBytes = 512
|
||||
|
||||
// maxLogRequestIDBytes bounds the request id, which is also
|
||||
// client-supplied: chi's RequestID middleware passes an inbound
|
||||
// X-Request-Id header through verbatim. Its generated form is an
|
||||
@@ -66,15 +54,10 @@ const (
|
||||
// is half this.
|
||||
maxLogMethodBytes = 32
|
||||
|
||||
// truncationMarker is appended to any field the access log cut, so
|
||||
// a short value and a truncated one cannot be confused. It is
|
||||
// charged on top of the budget, not inside it.
|
||||
truncationMarker = "[truncated]"
|
||||
|
||||
// MaxAccessLogLineBytes is the ceiling on one JSON access log line,
|
||||
// and the number an operator multiplies by the request rate to size
|
||||
// log storage. It is not an observation of a sample: it is the sum
|
||||
// of the budgets above, each of which truncateLogField enforces in
|
||||
// of the budgets above, each of which logfield.Truncate enforces in
|
||||
// ENCODED bytes, plus the part of the line no client can influence.
|
||||
//
|
||||
// url, useragent, referer 3*(512+11) = 1569
|
||||
@@ -91,13 +74,48 @@ const (
|
||||
// than sitting on the arithmetic.
|
||||
//
|
||||
// The tty text handler in internal/logger is covered by the same
|
||||
// figure. encodedLogFieldBytes charges every rune at least what
|
||||
// figure. logfield.EncodedBytes charges every rune at least what
|
||||
// the wider of the two handlers emits for it — including the ten
|
||||
// bytes strconv.Quote spends on a non-printable rune at or above
|
||||
// U+10000, which is four more than the JSON handler ever spends —
|
||||
// so each budget bounds the encoded field under either handler.
|
||||
// The text handler's fixed portion is 286, the smaller of the two,
|
||||
// which puts its worst case at 2037.
|
||||
//
|
||||
// It is also the ceiling on every OTHER line this service writes
|
||||
// THROUGH SLOG that carries text an UNAUTHENTICATED client
|
||||
// supplies. Those lines — the MaxBodySize rejection, the CSRF
|
||||
// rejection, the rate-limit rejection, the unauthenticated-request
|
||||
// and unknown-entrypoint DEBUG lines, the failed-login DEBUG
|
||||
// lines, and the two login-throttle WARN lines ("login failure
|
||||
// limit exceeded" in loginguard.go and "password verification
|
||||
// capacity exhausted" in internal/handlers/auth.go) — spend the
|
||||
// same per-field budgets, and each carries
|
||||
// strictly fewer client-supplied fields than the access log does,
|
||||
// so none of them can reach a width the access log cannot. That is
|
||||
// asserted directly, per line and under both handlers, rather than
|
||||
// left to the reasoning: see logbound_test.go in this package and
|
||||
// in internal/handlers.
|
||||
//
|
||||
// What it does NOT cover, so that the figure above is not read as
|
||||
// more than it is:
|
||||
//
|
||||
// - Lines carrying an AUTHENTICATED operator's own input, which
|
||||
// are not truncated at all: the webhook name on "webhook
|
||||
// created" and the target host on "target URL blocked by SSRF
|
||||
// protection" (both internal/handlers/source_management.go),
|
||||
// and target_name in internal/delivery/engine.go and
|
||||
// target_http.go. Each is bounded only by the 1 MB form body
|
||||
// cap, so a 100 KB name writes one line of roughly 600 KB.
|
||||
// Deliberate: truncating the operator's own configuration
|
||||
// echoed back costs debuggability against no adversary.
|
||||
// - The "log" delivery target, which exists to write the whole
|
||||
// inbound event to the log. Deliberate; see
|
||||
// internal/delivery/target_log.go.
|
||||
// - GORM's default logger, which prints the interpolated SQL to
|
||||
// stdout on a record-not-found and so is unbounded on the
|
||||
// receiver and login lookups. NOT deliberate; filed as
|
||||
// https://git.eeqj.de/sneak/webhooker/issues/178.
|
||||
MaxAccessLogLineBytes = 2560
|
||||
)
|
||||
|
||||
@@ -174,114 +192,6 @@ func (lrw *loggingResponseWriter) WriteHeader(code int) {
|
||||
lrw.ResponseWriter.WriteHeader(code)
|
||||
}
|
||||
|
||||
// encodedLogFieldBytes is what r costs on the line once the log
|
||||
// handler has escaped it, taking the worse of the two handlers
|
||||
// internal/logger configures.
|
||||
//
|
||||
// slog's JSON handler escapes quote, backslash, newline, carriage
|
||||
// return and tab to two bytes each, and every other C0 control plus
|
||||
// LINE SEPARATOR and PARAGRAPH SEPARATOR to a six-byte \u escape; it
|
||||
// passes every other rune through as its own UTF-8. Its text handler
|
||||
// quotes with strconv.Quote, which spells a non-printable rune below
|
||||
// U+10000 as \uXXXX but one at or above U+10000 as \UXXXXXXXX — ten
|
||||
// bytes, not six. The text handler is therefore the worse of the two
|
||||
// for every non-printable rune, and by four bytes apiece for the
|
||||
// 955,086 unassigned, private-use and format code points on planes 1
|
||||
// to 16.
|
||||
//
|
||||
// Charging ten there is what makes MaxAccessLogLineBytes hold for the
|
||||
// tty handler as well: U+1000C encodes as F0 90 80 8C, every byte
|
||||
// >= 0x80, which httpguts.ValidHeaderFieldValue accepts and
|
||||
// net/textproto does not strip, so a header can be filled with them.
|
||||
//
|
||||
// Both handlers pass printable runes through as their own UTF-8, so
|
||||
// unicode.IsPrint separates the escaped cases from the plain ones for
|
||||
// either handler.
|
||||
func encodedLogFieldBytes(r rune) int {
|
||||
const (
|
||||
// A backslash and the character itself.
|
||||
shortEscapeBytes = 2
|
||||
// \uXXXX, which is also the width of \u00XX.
|
||||
escapedRuneBytes = 6
|
||||
// \UXXXXXXXX, strconv.Quote's spelling of a non-printable
|
||||
// rune outside the basic multilingual plane.
|
||||
escapedAstralRuneBytes = 10
|
||||
// The first code point strconv.Quote spells with \U.
|
||||
firstAstralRune = 0x10000
|
||||
)
|
||||
|
||||
switch {
|
||||
case r == '"' || r == '\\' || r == '\n' || r == '\r' || r == '\t':
|
||||
return shortEscapeBytes
|
||||
case !unicode.IsPrint(r) && r >= firstAstralRune:
|
||||
return escapedAstralRuneBytes
|
||||
case !unicode.IsPrint(r):
|
||||
return escapedRuneBytes
|
||||
default:
|
||||
return utf8.RuneLen(r)
|
||||
}
|
||||
}
|
||||
|
||||
// truncateLogField caps s at maxBytes of ENCODED output, marking the
|
||||
// value when it cuts.
|
||||
//
|
||||
// Budgeting raw bytes would not bound the line. Escaping only ever
|
||||
// grows a value, so a raw budget spent on characters the encoder
|
||||
// escapes buys a field several times its nominal size — and the line
|
||||
// is the thing an operator is told to multiply by their request rate.
|
||||
// Charging each rune what it will actually cost is what makes
|
||||
// MaxAccessLogLineBytes true rather than merely larger. The visible
|
||||
// consequence is that an escape-heavy value keeps a shorter prefix
|
||||
// than a plain one, which is the correct trade.
|
||||
//
|
||||
// The result is always valid UTF-8. A cut on a byte boundary can split
|
||||
// a multi-byte rune, and a header can carry bytes that were never
|
||||
// valid UTF-8 to begin with; both are dropped rather than kept, since
|
||||
// an encoder would otherwise spend six bytes replacing each one.
|
||||
func truncateLogField(s string, maxBytes int) string {
|
||||
// No rune encodes to fewer bytes than it occupies, so nothing past
|
||||
// maxBytes raw can fit the budget. Slicing first bounds the scan
|
||||
// below to the budget rather than to the size of the header the
|
||||
// client sent.
|
||||
window, cut := s, false
|
||||
if len(window) > maxBytes {
|
||||
window, cut = window[:maxBytes], true
|
||||
}
|
||||
|
||||
var (
|
||||
kept strings.Builder
|
||||
spent int
|
||||
)
|
||||
|
||||
for i := 0; i < len(window); {
|
||||
r, size := utf8.DecodeRuneInString(window[i:])
|
||||
if r == utf8.RuneError && size == 1 {
|
||||
i += size
|
||||
|
||||
continue
|
||||
}
|
||||
|
||||
cost := encodedLogFieldBytes(r)
|
||||
if spent+cost > maxBytes {
|
||||
cut = true
|
||||
|
||||
break
|
||||
}
|
||||
|
||||
spent += cost
|
||||
|
||||
kept.WriteString(window[i : i+size])
|
||||
|
||||
i += size
|
||||
}
|
||||
|
||||
if !cut {
|
||||
return kept.String()
|
||||
}
|
||||
|
||||
return kept.String() + truncationMarker
|
||||
}
|
||||
|
||||
// concreteLogURL renders the request's own URL for the access log
|
||||
// branches that keep it, with the query string replaced by a fixed
|
||||
// marker.
|
||||
@@ -375,21 +285,21 @@ func (s *Middleware) Logging() func(http.Handler) http.Handler {
|
||||
// line does not track the size of the request.
|
||||
s.log.Info("http request",
|
||||
"request_start", start,
|
||||
"method", truncateLogField(
|
||||
"method", logfield.Truncate(
|
||||
r.Method, maxLogMethodBytes,
|
||||
),
|
||||
"url", truncateLogField(
|
||||
"url", logfield.Truncate(
|
||||
accessLogURL(r, lrw.statusCode),
|
||||
maxLogFieldBytes,
|
||||
logfield.MaxBytes,
|
||||
),
|
||||
"useragent", truncateLogField(
|
||||
r.UserAgent(), maxLogFieldBytes,
|
||||
"useragent", logfield.Truncate(
|
||||
r.UserAgent(), logfield.MaxBytes,
|
||||
),
|
||||
"request_id", truncateLogField(
|
||||
"request_id", logfield.Truncate(
|
||||
requestID, maxLogRequestIDBytes,
|
||||
),
|
||||
"referer", truncateLogField(
|
||||
r.Referer(), maxLogFieldBytes,
|
||||
"referer", logfield.Truncate(
|
||||
r.Referer(), logfield.MaxBytes,
|
||||
),
|
||||
"proto", r.Proto,
|
||||
"remoteIP", ipFromHostPort(r.RemoteAddr),
|
||||
@@ -457,10 +367,21 @@ func (s *Middleware) RequireAuth() func(http.Handler) http.Handler {
|
||||
// session lands here and is sent back to the login
|
||||
// page.
|
||||
if !s.session.IsAuthenticated(sess) {
|
||||
// This is the unauthenticated branch, so both
|
||||
// fields are entirely client-chosen and neither
|
||||
// is bounded by anything the router did. DEBUG
|
||||
// is off by default, but turning it on to
|
||||
// diagnose a problem must not hand a client an
|
||||
// unbounded write into the log, so the same
|
||||
// budgets apply here as in the access log.
|
||||
s.log.Debug(
|
||||
"auth middleware: unauthenticated request",
|
||||
"path", r.URL.Path,
|
||||
"method", r.Method,
|
||||
"path", logfield.Truncate(
|
||||
r.URL.Path, logfield.MaxBytes,
|
||||
),
|
||||
"method", logfield.Truncate(
|
||||
r.Method, maxLogMethodBytes,
|
||||
),
|
||||
)
|
||||
http.Redirect(
|
||||
w, r, "/pages/login", http.StatusSeeOther,
|
||||
@@ -620,10 +541,26 @@ func (s *Middleware) MaxBodySize(
|
||||
}
|
||||
|
||||
if r.ContentLength > maxBytes {
|
||||
// This runs ahead of RequireAuth (see
|
||||
// setupUserRoutes and friends in
|
||||
// internal/server/routes.go), so an
|
||||
// unauthenticated client reaches it with a path
|
||||
// of its own choosing and its own length —
|
||||
// POST /source/<8 KB>/edit with an oversize
|
||||
// declared Content-Length costs nothing to
|
||||
// send. At WARN, on by default, that is a
|
||||
// write into the operator's log sized by the
|
||||
// attacker unless the path is capped. Same
|
||||
// budgets as the access log, so this line
|
||||
// cannot be wider than that one.
|
||||
s.log.Warn(
|
||||
"request body exceeds limit",
|
||||
"method", r.Method,
|
||||
"path", r.URL.Path,
|
||||
"method", logfield.Truncate(
|
||||
r.Method, maxLogMethodBytes,
|
||||
),
|
||||
"path", logfield.Truncate(
|
||||
r.URL.Path, logfield.MaxBytes,
|
||||
),
|
||||
"content_length", r.ContentLength,
|
||||
"limit", maxBytes,
|
||||
)
|
||||
|
||||
Reference in New Issue
Block a user