Bound the event log's rendered bodies in the query (closes #135)
All checks were successful
check / check (push) Successful in 3m16s
All checks were successful
check / check (push) Successful in 3m16s
templates/source_logs.html rendered {{.Body}} untruncated. Bodies come
from the unauthenticated receiver under a 1 MB ingest cap, and since
renderTemplate started buffering a page instead of streaming it, a
25-event page of maximal bodies is tens of megabytes of resident memory
per concurrent viewer — inflated further by HTML escaping.
The cut happens in SQL, not in the template: loadEventsWithDeliveries
now selects substr(cast(body as blob), 1, 8192) with
length(cast(body as blob)) beside it, so an oversized body never
becomes a Go string at all. Truncating template-side would still
materialise the whole value and miss the point. The casts to blob make
substr and length count bytes rather than characters, so the bound
holds for any encoding.
Events reach the page as EventLogView, alongside the existing
DeliveryView and TargetView projections, carrying BodyTruncated and
BodyBytes so the page shows a marker with the true stored size.
SQLite cuts at an arbitrary byte, so trimPartialRune drops a trailing
sequence the cut left incomplete. Bytes that are merely invalid UTF-8 —
binary payloads, which this service receives — are left exactly as
stored: utf8.FullRune reports a complete sequence for an invalid
encoding too, so only a valid prefix awaiting its continuation bytes is
removed, and a tail with no rune start in its last utf8.UTFMax bytes is
untouched. A body that was not cut is never repaired.
Also corrects the executeTemplate comment that claimed these pages are
small.
This commit is contained in:
120
internal/handlers/event_log_view.go
Normal file
120
internal/handlers/event_log_view.go
Normal 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
|
||||
}
|
||||
258
internal/handlers/event_log_view_test.go
Normal file
258
internal/handlers/event_log_view_test.go
Normal 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, ""kept"")
|
||||
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),
|
||||
)
|
||||
})
|
||||
}
|
||||
}
|
||||
@@ -3,8 +3,35 @@ package handlers
|
||||
import (
|
||||
"html/template"
|
||||
"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
|
||||
// the handlers_test package can drive the render path with a
|
||||
// template of its own.
|
||||
|
||||
@@ -229,8 +229,10 @@ func (s *Handlers) renderTemplate(
|
||||
// the response only once rendering has fully succeeded. Executing
|
||||
// straight into the ResponseWriter commits a partial body and a 200
|
||||
// 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
|
||||
// the right trade.
|
||||
// to serve a 500. Buffering makes a page's rendered size resident
|
||||
// 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(
|
||||
w http.ResponseWriter,
|
||||
tmpl *template.Template,
|
||||
|
||||
@@ -92,13 +92,6 @@ func parseRetentionDays(raw string, fallback int) (int, error) {
|
||||
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
|
||||
// for the event log page. Its target is a TargetView, so the
|
||||
// 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
|
||||
// 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(
|
||||
w http.ResponseWriter,
|
||||
webhook database.Webhook,
|
||||
targetMap map[string]delivery.TargetView,
|
||||
page int,
|
||||
) ([]EventWithDeliveries, int64) {
|
||||
) ([]EventLogView, int64) {
|
||||
var totalEvents int64
|
||||
|
||||
var result []EventWithDeliveries
|
||||
var result []EventLogView
|
||||
|
||||
if !h.dbMgr.DBExists(webhook.ID) {
|
||||
return result, totalEvents
|
||||
@@ -845,23 +840,25 @@ func (h *Handlers) loadEventsWithDeliveries(
|
||||
|
||||
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,
|
||||
).Order("created_at DESC").Offset(offset).Limit(
|
||||
paginationPerPage,
|
||||
).Find(&events)
|
||||
).Find(&rows)
|
||||
|
||||
result = make([]EventWithDeliveries, len(events))
|
||||
result = make([]EventLogView, len(rows))
|
||||
|
||||
for i := range events {
|
||||
result[i].Event = events[i]
|
||||
for i := range rows {
|
||||
result[i] = rows[i].view()
|
||||
|
||||
var deliveries []database.Delivery
|
||||
|
||||
webhookDB.Where(
|
||||
"event_id = ?", events[i].ID,
|
||||
"event_id = ?", rows[i].ID,
|
||||
).Find(&deliveries)
|
||||
|
||||
result[i].Deliveries = newDeliveryViews(
|
||||
|
||||
Reference in New Issue
Block a user