Compare commits

3 Commits

Author SHA1 Message Date
8690cf9311 Bound the access log line against client-chosen text (closes #146)
All checks were successful
check / check (push) Successful in 2m51s
The access log wrote one INFO line per request carrying
r.URL.String(). Registered with Use, it runs ahead of the route
limiter, so a client flooding the unauthenticated receiver with
invented paths wrote attacker-chosen text of attacker-chosen length
into the operator's log, one line per request.

3xx and 4xx responses now log the chi route pattern in place of the
concrete URL, and the fixed literal "(unmatched)" when routing matched
nothing at all. One line per request is retained, so real traffic
stays observable and rate accounting still works, but the line's
content is now bounded by the service's own route table. The pattern
is only populated after routing, so it is read in the deferred part of
the handler rather than before next.ServeHTTP.

The route pattern alone does not close the hole, because it leaves two
other ways for a request to choose the size of the line it writes.

The query string is one: /.well-known/healthcheck and /s/* answer 200
to anyone with no rate limiter in front of them, and /pages/login
behind only the login limiter, so appending 8 KB after the '?' bought
the same amplification as an invented 404 path. The branches that keep
the concrete URL now log the path only, with the query replaced by the
fixed marker "?(redacted)". Nothing debuggable is lost: `page`, on the
authenticated pagination links, is the only query parameter this
service reads.

The headers are the other: useragent and referer are logged on every
line, including the correctly redacted ones, so an 8 KB User-Agent
plus an 8 KB Referer produced a 24 KB line whose url field read
"(unmatched)". Each field a client supplies is now truncated rather
than dropped -- a truncated User-Agent is still worth reading -- to
512 bytes for url, useragent and referer, 128 for request_id (chi
passes an inbound X-Request-Id header straight through), and 32 for
method, which Go accepts as any token up to the header size limit.
Truncation also drops invalid UTF-8, which a JSON encoder would
otherwise expand six-fold past the budget.

A complete line is now at most 2,560 bytes, which the tests assert
against a request carrying 8 KB in the query and 8 KB in each of three
headers, and which the README states so an operator can size log
storage against it.
2026-08-17 21:03:06 +00:00
279effb4c2 Bound the event log's rendered bodies in the query (closes #135)
All checks were successful
check / check (push) Successful in 3m0s
The event log rendered stored bodies untruncated. Since buffered
rendering landed (#123) that became resident memory per concurrent
viewer, up to tens of MB, driven by payloads unauthenticated clients
supply to the public receiver.

Bound in the query rather than the template, via
substr(cast(body as blob), 1, ?) plus length(cast(body as blob)), so an
oversized body never becomes a Go string at all. Adds an EventLogView
projection carrying the true byte count, and trims a partial UTF-8 tail
without rewriting bodies that are merely invalid UTF-8.

Independently reviewed. The generated SQL was dumped under GORM DryRun
to confirm the cap is a bound parameter, both casts are present, and no
other path selects the full column; soft-delete scope, ordering and
pagination are unchanged.

Correction to the PR body: its quoted mutation output was produced by
removing the bound from eventLogColumns, not by raising the cap to
1<<30 as the text claimed. The reviewer reproduced the real
mutation and confirmed the tests do catch removal of the bound.

Follow-up #157 restores in-app retrieval of bodies above the cap.
2026-08-17 22:57:08 +02:00
9ae19159a3 Mask the http target's destination URL in the UI (closes #115)
Some checks failed
check / check (push) Superseded by a newer commit; never tested
The http target's destination URL can itself be a bearer credential, and
the source detail page rendered it in full. Render it through the
existing MaskURL instead, matching the rule already applied to slack
targets.

Independently reviewed: mutation-verified (reverting to the raw value
fails the absence assertions, not merely the masked-form ones), MaskURL
probed against userinfo, query, fragment, port, IPv6 literal and
non-http schemes, and every sibling path that surfaces target data
re-walked and found clean.
2026-08-17 22:50:26 +02:00
12 changed files with 828 additions and 59 deletions

View File

@@ -914,14 +914,34 @@ no route at all — in place of the concrete URL. Those are the outcomes
an unauthenticated client can drive for free: 404 and 429 on any an unauthenticated client can drive for free: 404 and 429 on any
invented receiver path, a login redirect on any invented profile path. invented receiver path, a login redirect on any invented profile path.
Logging the URL there would let a flood write text of its own choosing, Logging the URL there would let a flood write text of its own choosing,
at a length of its own choosing, into the log. The pattern comes from at a length of its own choosing, into the log. 2xx and 5xx responses
the service's own route table, so an operator sizing log storage can keep the concrete path — a success resolved against a static route or
multiply a fixed per-line cost by the request rate the rate limits against the operator's own data (on the receiver, against a stored
allow. 2xx and 5xx responses keep the full URL, query string included: entrypoint UUID), and a 5xx is a bug in this service, where the exact
a success resolved against a static route or against the operator's own path is the evidence and no client can provoke one at will.
data (on the receiver, against a stored entrypoint UUID), and a 5xx is
a bug in this service, where the exact URL is the evidence and no The query string is never logged; it is replaced by the fixed marker
client can provoke one at will. `?(redacted)`. It is client-chosen on every route, and
`/.well-known/healthcheck` and `/s/*` answer 200 to anyone with no rate
limiter in front of them, so a query on a fixed 200 URL would otherwise
buy the same amplification as an invented path. Nothing debuggable is
lost: `page`, on the authenticated pagination links, is the only query
parameter this service reads.
The remaining client-supplied fields are truncated rather than dropped,
each to a fixed budget: 512 bytes for `url`, `useragent` and `referer`,
128 for `request_id` (chi passes an inbound `X-Request-Id` header
through), and 32 for `method`. A truncated `User-Agent` is still worth
reading; an absent one is not. A cut value ends in `[truncated]`.
Net: **one `INFO` line per request, of at most 2,560 bytes**
`internal/middleware/accesslog_test.go` asserts that ceiling against a
request carrying an 8 KB query, an 8 KB `User-Agent`, an 8 KB `Referer`
and an 8 KB `X-Request-Id`, which together produce a 1,460-byte line.
Multiply that ceiling by the request rate to size log storage. Note
that the rate is not bounded by the limits above on every route:
`/.well-known/healthcheck` and `/s/*` sit behind no limiter, so there
the multiplier is whatever the deployment will serve.
Every limiter here — receiver, login, and password change — identifies Every limiter here — receiver, login, and password change — identifies
the client the same way, through one shared key function: the the client the same way, through one shared key function: the

View File

@@ -106,6 +106,12 @@ func slackConfigFields(configJSON string) []ConfigField {
// and its retry settings. Header values are not shown — they // and its retry settings. Header values are not shown — they
// routinely carry authorization tokens — only how many are // routinely carry authorization tokens — only how many are
// configured. // configured.
//
// The destination is masked to scheme and host by the same
// rule the Slack target uses. An HTTP target's destination is
// commonly a Slack, Discord or Teams incoming-webhook endpoint
// whose path segments are the credential, and the field takes
// an arbitrary URL, so no segment can be assumed non-secret.
func httpConfigFields(t *database.Target) []ConfigField { func httpConfigFields(t *database.Target) []ConfigField {
cfg, err := parseHTTPConfig(t.Config) cfg, err := parseHTTPConfig(t.Config)
if err != nil { if err != nil {
@@ -114,7 +120,7 @@ func httpConfigFields(t *database.Target) []ConfigField {
fields := []ConfigField{{ fields := []ConfigField{{
Label: "Destination URL", Label: "Destination URL",
Value: cfg.URL, Value: MaskURL(cfg.URL),
}} }}
if cfg.Timeout > 0 { if cfg.Timeout > 0 {

View File

@@ -19,6 +19,7 @@ const (
viewExampleOrigin = "https://example.com" viewExampleOrigin = "https://example.com"
viewExampleHook = viewExampleOrigin + "/hook" viewExampleHook = viewExampleOrigin + "/hook"
viewMaskedOrigin = viewExampleOrigin + "/..."
viewUnavailable = "(unavailable)" viewUnavailable = "(unavailable)"
viewExpiryNever = "never" viewExpiryNever = "never"
) )
@@ -162,7 +163,7 @@ func TestNewTargetViews_HTTP(t *testing.T) {
assert.Equal( assert.Equal(
t, t,
map[string]string{ map[string]string{
"Destination URL": viewExampleHook, "Destination URL": viewMaskedOrigin,
"Timeout": "30s", "Timeout": "30s",
"Headers": "1 configured", "Headers": "1 configured",
"Max Retries": "5", "Max Retries": "5",
@@ -188,13 +189,41 @@ func TestNewTargetViews_HTTPFireAndForget(t *testing.T) {
assert.Equal( assert.Equal(
t, t,
map[string]string{ map[string]string{
"Destination URL": viewExampleHook, "Destination URL": viewMaskedOrigin,
"Max Retries": "0 (fire-and-forget)", "Max Retries": "0 (fire-and-forget)",
}, },
fieldMap(view.Config), fieldMap(view.Config),
) )
} }
// TestNewTargetViews_HTTPMasksDestinationURL proves the rule
// holds for the http target too: an http destination is
// routinely an incoming-webhook endpoint whose path segments
// are the credential, so none of them is shown.
func TestNewTargetViews_HTTPMasksDestinationURL(t *testing.T) {
t.Parallel()
view := viewFor(t, database.Target{
Type: database.TargetTypeHTTP,
Config: `{"url":"` + slackWebhookURL + `"}`,
})
fields := fieldMap(view.Config)
assert.Equal(
t,
"https://hooks.slack.com/...",
fields["Destination URL"],
)
for _, v := range fields {
assert.NotContains(t, v, slackSecretPath)
assert.NotContains(t, v, "T00000000")
assert.NotContains(t, v, "B00000000")
assert.NotContains(t, v, "XXXXXXXXXXXXXXXXXXXXXXXX")
}
}
func TestNewTargetViews_Database(t *testing.T) { func TestNewTargetViews_Database(t *testing.T) {
t.Parallel() t.Parallel()

View File

@@ -0,0 +1,120 @@
package handlers
import (
"time"
"unicode/utf8"
)
// maxRenderedBodyBytes caps how many bytes of a stored event
// body reach the event log page. Bodies come from the
// unauthenticated receiver under the 1 MB ingest cap and
// renderTemplate buffers a whole page before writing it, so
// an uncapped page of paginationPerPage events is tens of
// megabytes of resident memory per concurrent viewer.
const maxRenderedBodyBytes = 8192
// eventLogColumns is the event log's projection. The casts to
// blob are load-bearing: they make substr and length count
// bytes rather than characters, so the cap bounds the page in
// bytes whatever the payload's encoding. Cutting in SQLite
// rather than in Go is the point of the projection — an
// oversized body never becomes a Go string at all.
const eventLogColumns = "id, created_at, method, content_type, " +
"substr(cast(body as blob), 1, ?) AS body, " +
"length(cast(body as blob)) AS body_bytes"
// EventLogView is the display-safe projection of an event for
// the event log page, alongside DeliveryView and TargetView.
// It carries a capped body plus the true stored size, so the
// page can mark a body as truncated without ever holding the
// whole thing.
type EventLogView struct {
ID string
CreatedAt time.Time
Method string
ContentType string
// Body holds at most maxRenderedBodyBytes bytes of the
// stored body.
Body string
// BodyBytes is the true size of the stored body.
BodyBytes int64
// BodyTruncated reports that the stored body was larger
// than the cap, so the page owes the reader a marker.
BodyTruncated bool
Deliveries []DeliveryView
}
// BodyShownBytes is how many body bytes the page is actually
// rendering, which the truncation marker reports beside the
// true size.
func (v EventLogView) BodyShownBytes() int {
return len(v.Body)
}
// eventLogRow is one row of the event log projection. Its
// body column arrives already cut to the cap by SQLite, with
// the true size beside it.
type eventLogRow struct {
ID string
CreatedAt time.Time
Method string
ContentType string
Body []byte
BodyBytes int64
}
// view projects a loaded row for rendering.
func (r *eventLogRow) view() EventLogView {
body := r.Body
truncated := r.BodyBytes > int64(len(body))
// Only a cut body can have been left mid-sequence by
// this query. A whole body is passed through exactly as
// stored, however malformed.
if truncated {
body = trimPartialRune(body)
}
return EventLogView{
ID: r.ID,
CreatedAt: r.CreatedAt,
Method: r.Method,
ContentType: r.ContentType,
Body: string(body),
BodyBytes: r.BodyBytes,
BodyTruncated: truncated,
}
}
// trimPartialRune drops a trailing UTF-8 sequence that the
// byte-wise cut left incomplete, so a multi-byte rune severed
// at the cap does not surface as a mojibake tail.
//
// Bytes that are merely invalid UTF-8 are left exactly as
// stored: this service receives binary payloads, and rewriting
// them would misreport what was delivered. The distinction is
// utf8.FullRune's — it reports a complete sequence for an
// invalid encoding too, since that decodes to a width-1 error
// rune, so only a valid prefix still waiting for its
// continuation bytes is removed. A tail with no rune start in
// its last utf8.UTFMax bytes cannot be an incomplete sequence
// either, and is likewise left alone.
func trimPartialRune(b []byte) []byte {
for i := len(b) - 1; i >= 0 && len(b)-i <= utf8.UTFMax; i-- {
if !utf8.RuneStart(b[i]) {
continue
}
if utf8.FullRune(b[i:]) {
return b
}
return b[:i]
}
return b
}

View File

@@ -0,0 +1,258 @@
package handlers_test
import (
"net/http"
"net/http/httptest"
"strconv"
"strings"
"testing"
"unicode/utf8"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"gorm.io/gorm/clause"
"sneak.berlin/go/webhooker/internal/database"
"sneak.berlin/go/webhooker/internal/handlers"
"sneak.berlin/go/webhooker/internal/session"
)
// bodyCap is the number of body bytes the event log page is
// allowed to render for one event.
const bodyCap = handlers.MaxRenderedBodyBytesForTest
// snowman is a three-byte rune, so a body of them straddles the
// byte-wise cut: bodyCap is not a multiple of three.
const snowman = "☃"
// seedEventWithBody records one event with the given body in the
// webhook's own database.
func seedEventWithBody(
t *testing.T,
dbMgr *database.WebhookDBManager,
webhookID string,
body string,
) {
t.Helper()
webhookDB, err := dbMgr.GetDB(webhookID)
require.NoError(t, err)
event := &database.Event{
WebhookID: webhookID,
Method: http.MethodPost,
Body: body,
ContentType: "application/octet-stream",
}
require.NoError(t, webhookDB.Omit(
clause.Associations,
).Create(event).Error)
}
// seedAndProject stores one body and returns the projection the
// event log page would be handed for it.
func seedAndProject(
t *testing.T,
body string,
) handlers.EventLogView {
t.Helper()
var (
h *handlers.Handlers
sess *session.Session
db *database.Database
dbMgr *database.WebhookDBManager
)
app := newTestApp(t, &h, &sess, &db, &dbMgr)
app.RequireStart()
t.Cleanup(app.RequireStop)
wh := seedWebhook(t, db)
seedEventWithBody(t, dbMgr, wh.ID, body)
views := h.LoadEventLogViewsForTest(
httptest.NewRecorder(), *wh, 1,
)
require.Len(t, views, 1)
return views[0]
}
// TestHandleSourceLogs_BoundsOversizeBody proves the rendered
// page is bounded by the cap rather than by the stored payload:
// the body here is 64 times the cap, and the ingest path would
// accept twice as much again.
func TestHandleSourceLogs_BoundsOversizeBody(t *testing.T) {
t.Parallel()
var (
h *handlers.Handlers
sess *session.Session
db *database.Database
dbMgr *database.WebhookDBManager
)
app := newTestApp(t, &h, &sess, &db, &dbMgr)
app.RequireStart()
t.Cleanup(app.RequireStop)
const (
sentinel = "TAIL-SENTINEL-1f4a9c"
storedBytes = 512 * 1024
)
wh := seedWebhook(t, db)
seedEventWithBody(
t, dbMgr, wh.ID,
strings.Repeat("A", storedBytes-len(sentinel))+sentinel,
)
page := renderSourceLogsPage(t, h, sess, wh.ID)
// Nothing past the cap reaches the page, and the whole page
// stays far below the stored body it is reporting on.
assert.NotContains(t, page, sentinel)
assert.Less(t, len(page), 4*bodyCap)
// The marker states the true stored size, not the cut one.
assert.Contains(
t, page,
"showing "+strconv.Itoa(bodyCap)+
" of "+strconv.Itoa(storedBytes)+" bytes",
)
}
// TestHandleSourceLogs_SmallBodyRendersWhole guards the other
// side of the cap: a body under it is shown in full and carries
// no truncation marker.
func TestHandleSourceLogs_SmallBodyRendersWhole(t *testing.T) {
t.Parallel()
var (
h *handlers.Handlers
sess *session.Session
db *database.Database
dbMgr *database.WebhookDBManager
)
app := newTestApp(t, &h, &sess, &db, &dbMgr)
app.RequireStart()
t.Cleanup(app.RequireStop)
wh := seedWebhook(t, db)
seedEventWithBody(t, dbMgr, wh.ID, `{"kept":"whole"}`)
page := renderSourceLogsPage(t, h, sess, wh.ID)
assert.Contains(t, page, "&#34;kept&#34;")
assert.NotContains(t, page, "Body truncated for display")
}
// TestEventLogView_CutMidRune proves a multi-byte rune severed
// by the byte-wise cut is dropped rather than surfaced as a
// mojibake tail.
func TestEventLogView_CutMidRune(t *testing.T) {
t.Parallel()
body := strings.Repeat(snowman, 4096)
view := seedAndProject(t, body)
// bodyCap bytes hold bodyCap/3 whole snowmen and two bytes
// of the next one; those two are dropped.
whole := bodyCap / len(snowman)
assert.True(t, view.BodyTruncated)
assert.Equal(t, int64(len(body)), view.BodyBytes)
assert.Equal(t, strings.Repeat(snowman, whole), view.Body)
assert.True(t, utf8.ValidString(view.Body))
assert.LessOrEqual(t, len(view.Body), bodyCap)
}
// TestEventLogView_BinaryBodyLeftAsStored proves a binary
// payload is passed through byte for byte. Its tail is invalid
// UTF-8 however the cut falls, so repairing it would misreport
// what the sender delivered.
func TestEventLogView_BinaryBodyLeftAsStored(t *testing.T) {
t.Parallel()
raw := make([]byte, bodyCap+808)
for i := range raw {
// 0x80..0xBF: continuation bytes, never a rune start.
raw[i] = 0x80 | byte(i%0x40)
}
view := seedAndProject(t, string(raw))
assert.True(t, view.BodyTruncated)
assert.Equal(t, int64(len(raw)), view.BodyBytes)
assert.Equal(t, string(raw[:bodyCap]), view.Body)
assert.False(t, utf8.ValidString(view.Body))
}
// TestTrimPartialRune covers the distinction the cut repair
// turns on: an incomplete but valid sequence is dropped, while
// bytes that are merely invalid UTF-8 are left alone.
func TestTrimPartialRune(t *testing.T) {
t.Parallel()
cases := []struct {
name string
in []byte
want []byte
}{{
name: "complete ascii",
in: []byte("abc"),
want: []byte("abc"),
}, {
name: "complete multibyte",
in: []byte("ab" + snowman),
want: []byte("ab" + snowman),
}, {
name: "two byte rune cut",
in: []byte{'a', 0xC3},
want: []byte{'a'},
}, {
name: "three byte rune cut after one",
in: []byte{'a', 0xE2},
want: []byte{'a'},
}, {
name: "three byte rune cut after two",
in: []byte{'a', 0xE2, 0x98},
want: []byte{'a'},
}, {
name: "four byte rune cut",
in: []byte{'a', 0xF0, 0x9F, 0x92}, // U+1F4A9 cut
want: []byte{'a'},
}, {
name: "invalid start byte kept",
in: []byte{'a', 0xFF},
want: []byte{'a', 0xFF},
}, {
name: "orphan continuation bytes kept",
in: []byte{0x80, 0x81, 0x82, 0x83, 0x84},
want: []byte{0x80, 0x81, 0x82, 0x83, 0x84},
}, {
name: "truncated sequence followed by junk kept",
in: []byte{0xE2, 0x98, 0xFF},
want: []byte{0xE2, 0x98, 0xFF},
}, {
name: "empty",
in: []byte{},
want: []byte{},
}}
for _, tc := range cases {
t.Run(tc.name, func(t *testing.T) {
t.Parallel()
assert.Equal(
t, tc.want,
handlers.TrimPartialRuneForTest(tc.in),
)
})
}
}

View File

@@ -3,8 +3,35 @@ package handlers
import ( import (
"html/template" "html/template"
"net/http" "net/http"
"sneak.berlin/go/webhooker/internal/database"
) )
// MaxRenderedBodyBytesForTest exposes the event log's body cap
// to the handlers_test package.
const MaxRenderedBodyBytesForTest = maxRenderedBodyBytes
// TrimPartialRuneForTest exposes trimPartialRune for use in the
// handlers_test package.
func TrimPartialRuneForTest(b []byte) []byte {
return trimPartialRune(b)
}
// LoadEventLogViewsForTest exposes loadEventsWithDeliveries for
// use in the handlers_test package. Assertions on the projected
// body need the bytes as loaded: html/template rewrites invalid
// UTF-8 on the way out, so the rendered page cannot show whether
// a binary body survived the projection intact.
func (s *Handlers) LoadEventLogViewsForTest(
w http.ResponseWriter,
webhook database.Webhook,
page int,
) []EventLogView {
views, _ := s.loadEventsWithDeliveries(w, webhook, nil, page)
return views
}
// AddTemplateForTest registers a template under a page name so that // AddTemplateForTest registers a template under a page name so that
// the handlers_test package can drive the render path with a // the handlers_test package can drive the render path with a
// template of its own. // template of its own.

View File

@@ -229,8 +229,10 @@ func (s *Handlers) renderTemplate(
// the response only once rendering has fully succeeded. Executing // the response only once rendering has fully succeeded. Executing
// straight into the ResponseWriter commits a partial body and a 200 // straight into the ResponseWriter commits a partial body and a 200
// status before a mid-render error can be reported, leaving no way // status before a mid-render error can be reported, leaving no way
// to serve a 500. These pages are small, so holding one in memory is // to serve a 500. Buffering makes a page's rendered size resident
// the right trade. // memory per concurrent viewer, so every page owes it a bound: the
// event log caps each stored body at maxRenderedBodyBytes for exactly
// this reason.
func (s *Handlers) executeTemplate( func (s *Handlers) executeTemplate(
w http.ResponseWriter, w http.ResponseWriter,
tmpl *template.Template, tmpl *template.Template,

View File

@@ -131,6 +131,47 @@ func TestHandleSourceDetail_MasksSlackWebhookURL(t *testing.T) {
assert.Contains(t, body, "https://hooks.slack.com/...") assert.Contains(t, body, "https://hooks.slack.com/...")
} }
// TestHandleSourceDetail_MasksHTTPDestinationURL is the
// regression test for the same leak reached through the http
// target: its destination is routinely an incoming-webhook
// endpoint whose path segments are the credential, so the
// rendered page must not contain them.
func TestHandleSourceDetail_MasksHTTPDestinationURL(
t *testing.T,
) {
t.Parallel()
var (
h *handlers.Handlers
sess *session.Session
db *database.Database
)
app := newTestApp(t, &h, &sess, &db)
app.RequireStart()
t.Cleanup(app.RequireStop)
wh := seedWebhook(t, db)
seedConfiguredTarget(
t, db, wh.ID,
database.TargetTypeHTTP,
`{"url":"`+slackWebhookURL+`"}`,
)
body := renderSourceDetailPage(t, h, sess, wh.ID)
assert.NotContains(t, body, slackSecretPath)
assert.NotContains(t, body, "T00000000")
assert.NotContains(t, body, "B00000000")
assert.NotContains(
t, body, "XXXXXXXXXXXXXXXXXXXXXXXX",
)
assert.Contains(t, body, "Destination URL")
assert.Contains(t, body, "https://hooks.slack.com/...")
}
// TestHandleSourceDetail_RendersNamedTargetFields proves the // TestHandleSourceDetail_RendersNamedTargetFields proves the
// other target types render labelled fields rather than the // other target types render labelled fields rather than the
// stored blob. // stored blob.
@@ -172,7 +213,7 @@ func TestHandleSourceDetail_RendersNamedTargetFields(
body := renderSourceDetailPage(t, h, sess, wh.ID) body := renderSourceDetailPage(t, h, sess, wh.ID)
assert.Contains(t, body, "Destination URL") assert.Contains(t, body, "Destination URL")
assert.Contains(t, body, "https://example.com/hook") assert.Contains(t, body, "https://example.com/...")
assert.Contains(t, body, "Timeout") assert.Contains(t, body, "Timeout")
assert.Contains(t, body, "1 configured") assert.Contains(t, body, "1 configured")
assert.NotContains(t, body, "sekrit") assert.NotContains(t, body, "sekrit")

View File

@@ -92,13 +92,6 @@ func parseRetentionDays(raw string, fallback int) (int, error) {
return v, nil return v, nil
} }
// EventWithDeliveries holds an event and its deliveries.
type EventWithDeliveries struct {
database.Event
Deliveries []DeliveryView
}
// DeliveryView is the display-safe projection of a delivery // DeliveryView is the display-safe projection of a delivery
// for the event log page. Its target is a TargetView, so the // for the event log page. Its target is a TargetView, so the
// stored configuration blob — which holds the target's // stored configuration blob — which holds the target's
@@ -815,16 +808,18 @@ func (h *Handlers) parsePage(r *http.Request) int {
} }
// loadEventsWithDeliveries loads paginated events and their // loadEventsWithDeliveries loads paginated events and their
// deliveries from the per-webhook database. // deliveries from the per-webhook database. Events come back
// as capped projections rather than database.Event rows: see
// eventLogColumns for why the cut happens in SQL.
func (h *Handlers) loadEventsWithDeliveries( func (h *Handlers) loadEventsWithDeliveries(
w http.ResponseWriter, w http.ResponseWriter,
webhook database.Webhook, webhook database.Webhook,
targetMap map[string]delivery.TargetView, targetMap map[string]delivery.TargetView,
page int, page int,
) ([]EventWithDeliveries, int64) { ) ([]EventLogView, int64) {
var totalEvents int64 var totalEvents int64
var result []EventWithDeliveries var result []EventLogView
if !h.dbMgr.DBExists(webhook.ID) { if !h.dbMgr.DBExists(webhook.ID) {
return result, totalEvents return result, totalEvents
@@ -845,23 +840,25 @@ func (h *Handlers) loadEventsWithDeliveries(
offset := (page - 1) * paginationPerPage offset := (page - 1) * paginationPerPage
var events []database.Event var rows []eventLogRow
webhookDB.Where( webhookDB.Model(&database.Event{}).Select(
eventLogColumns, maxRenderedBodyBytes,
).Where(
"webhook_id = ?", webhook.ID, "webhook_id = ?", webhook.ID,
).Order("created_at DESC").Offset(offset).Limit( ).Order("created_at DESC").Offset(offset).Limit(
paginationPerPage, paginationPerPage,
).Find(&events) ).Find(&rows)
result = make([]EventWithDeliveries, len(events)) result = make([]EventLogView, len(rows))
for i := range events { for i := range rows {
result[i].Event = events[i] result[i] = rows[i].view()
var deliveries []database.Delivery var deliveries []database.Delivery
webhookDB.Where( webhookDB.Where(
"event_id = ?", events[i].ID, "event_id = ?", rows[i].ID,
).Find(&deliveries) ).Find(&deliveries)
result[i].Deliveries = newDeliveryViews( result[i].Deliveries = newDeliveryViews(

View File

@@ -11,6 +11,7 @@ import (
"testing" "testing"
"github.com/go-chi/chi" "github.com/go-chi/chi"
chimw "github.com/go-chi/chi/middleware"
"github.com/stretchr/testify/assert" "github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require" "github.com/stretchr/testify/require"
"sneak.berlin/go/webhooker/internal/config" "sneak.berlin/go/webhooker/internal/config"
@@ -25,15 +26,38 @@ const floodRequests = 64
// line for a redirected or rejected request may contain it. // line for a redirected or rejected request may contain it.
const attackerMarker = "QQATTACKERTEXTQQ" const attackerMarker = "QQATTACKERTEXTQQ"
// maxLineBytes bounds a single access log line. Well above what the // maxLineBytes bounds a single access log line whose client-supplied
// fixed fields need, well below the length of the oversized path the // fields are of ordinary size. Well above what the fixed fields need,
// amplification test sends. // well below the length of the oversized input the amplification tests
// send.
const maxLineBytes = 1024 const maxLineBytes = 1024
// maxCappedLineBytes bounds a single access log line when every
// client-supplied field arrives oversized and is truncated to its
// budget. This is the number the README quotes as the per-line cost an
// operator sizes log storage against.
const maxCappedLineBytes = 2560
// oversizedSegmentBytes is the length of the single attacker-chosen // oversizedSegmentBytes is the length of the single attacker-chosen
// path segment used to show line size does not track input size. // path segment, query string or header used to show line size does not
// track input size.
const oversizedSegmentBytes = 8192 const oversizedSegmentBytes = 8192
// tailMarker is placed at the END of an oversized header value, so its
// absence from the log proves the value was truncated rather than
// merely being short.
const tailMarker = "QQTRUNCATEDTAILQQ"
// These mirror the middleware's own budgets, which are unexported.
// They are duplicated rather than exported so that widening a budget
// in the middleware has to be restated here deliberately.
const (
maxFieldBytes = 512
maxRequestIDBytes = 128
truncationSuffix = "[truncated]"
unmatchedRouteLiteral = "(unmatched)"
)
// capturingMiddleware returns a Middleware whose logger writes JSON // capturingMiddleware returns a Middleware whose logger writes JSON
// lines into the returned buffer, so the access log can be asserted // lines into the returned buffer, so the access log can be asserted
// on directly. // on directly.
@@ -54,11 +78,23 @@ func capturingMiddleware(t *testing.T) (*middleware.Middleware, *bytes.Buffer) {
// accessLogRouter mirrors the production route shapes that an // accessLogRouter mirrors the production route shapes that an
// unauthenticated client can reach: the public receiver, the // unauthenticated client can reach: the public receiver, the
// authenticated profile route (which redirects to login rather than // authenticated profile route (which redirects to login rather than
// rejecting outright), and a plain static route. // rejecting outright), the health check (which answers 200 to anyone,
// behind no rate limiter at all), and a plain static route.
func accessLogRouter(m *middleware.Middleware) *chi.Mux { func accessLogRouter(m *middleware.Middleware) *chi.Mux {
router := chi.NewRouter() router := chi.NewRouter()
// Production registers RequestID ahead of Logging, and chi's
// RequestID passes an inbound X-Request-Id header straight
// through, so the request_id field is client-supplied too.
router.Use(chimw.RequestID)
router.Use(m.Logging()) router.Use(m.Logging())
router.Get(
"/.well-known/healthcheck",
func(w http.ResponseWriter, _ *http.Request) {
w.WriteHeader(http.StatusOK)
},
)
router.HandleFunc( router.HandleFunc(
"/webhook/{uuid}", "/webhook/{uuid}",
func(w http.ResponseWriter, r *http.Request) { func(w http.ResponseWriter, r *http.Request) {
@@ -93,13 +129,25 @@ func accessLogRouter(m *middleware.Middleware) *chi.Mux {
} }
// accessLogEntries decodes the captured buffer into one map per // accessLogEntries decodes the captured buffer into one map per
// logged line. // logged line, holding every line to maxLineBytes.
func accessLogEntries( func accessLogEntries(
t *testing.T, t *testing.T,
buf *bytes.Buffer, buf *bytes.Buffer,
) []map[string]any { ) []map[string]any {
t.Helper() t.Helper()
return accessLogEntriesWithin(t, buf, maxLineBytes)
}
// accessLogEntriesWithin decodes the captured buffer into one map per
// logged line, holding every line to bound bytes.
func accessLogEntriesWithin(
t *testing.T,
buf *bytes.Buffer,
bound int,
) []map[string]any {
t.Helper()
var entries []map[string]any var entries []map[string]any
for line := range strings.SplitSeq( for line := range strings.SplitSeq(
@@ -110,7 +158,7 @@ func accessLogEntries(
} }
require.LessOrEqual( require.LessOrEqual(
t, len(line), maxLineBytes, t, len(line), bound,
"access log line exceeded its bound", "access log line exceeded its bound",
) )
@@ -128,9 +176,27 @@ func accessLogEntries(
func get(t *testing.T, router *chi.Mux, target string) int { func get(t *testing.T, router *chi.Mux, target string) int {
t.Helper() t.Helper()
return getWithHeaders(t, router, target, nil)
}
// getWithHeaders drives one GET through the router with the supplied
// request headers set.
func getWithHeaders(
t *testing.T,
router *chi.Mux,
target string,
headers map[string]string,
) int {
t.Helper()
req := httptest.NewRequestWithContext( req := httptest.NewRequestWithContext(
context.Background(), http.MethodGet, target, nil, context.Background(), http.MethodGet, target, nil,
) )
for name, value := range headers {
req.Header.Set(name, value)
}
w := httptest.NewRecorder() w := httptest.NewRecorder()
router.ServeHTTP(w, req) router.ServeHTTP(w, req)
@@ -217,26 +283,134 @@ func TestAccessLog_UnroutablePathsLogFixedLiteral(t *testing.T) {
) )
} }
// TestAccessLog_LineSizeDoesNotTrackInputSize drives 8 KB of
// client-chosen text at the access log through each part of the
// request that reaches it, and holds the resulting line to a fixed
// bound in every case.
func TestAccessLog_LineSizeDoesNotTrackInputSize(t *testing.T) { func TestAccessLog_LineSizeDoesNotTrackInputSize(t *testing.T) {
t.Parallel() t.Parallel()
oversized := strings.Repeat("h", oversizedSegmentBytes) + tailMarker
tests := map[string]struct {
target string
headers map[string]string
wantStatus int
wantURL string
bound int
}{
"oversized path segment": {
target: "/webhook/" + attackerMarker +
strings.Repeat("x", oversizedSegmentBytes),
wantStatus: http.StatusNotFound,
wantURL: "/webhook/{uuid}",
bound: maxLineBytes,
},
// /.well-known/healthcheck answers 200 to anyone and has no
// rate limiter in front of it, so an oversized query appended
// to it would otherwise buy the same amplification as an
// invented 404 path, unauthenticated and unthrottled.
"oversized query on an unauthenticated 200": {
target: "/.well-known/healthcheck?q=" + attackerMarker +
strings.Repeat("x", oversizedSegmentBytes),
wantStatus: http.StatusOK,
wantURL: "/.well-known/healthcheck?(redacted)",
bound: maxLineBytes,
},
// These reach the line on every request, including one whose
// url field is correctly redacted.
"oversized headers": {
target: "/" + attackerMarker,
headers: map[string]string{
"User-Agent": oversized,
"Referer": oversized,
"X-Request-Id": oversized,
},
wantStatus: http.StatusNotFound,
wantURL: unmatchedRouteLiteral,
bound: maxCappedLineBytes,
},
}
for name, tc := range tests {
t.Run(name, func(t *testing.T) {
t.Parallel()
m, buf := capturingMiddleware(t)
router := accessLogRouter(m)
assert.Equal(
t,
tc.wantStatus,
getWithHeaders(t, router, tc.target, tc.headers),
)
// accessLogEntriesWithin enforces the bound, which is
// orders of magnitude smaller than the input just sent.
entries := accessLogEntriesWithin(t, buf, tc.bound)
require.Len(t, entries, 1)
assert.Equal(t, tc.wantURL, entries[0]["url"])
// The markers sit at the far end of the client-chosen
// text, so their absence is what proves the redaction and
// the truncation actually ran.
assert.NotContains(
t, buf.String(), attackerMarker,
"access log carried attacker-chosen text",
)
assert.NotContains(
t, buf.String(), tailMarker,
"access log carried an untruncated client field",
)
})
}
}
// TestAccessLog_OversizedHeadersKeepATruncatedPrefix checks the other
// half of the header cap: the fields are cut, not dropped, so a
// truncated User-Agent is still worth reading.
func TestAccessLog_OversizedHeadersKeepATruncatedPrefix(t *testing.T) {
t.Parallel()
m, buf := capturingMiddleware(t) m, buf := capturingMiddleware(t)
router := accessLogRouter(m) router := accessLogRouter(m)
target := "/webhook/" + attackerMarker + oversized := strings.Repeat("h", oversizedSegmentBytes) + tailMarker
strings.Repeat("x", oversizedSegmentBytes)
assert.Equal(t, http.StatusNotFound, get(t, router, target)) assert.Equal(
t,
http.StatusNotFound,
getWithHeaders(
t, router, "/nope",
map[string]string{
"User-Agent": oversized,
"Referer": oversized,
"X-Request-Id": oversized,
},
),
)
// accessLogEntries enforces maxLineBytes, which is far smaller entries := accessLogEntriesWithin(t, buf, maxCappedLineBytes)
// than the path just sent.
entries := accessLogEntries(t, buf)
require.Len(t, entries, 1) require.Len(t, entries, 1)
assert.Equal(t, "/webhook/{uuid}", entries[0]["url"])
assert.NotContains(t, buf.String(), attackerMarker) for key, budget := range map[string]int{
"useragent": maxFieldBytes,
"referer": maxFieldBytes,
"request_id": maxRequestIDBytes,
} {
value, ok := entries[0][key].(string)
require.True(t, ok, key)
assert.LessOrEqual(
t, len(value), budget+len(truncationSuffix), key,
)
assert.Contains(t, value, truncationSuffix, key)
assert.Contains(t, value, "hhhh", key)
}
} }
func TestAccessLog_SuccessKeepsConcreteURL(t *testing.T) { func TestAccessLog_SuccessKeepsConcretePathAndRedactsQuery(
t *testing.T,
) {
t.Parallel() t.Parallel()
m, buf := capturingMiddleware(t) m, buf := capturingMiddleware(t)
@@ -246,9 +420,12 @@ func TestAccessLog_SuccessKeepsConcreteURL(t *testing.T) {
t, http.StatusOK, get(t, router, "/webhook/known?src=ci"), t, http.StatusOK, get(t, router, "/webhook/known?src=ci"),
) )
// The path resolved against a stored entrypoint, so it stays. The
// query never does: see TestAccessLog_UnauthenticatedSuccess...
entries := accessLogEntries(t, buf) entries := accessLogEntries(t, buf)
require.Len(t, entries, 1) require.Len(t, entries, 1)
assert.Equal(t, "/webhook/known?src=ci", entries[0]["url"]) assert.Equal(t, "/webhook/known?(redacted)", entries[0]["url"])
assert.NotContains(t, buf.String(), "src=ci")
} }
func TestAccessLog_ServerErrorKeepsConcreteURL(t *testing.T) { func TestAccessLog_ServerErrorKeepsConcreteURL(t *testing.T) {

View File

@@ -6,6 +6,7 @@ import (
"log/slog" "log/slog"
"net" "net"
"net/http" "net/http"
"strings"
"time" "time"
basicauth "github.com/99designs/basicauth-go" basicauth "github.com/99designs/basicauth-go"
@@ -32,6 +33,35 @@ const (
// all. Every byte of such a path is client-chosen, so none of it // all. Every byte of such a path is client-chosen, so none of it
// is logged. // is logged.
unmatchedRoute = "(unmatched)" unmatchedRoute = "(unmatched)"
// redactedQuery stands in for the query string on the access log
// branches that keep the concrete URL. The query is client-chosen
// on every route, including the ones that answer an
// unauthenticated 200, so logging it verbatim would let a client
// 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. 512 bytes holds a real browser's User-Agent whole, so a
// truncated one is still worth having.
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
// order of magnitude shorter than this.
maxLogRequestIDBytes = 128
// maxLogMethodBytes bounds the method. Go accepts any RFC 7230
// token there, bounded only by the header size limit, so it is
// client-chosen text like the rest. The longest registered method
// 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.
truncationMarker = "[truncated]"
) )
//nolint:revive // MiddlewareParams is a standard fx naming convention. //nolint:revive // MiddlewareParams is a standard fx naming convention.
@@ -101,13 +131,58 @@ func (lrw *loggingResponseWriter) WriteHeader(code int) {
lrw.ResponseWriter.WriteHeader(code) lrw.ResponseWriter.WriteHeader(code)
} }
// truncateLogField caps s at maxBytes, marking the value when it cuts.
//
// The result is always valid UTF-8: a byte-boundary cut can split a
// multi-byte rune, and a header can carry bytes that were never valid
// UTF-8 to begin with, either of which a JSON encoder expands to six
// bytes apiece. Dropping them keeps the encoded field inside the same
// budget as the raw one.
func truncateLogField(s string, maxBytes int) string {
if len(s) <= maxBytes {
return strings.ToValidUTF8(s, "")
}
return strings.ToValidUTF8(s[:maxBytes], "") + 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.
//
// The path on those branches is bounded by the service's routes or by
// the operator's data — a 2xx on the receiver means the UUID named a
// stored entrypoint, a 2xx under /s means the file is in the embedded
// tree. The query is not bounded by anything: /.well-known/healthcheck
// and /s/* take no authentication and sit behind no rate limiter, and
// /pages/login behind only the login limiter, so any of them will
// answer 200 to a URL carrying an arbitrary number of arbitrary bytes
// after the '?'. Keeping the path and dropping the query is what makes
// this branch as bounded as the pattern branches below.
//
// Nothing debuggable is lost. One route in the service reads a query
// parameter at all — `page`, on the authenticated pagination links in
// internal/handlers/source_management.go — and the alternatives that
// would preserve more (a key count, a key allowlist) all require
// parsing an attacker-sized query on every request, which is work an
// unauthenticated client would then be choosing for us.
func concreteLogURL(r *http.Request) string {
path := r.URL.EscapedPath()
if r.URL.RawQuery == "" && !r.URL.ForceQuery {
return path
}
return path + redactedQuery
}
// accessLogURL returns the value for the access log's url field. // accessLogURL returns the value for the access log's url field.
// //
// 2xx and 5xx responses get the concrete URL. A success resolved // 2xx and 5xx responses get the concrete path (see concreteLogURL). A
// against a static route or against the operator's own data — on the // success resolved against a static route or against the operator's
// receiver, a 2xx means the UUID named a stored entrypoint — and a // own data — on the receiver, a 2xx means the UUID named a stored
// server error is our own bug, where the exact URL is the primary // entrypoint — and a server error is our own bug, where the exact URL
// evidence and which no client can provoke at will. // is the primary evidence and which no client can provoke at will.
// //
// 3xx and 4xx responses get the chi route pattern instead. Those are // 3xx and 4xx responses get the chi route pattern instead. Those are
// the outcomes an unauthenticated client drives for free: 404 or 429 // the outcomes an unauthenticated client drives for free: 404 or 429
@@ -123,7 +198,7 @@ func (lrw *loggingResponseWriter) WriteHeader(code int) {
func accessLogURL(r *http.Request, status int) string { func accessLogURL(r *http.Request, status int) string {
if status < http.StatusMultipleChoices || if status < http.StatusMultipleChoices ||
status >= http.StatusInternalServerError { status >= http.StatusInternalServerError {
return r.URL.String() return concreteLogURL(r)
} }
if rc := chi.RouteContext(r.Context()); rc != nil { if rc := chi.RouteContext(r.Context()); rc != nil {
@@ -159,13 +234,27 @@ func (s *Middleware) Logging() func(http.Handler) http.Handler {
} }
} }
// Every field below that a client can influence is
// truncated to a fixed budget, so the size of this
// line does not track the size of the request.
s.log.Info("http request", s.log.Info("http request",
"request_start", start, "request_start", start,
"method", r.Method, "method", truncateLogField(
"url", accessLogURL(r, lrw.statusCode), r.Method, maxLogMethodBytes,
"useragent", r.UserAgent(), ),
"request_id", requestID, "url", truncateLogField(
"referer", r.Referer(), accessLogURL(r, lrw.statusCode),
maxLogFieldBytes,
),
"useragent", truncateLogField(
r.UserAgent(), maxLogFieldBytes,
),
"request_id", truncateLogField(
requestID, maxLogRequestIDBytes,
),
"referer", truncateLogField(
r.Referer(), maxLogFieldBytes,
),
"proto", r.Proto, "proto", r.Proto,
"remoteIP", ipFromHostPort(r.RemoteAddr), "remoteIP", ipFromHostPort(r.RemoteAddr),
"status", lrw.statusCode, "status", lrw.statusCode,

View File

@@ -37,6 +37,9 @@
<div x-show="open" x-cloak class="mt-3 p-3 bg-gray-50 rounded-md"> <div x-show="open" x-cloak class="mt-3 p-3 bg-gray-50 rounded-md">
<pre class="text-xs text-gray-700 overflow-x-auto whitespace-pre-wrap break-all">{{.Body}}</pre> <pre class="text-xs text-gray-700 overflow-x-auto whitespace-pre-wrap break-all">{{.Body}}</pre>
{{if .BodyTruncated}}
<p class="mt-2 text-xs text-gray-500">Body truncated for display: showing {{.BodyShownBytes}} of {{.BodyBytes}} bytes. The stored body is unchanged.</p>
{{end}}
</div> </div>
</div> </div>
{{else}} {{else}}