Compare commits

1 Commits

Author SHA1 Message Date
ce36f430fb Route GORM's logger through slog and bound it (closes #178)
All checks were successful
check / check (push) Successful in 2m54s
GORM's default logger printed the fully interpolated SQL to standard
output on every statement that returned an error, including a plain
record-not-found. On /webhook/{uuid} and on the login form the
interpolated parameter is client-chosen and unbounded, so an
unauthenticated client sized the operator's log, one line per request,
at no level the operator could turn down.

Every gorm.Open in the service now installs internal/gormlog, a
gormlogger.Interface over the service's *slog.Logger. Its lines take
the level the operator set and the handler internal/logger selected; a
record-not-found is not logged at all, since it is the expected
outcome on both of those paths and each handler already records its
own miss at DEBUG without the SQL; slow statements are kept at WARN
above the same 200ms threshold GORM used; and every value it emits is
spent through an encoded-byte budget.

That budget is internal/middleware's truncateLogField, moved to a new
internal/logfield package now that a second writer needs it. The move
is unchanged logic. MaxAccessLogLineBytes bounds a GORM line too, and
internal/gormlog asserts each line against the constant directly.

The third gorm.Open, in the archive writer, was not named in the issue
and had the same default.

README: the ceiling now covers GORM; the writers it does not cover are
named, including net/http's nil ErrorLog, fx's console logger and the
Go runtime, none of which carry a client-chosen value.
2026-08-18 00:24:57 +00:00
9 changed files with 193 additions and 945 deletions

154
README.md
View File

@@ -1037,77 +1037,38 @@ reduces the headers to a fixed allowlist — `Accept`, `Content-Length`,
`Content-Type`, `Host`, `Origin`, `Referer`, `User-Agent` and
`X-Request-Id`.
The same hook rewrites the request URL. The SDK builds it as
`scheme://host/path` from the concrete path, which on the receiver
route is `/webhook/<uuid>` in full — and that UUID is a write
capability, not an identifier: anyone holding it can post events this
service accepts and its targets then deliver. A tracker has its own
retention, access control and deletion policy, so the rule the access
log follows above does not carry across that boundary. What is sent is
the chi route pattern instead: `http://host/webhook/{uuid}`.
The scheme and the host are kept, and everything else in the URL is
discarded rather than edited, so a future SDK version that starts
appending a query string cannot widen this. The scheme has to survive
for the reason given below. The host is whatever the request's `Host`
header carried — this service validates no hostname, so on a directly
exposed deployment a client sets it — and that same header is on the
allowlist above, so scrubbing the host out of the URL would withhold
nothing that is not sent anyway.
The body, the query string and the URL are all handled on every route
rather than filtered by route. For the URL that is also what keeps the
event locatable: an error event is grouped by its exception and stack
trace, not by its URL, so replacing the path with the pattern costs no
grouping and the pattern still names the route in the UI. And an
unconditional rule cannot leak on a route somebody forgets to add to
it, which a route-conditional one can. For the body there is a second
reason: nothing debuggable is lost, because every handler reads its
fields with `PostFormValue`, so the body is exactly where the
credentials are — the target destination URL, the login password, both
password-change fields — and the one route whose body is genuine
signal is the receiver, whose body is already stored on the event and
served from the UI, so a tracker is not where anyone reads it.
The route is reachable from the hook only on the error dispatch.
`sentryhttp`'s recover path puts the request on the context it hands
to `RecoverWithContext`, and the SDK carries that context through to
`BeforeSend` as `hint.Context`, so
The body is replaced on every route rather than filtered by route, and
that is a choice rather than a limitation: the route is reachable from
the hook. `sentryhttp`'s recover path puts the request on the context
it hands to `RecoverWithContext`, and the SDK carries that context
through to `BeforeSend` as `hint.Context`, so
`hint.Context.Value(sentry.RequestContextKey)` yields the live request
and chi's `RoutePattern()` yields the matched pattern off it. The
transaction dispatch has no such request: a finished span captures
with a nil hint, which the client replaces with an empty one, so
`BeforeSendTransaction` sees no context at all. Tracing is off in this
service, so no transaction event is produced today, but the hook is
installed on both dispatches as a floor.
and chi's `RoutePattern()` yields the matched pattern off it. There
are two reasons to redact unconditionally anyway. Nothing debuggable
is lost:
every handler reads its fields with `PostFormValue`, so the body is
exactly where the credentials are — the target destination URL, the
login password, both password-change fields — and the one route whose
body is genuine signal is the receiver, whose body is already stored
on the event and served from the UI, so a tracker is not where anyone
reads it. And an unconditional rule cannot leak on a route somebody
forgets to add to it, which a route-conditional one can.
Where the pattern is out of reach — the transaction dispatch, an event
captured outside the router, or a request that matched no route — the
fallback is never the concrete path. The path becomes the literal
`/(redacted)`, so the URL reads `http://host/(redacted)`; a URL the
rewrite cannot parse into a scheme is withheld whole. A transaction
event additionally carries the SDK's own `METHOD /path` name, built
from the concrete path as well; it is rewritten on the same terms, to
`POST /webhook/{uuid}` where the pattern is known and `POST
/(redacted)` where it is not.
The headers are an allowlist for the same reason the rules above are
unconditional: the SDK's own filter removes four names and passes
everything else, which would ship `X-CSRF-Token` and the shared
secrets senders put on the receiver route. What survives still names
the failing route — scheme, host, route pattern, method — and
`X-Request-Id` ties the event to the local access log line that holds
the rest. Nothing dropped is needed for the likeliest use, debugging a
CSRF rejection. Its three inputs are the TLS decision, `Origin` and
`Referer`; the latter two are kept, and the first is the scheme of the
retained URL, because the SDK derives that scheme from
`r.TLS != nil || r.Header.Get("X-Forwarded-Proto") == "https"` — byte
for byte the predicate `internal/middleware/csrf.go` uses to choose
between the `csrf.Secure(true)` and `csrf.Secure(false)` handlers.
That is what the rewrite above preserves it for, and it is why
dropping `X-Forwarded-Proto` costs nothing. The dropped provider
headers (`X-GitHub-Event`, `X-Gitlab-Event` and the like) are real
signal but are recorded locally on the event, and
The headers are an allowlist for that second reason: the SDK's own
filter removes four names and passes everything else, which would ship
`X-CSRF-Token` and the shared secrets senders put on the receiver
route. What survives still names the failing route — scheme, host,
path, method — and `X-Request-Id` ties the event to the local access
log line that holds the rest. Nothing dropped is needed for the
likeliest use, debugging a CSRF rejection. Its three inputs are the
TLS decision, `Origin` and `Referer`; the latter two are kept, and the
first is already in the retained URL, because the SDK derives that
URL's scheme from `r.TLS != nil || r.Header.Get("X-Forwarded-Proto") == "https"`
byte for byte the predicate `internal/middleware/csrf.go` uses to
choose between the `csrf.Secure(true)` and `csrf.Secure(false)`
handlers. So dropping `X-Forwarded-Proto` costs nothing. The dropped
provider headers (`X-GitHub-Event`, `X-Gitlab-Event` and the like) are
real signal but are recorded locally on the event, and
`Sentry-Trace`/`Baggage` are already reflected in the event's trace
context.
@@ -1165,15 +1126,11 @@ writes through the same `slog` logger as everything else, so its lines
take the level the operator set and the handler `internal/logger`
selected, and every value it emits is spent through the same 512-byte
encoded budget (`internal/logfield`). A record-not-found is not logged
as an error: it is the expected outcome on both of those paths, and
each handler already records its own miss at `DEBUG`, without the SQL.
Slow statements are kept — at `WARN`, above the same 200 ms threshold
GORM used, with the statement bounded — because that report is the one
thing GORM's logger gave an operator that nothing else here does, and
a statement that both missed and ran slow is still reported as slow.
The adapter orders those cases exactly as GORM's own `Trace` orders
them, so dropping the miss costs an operator no report that GORM's
`IgnoreRecordNotFoundError` would have kept. A
at all: it is the expected outcome on both of those paths, and each
handler already records its own miss at `DEBUG`, without the SQL. Slow
statements are kept — at `WARN`, above the same 200 ms threshold GORM
used, with the statement bounded — because that report is the one
thing GORM's logger gave an operator that nothing else here does. A
GORM line spends at most two of those budgets, the statement and the
driver error, against a smaller fixed portion than the access log's;
`internal/gormlog/gormlog_test.go` asserts each line against
@@ -1194,37 +1151,16 @@ no stated bound at all.
the target is for. Each line is bounded per event by the 1 MB
receiver body cap, and it costs nothing unless an authenticated
operator creates a target of that type.
- Two writers that do not go through `internal/logger` at all, both on
standard error. `fx` prints the dependency graph and the lifecycle
hooks through its default console logger at startup and shutdown —
nothing calls `fx.WithLogger`, and `fx.New` builds that logger over
`os.Stderr`. The Go runtime writes a panic or a fatal error itself;
a panic in a background worker rather than in a request handler is
the case that reaches it, since nothing recovers those. Neither
carries a client-chosen value at a client-chosen length: the five
`panic` calls in this service are invariant guards over constants
and over `crypto/rand`.
- `net/http`'s own faults, which are **not** a separate writer.
`internal/server/http.go` builds its server with a nil `ErrorLog`,
so `net/http` falls back to the `log` package's default logger — and
`internal/logger` calls `slog.SetDefault`, which redirects that
logger into whichever handler it installed. Those lines therefore
arrive on standard output, shaped like every other line, at `INFO`.
They are not truncated and they are not bounded by the ceiling: a
handler panic arrives as one record carrying a whole goroutine
stack, measured at 2,772 bytes against the ceiling's 2,560. The
value is the runtime's, not a client's.
- A handler panic reaches that path rather than the one it looks like
it should. `internal/server/routes.go` installs chi's
`middleware.Recoverer` in front of every route, which is meant to
print the panic and its stack to standard error and answer 500. On
the Go version this service builds against it does neither: chi
v1.5.5's stack pretty-printer looks for a `panic(0x` frame that the
runtime no longer emits, walks past the end of its own slice, and
panics before writing a byte. That second panic escapes to
`net/http`, which drops the connection and reports it through the
nil `ErrorLog` above. Tracked separately in
https://git.eeqj.de/sneak/webhooker/issues/187.
- Three writers that do not go through `internal/logger` at all, all
of them on standard error. `net/http` builds its server with a nil
`ErrorLog`, so its own faults — a handler panic and its stack, a
superfluous `WriteHeader` — go to the `log` package's default
logger. `fx` prints the dependency graph and the lifecycle hooks
through its console logger at startup and shutdown. The Go runtime
writes a panic or a fatal error itself. None of the three carries a
client-chosen value at a client-chosen length: the three `panic`
calls in this service are invariant guards over constants and over
`crypto/rand`.
Every limiter here — receiver, login, and password change — identifies
the client the same way, through one shared key function: the

View File

@@ -1,155 +0,0 @@
package delivery_test
import (
"bytes"
"log"
"log/slog"
"path/filepath"
"strings"
"sync"
"testing"
"time"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"gorm.io/gorm"
gormlogger "gorm.io/gorm/logger"
"sneak.berlin/go/webhooker/internal/delivery"
"sneak.berlin/go/webhooker/internal/middleware"
)
// archiveGORMTailMarker sits at the far end of the value this file
// drives into an archive lookup. Its presence in a log line means the
// whole value reached the log, so nothing truncated it.
const archiveGORMTailMarker = "ENDOFCLIENTVALUE"
// archiveGORMFillBytes is how much text the lookup carries. It is far
// past every budget in play.
const archiveGORMFillBytes = 8 << 10
// gormDefaultBuf collects what GORM's package-level default logger
// writes, if anything reaches it.
type gormDefaultBuf struct {
mu sync.Mutex
b bytes.Buffer
}
func (g *gormDefaultBuf) Write(p []byte) (int, error) {
g.mu.Lock()
defer g.mu.Unlock()
return g.b.Write(p)
}
func (g *gormDefaultBuf) String() string {
g.mu.Lock()
defer g.mu.Unlock()
return g.b.String()
}
// captureArchiveGORMDefault replaces GORM's package-level default
// logger with one configured exactly as GORM configures its own,
// writing to a buffer.
//
// This duplicates the detector in internal/handlers rather than
// sharing it: a test helper cannot cross a package's test boundary
// without exporting production code to carry it, and a logging
// detector is not worth a production symbol. What it detects is the
// third gorm.Open in this service, at
// internal/delivery/target_database_archive.go — the archive writer,
// whose type is unexported, so nothing outside this package can drive
// it.
func captureArchiveGORMDefault(t *testing.T) *gormDefaultBuf {
t.Helper()
buf := &gormDefaultBuf{}
orig := gormlogger.Default
gormlogger.Default = gormlogger.New(
log.New(buf, "", log.LstdFlags),
gormlogger.Config{
SlowThreshold: 200 * time.Millisecond,
LogLevel: gormlogger.Warn,
IgnoreRecordNotFoundError: false,
Colorful: false,
},
)
t.Cleanup(func() { gormlogger.Default = orig })
return buf
}
// TestArchiveWriter_NeverUsesGORMsDefaultLogger pins the archive
// writer's gorm.Open to the adapter.
//
// Restore a bare &gorm.Config{} at
// internal/delivery/target_database_archive.go and this fails: the
// default logger prints the fully interpolated SELECT on every
// ErrRecordNotFound, so the client-chosen event id below arrives whole
// and unbounded on stdout, answering to no level the operator set.
//
// Not parallel: gormlogger.Default is process-global. Go runs every
// non-parallel top-level test to completion before it resumes the
// parallel ones.
//
//nolint:paralleltest // Deliberately sequential; see above.
func TestArchiveWriter_NeverUsesGORMsDefaultLogger(t *testing.T) {
var captured bytes.Buffer
gormDefault := captureArchiveGORMDefault(t)
w := delivery.NewExportArchiveWriter(
filepath.Join(t.TempDir(), "archive.db"),
slog.New(slog.NewTextHandler(
&captured, &slog.HandlerOptions{Level: slog.LevelDebug},
)),
0,
)
require.NoError(t, w.Open(0))
t.Cleanup(w.Evict)
// A lookup that misses, carrying a value the size of an inbound
// event id. Under the default logger this is the line that gets
// interpolated and printed.
value := strings.Repeat("\x01", archiveGORMFillBytes) +
archiveGORMTailMarker
var row delivery.ExportArchivedEvent
err := w.DB().Where("event_id = ?", value).First(&row).Error
require.ErrorIs(t, err, gorm.ErrRecordNotFound)
got := gormDefault.String()
assert.Empty(
t, got,
"GORM's default logger wrote %d bytes, so the archive "+
"writer's gorm.Open is back on a bare &gorm.Config{}; "+
"the first of them: %s",
len(got), got[:min(len(got), 300)],
)
// The adapter drops a miss, so this should be silent too — and
// whatever it does write stays inside the stated ceiling.
out := captured.String()
assert.NotContains(
t, out, archiveGORMTailMarker,
"the far end of the client-chosen value reached the log",
)
for line := range strings.SplitSeq(strings.TrimRight(out, "\n"), "\n") {
if line == "" {
continue
}
assert.LessOrEqual(
t, len(line), middleware.MaxAccessLogLineBytes,
"log line exceeded its bound: %s",
line[:min(len(line), 300)],
)
}
}

View File

@@ -1,17 +1,9 @@
package gormlog
import (
"log/slog"
"time"
)
import "time"
// ExportNewWithSlowThreshold builds a Logger whose slow-statement
// threshold is d rather than DefaultSlowThreshold, so a test can pin
// which arm of Trace it is exercising instead of racing the clock on a
// loaded machine. The threshold is set at construction, like every
// other field, so the type's concurrency guarantee still holds.
func ExportNewWithSlowThreshold(
log *slog.Logger, d time.Duration,
) *Logger {
return &Logger{log: log, slowThreshold: d}
// ExportSetSlowThreshold overrides the slow-statement threshold so a
// test can drive the slow path without sleeping. Tests only.
func (l *Logger) ExportSetSlowThreshold(d time.Duration) {
l.slowThreshold = d
}

View File

@@ -96,14 +96,6 @@ func (l *Logger) Error(
// every statement it runs, so the cheap paths stay cheap: fc()
// renders the interpolated SQL and is called only on a branch that
// will actually emit.
//
// The arms are ordered exactly as GORM's own Trace orders them —
// non-record-not-found error, then slow, then the routine case — so
// that a statement which both misses and runs slow is still reported
// as slow. A miss is the likeliest statement to be slow, since it is
// the one that scans without finding a row, and ordering the drop
// ahead of the slow arm would have made this adapter less observant
// than the IgnoreRecordNotFoundError option it was chosen over.
func (l *Logger) Trace(
ctx context.Context,
begin time.Time,
@@ -122,15 +114,6 @@ func (l *Logger) Trace(
"elapsed_ms", elapsed.Milliseconds(),
)
case l.slowThreshold > 0 && elapsed >= l.slowThreshold:
sql, rows := fc()
l.log.WarnContext(ctx, "slow sql statement",
"sql", logfield.Truncate(sql, logfield.MaxBytes),
"rows", rows,
"elapsed_ms", elapsed.Milliseconds(),
"threshold_ms", l.slowThreshold.Milliseconds(),
)
case err != nil:
// gorm.ErrRecordNotFound is not an error on the paths that
// produce it here: an invented entrypoint UUID and an unknown
@@ -139,10 +122,18 @@ func (l *Logger) Trace(
// behaviour, and it is unconditional rather than configurable
// because no caller in this service wants the other one — the
// two handlers that care already record the miss themselves,
// at DEBUG, without the SQL. A miss that ran slow has already
// been reported by the arm above.
// at DEBUG, without the SQL.
return
case l.slowThreshold > 0 && elapsed >= l.slowThreshold:
sql, rows := fc()
l.log.WarnContext(ctx, "slow sql statement",
"sql", logfield.Truncate(sql, logfield.MaxBytes),
"rows", rows,
"elapsed_ms", elapsed.Milliseconds(),
"threshold_ms", l.slowThreshold.Milliseconds(),
)
case l.log.Enabled(ctx, slog.LevelDebug):
sql, rows := fc()
l.log.DebugContext(ctx, "sql statement",

View File

@@ -100,23 +100,12 @@ type thing struct {
Name string
}
// neverSlow is a slow-statement threshold no statement in this file
// can reach. Cases that are about a non-slow arm of Trace set it, so
// that a machine under load cannot turn a miss into a slow report and
// decide the outcome for them.
const neverSlow = time.Hour
// alwaysSlow makes every statement count as slow, so the slow arm is
// reached without the test waiting for it.
const alwaysSlow = time.Nanosecond
// openDB opens a real SQLite database behind the adapter under test,
// so every assertion below is made against SQL that GORM actually
// rendered rather than against a string a test wrote by hand. slow is
// the adapter's slow-statement threshold.
// rendered rather than against a string a test wrote by hand.
func openDB(
t *testing.T, buf *bytes.Buffer, h slog.Handler, slow time.Duration,
) *gorm.DB {
t *testing.T, buf *bytes.Buffer, h slog.Handler,
) (*gorm.DB, *gormlog.Logger) {
t.Helper()
sqlDB, err := sql.Open("sqlite", fmt.Sprintf(
@@ -127,7 +116,7 @@ func openDB(
t.Cleanup(func() { _ = sqlDB.Close() })
gl := gormlog.ExportNewWithSlowThreshold(slog.New(h), slow)
gl := gormlog.New(slog.New(h))
gdb, err := gorm.Open(
sqlite.Dialector{Conn: sqlDB},
@@ -140,7 +129,7 @@ func openDB(
// Migration chatter is not what any of these cases is about.
buf.Reset()
return gdb
return gdb, gl
}
// assertBounded holds every line the adapter wrote to the stated
@@ -183,7 +172,7 @@ func TestRecordNotFound_WritesNothing(t *testing.T) {
var buf bytes.Buffer
gdb := openDB(t, &buf, h.make(&buf), neverSlow)
gdb, _ := openDB(t, &buf, h.make(&buf))
var got thing
@@ -202,46 +191,6 @@ func TestRecordNotFound_WritesNothing(t *testing.T) {
}
}
// TestSlowRecordNotFound_IsStillReportedSlow pins the arm ordering in
// Trace against the drop above.
//
// GORM's own Trace orders its cases error-that-is-not-a-miss, then
// slow, then routine, so IgnoreRecordNotFoundError: true — the cheap
// option this adapter was chosen over — still reports a miss that ran
// slow. An adapter that dropped the miss first would be strictly less
// observant than the option it replaced, on exactly the two lookups
// this package exists for. A miss is also the statement most likely to
// be slow, since it is the one that scans without finding a row.
func TestSlowRecordNotFound_IsStillReportedSlow(t *testing.T) {
t.Parallel()
for _, h := range handlers() {
for _, f := range fills() {
t.Run(h.name+"/"+f.name, func(t *testing.T) {
t.Parallel()
var buf bytes.Buffer
gdb := openDB(t, &buf, h.make(&buf), alwaysSlow)
var got thing
err := gdb.Where(
"id = ?", clientValue(f.fill),
).First(&got).Error
require.ErrorIs(t, err, gorm.ErrRecordNotFound)
assert.Contains(
t, buf.String(), "slow sql statement",
"a slow statement that missed was not "+
"reported as slow",
)
assertBounded(t, buf.String())
})
}
}
}
// TestRecordNotFoundFlood_DoesNotGrowWithInput states the definition
// of done directly: a flood of misses at two input sizes 64 times
// apart must cost the same number of bytes of log.
@@ -255,12 +204,11 @@ func TestRecordNotFoundFlood_DoesNotGrowWithInput(t *testing.T) {
var buf bytes.Buffer
gdb := openDB(
gdb, _ := openDB(
t, &buf,
slog.NewJSONHandler(&buf, &slog.HandlerOptions{
Level: slog.LevelDebug,
}),
neverSlow,
)
value := strings.Repeat("\x01", size)
@@ -297,7 +245,7 @@ func TestStatementError_LineIsBounded(t *testing.T) {
var buf bytes.Buffer
gdb := openDB(t, &buf, h.make(&buf), neverSlow)
gdb, _ := openDB(t, &buf, h.make(&buf))
row := thing{ID: clientValue(f.fill), Name: "a"}
@@ -321,39 +269,25 @@ func TestStatementError_LineIsBounded(t *testing.T) {
}
}
// TestSucceedingStatement_LineIsBoundedOnEitherArm covers the two
// arms a statement that returns no error can take, over the same
// query, so neither can be bounded by accident of the other.
//
// - slow. Silencing GORM outright would have been the cheaper fix
// and would have cost this report, which is the one thing GORM's
// logger gave an operator that nothing else in this service does.
// - routine. The branch an operator reaches by turning the level
// down to DEBUG: every statement is reported, so every
// statement's interpolated parameters have to be bounded too.
func TestSucceedingStatement_LineIsBoundedOnEitherArm(t *testing.T) {
// TestSlowStatement_IsLoggedAndBounded proves the slow-statement
// report survived the fix. Silencing GORM outright would have been
// the cheaper change and would have cost this, which is the one thing
// GORM's logger reports that nothing else in the service does.
func TestSlowStatement_IsLoggedAndBounded(t *testing.T) {
t.Parallel()
arms := []struct {
name string
slow time.Duration
want string
}{
{"slow", alwaysSlow, "slow sql statement"},
{"routine", neverSlow, "sql statement"},
}
for _, a := range arms {
for _, h := range handlers() {
for _, f := range fills() {
name := a.name + "/" + h.name + "/" + f.name
t.Run(name, func(t *testing.T) {
t.Run(h.name+"/"+f.name, func(t *testing.T) {
t.Parallel()
var buf bytes.Buffer
gdb := openDB(t, &buf, h.make(&buf), a.slow)
gdb, gl := openDB(t, &buf, h.make(&buf))
// Every statement counts as slow, so the branch is
// reached without making the test wait for it.
gl.ExportSetSlowThreshold(time.Nanosecond)
var got []thing
@@ -361,12 +295,41 @@ func TestSucceedingStatement_LineIsBoundedOnEitherArm(t *testing.T) {
"name = ?", clientValue(f.fill),
).Find(&got).Error)
assert.Contains(t, buf.String(), a.want)
assert.Contains(
t, buf.String(), "slow sql statement",
)
assertBounded(t, buf.String())
})
}
}
}
// TestDebugStatement_LineIsBounded covers the branch an operator
// reaches by turning the level down: every statement is reported, so
// every statement's interpolated parameters have to be bounded too.
func TestDebugStatement_LineIsBounded(t *testing.T) {
t.Parallel()
for _, h := range handlers() {
for _, f := range fills() {
t.Run(h.name+"/"+f.name, func(t *testing.T) {
t.Parallel()
var buf bytes.Buffer
gdb, _ := openDB(t, &buf, h.make(&buf))
var got []thing
require.NoError(t, gdb.Where(
"name = ?", clientValue(f.fill),
).Find(&got).Error)
assert.Contains(t, buf.String(), "sql statement")
assertBounded(t, buf.String())
})
}
}
}
// TestGORMOwnMessages_AreBounded covers the three printf-style

View File

@@ -18,9 +18,7 @@ import (
"github.com/go-chi/chi"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"gorm.io/gorm"
gormlogger "gorm.io/gorm/logger"
"sneak.berlin/go/webhooker/internal/database"
"sneak.berlin/go/webhooker/internal/handlers"
"sneak.berlin/go/webhooker/internal/middleware"
)
@@ -168,38 +166,15 @@ func (c *stdoutCapture) drain(t *testing.T) string {
return out
}
// teeStdout writes to a buffer and to whatever os.Stdout is at the
// moment of the write.
//
// The second half is the point. GORM's package-level default logger
// resolves os.Stdout once, at package init, so a logger built over the
// variable would keep writing to the real terminal no matter what a
// test redirects. Resolving it per write puts the bytes a defaulted
// gorm.Config would cost in production into the same capture as
// everything else internal/logger emits, which is what lets the volume
// assertions below measure the whole writer set rather than one member
// of it.
type teeStdout struct {
buf *syncBuf
}
func (w teeStdout) Write(p []byte) (int, error) {
_, _ = os.Stdout.Write(p)
return w.buf.Write(p)
}
// captureGORMDefault replaces GORM's package-level default logger with
// one configured exactly as GORM configures its own, writing to a
// buffer and to os.Stdout.
// captureGORMDefault points GORM's package-level default logger at a
// buffer for the duration of the test.
//
// This is the mutation detector. gormlogger.Default is what a bare
// &gorm.Config{} installs, and its config here is GORM's verbatim —
// Warn, IgnoreRecordNotFoundError false — so a reverted call site
// behaves as it would in production rather than as a test dialed it.
// With every gorm.Open in this service naming its own logger, nothing
// consults this value and the buffer stays empty; revert any one of
// the three and the interpolated SQL lands here.
// &gorm.Config{} installs, and it holds an *os.File captured at
// package init, so redirecting os.Stdout does not reach it — it has
// to be replaced. With every gorm.Open in this service naming its own
// logger, nothing consults this value and the buffer stays empty;
// revert any one of them and the interpolated SQL lands here.
func captureGORMDefault(t *testing.T) *syncBuf {
t.Helper()
@@ -207,7 +182,7 @@ func captureGORMDefault(t *testing.T) *syncBuf {
orig := gormlogger.Default
gormlogger.Default = gormlogger.New(
log.New(teeStdout{buf: buf}, "", log.LstdFlags),
log.New(buf, "", log.LstdFlags),
gormlogger.Config{
SlowThreshold: 200 * time.Millisecond,
LogLevel: gormlogger.Warn,
@@ -253,51 +228,6 @@ func floodUnauthenticated(
return requests
}
// floodPerWebhook drives the same client-chosen values at the second
// gorm.Open site, the per-webhook database internal/database's
// WebhookDBManager opens.
//
// That site is behind authentication in production, so this is not
// part of the unauthenticated flood above and is counted separately.
// It is here because the ceiling the README states covers every
// writer, and the manager is one of them: with nothing driving it, a
// bare &gorm.Config{} could be restored at
// internal/database/webhook_db_manager.go and the whole suite would
// stay green.
func floodPerWebhook(
t *testing.T, mgr *database.WebhookDBManager, size, reps int,
) int {
t.Helper()
requests := 0
for _, f := range gormBoundFills() {
var b strings.Builder
for b.Len() < size {
b.WriteString(f.fill)
}
b.WriteString(gormBoundTailMarker)
value := b.String()
db, err := mgr.GetDB("pin-" + f.name)
require.NoError(t, err)
for range reps {
var got database.Event
err = db.Where("id = ?", value).First(&got).Error
require.ErrorIs(t, err, gorm.ErrRecordNotFound)
requests++
}
}
return requests
}
// postWebhook drives the receiver with an invented entrypoint path.
// The route pattern matches any single segment, so every byte of the
// value is the client's, and the lookup behind it misses by design.
@@ -384,41 +314,20 @@ func assertFloodBounded(t *testing.T, label, out string) {
}
}
// TestFlood_NoWriterGrowsWithTheInput is the definition of done for
// the GORM logger defect, stated over every writer at once, for two of
// this service's three gorm.Open sites: the main database behind the
// two unauthenticated lookups, and the per-webhook database the
// WebhookDBManager opens. The third, the archive writer, is pinned in
// internal/delivery, where its type lives.
// TestUnauthenticatedFlood_NoWriterGrowsWithTheInput is the
// definition of done for the GORM logger defect, stated over both
// writers at once.
//
// What each assertion is worth, since two of the three would pass
// against a service that had never been fixed if the capture were set
// up differently:
//
// - The gormDefault check is the sharp one. It fires the moment any
// gorm.Open in this service goes back to a bare &gorm.Config{}.
// - The volume and per-line checks bite only because the replaced
// default logger tees into os.Stdout, so a reverted call site
// shows up in the same capture as everything internal/logger
// writes — the way it would in production. Without that tee both
// were vacuous: at INFO the two handler misses log at DEBUG and
// the adapter drops the record-not-found, so the capture holds
// nothing but fixed-string warnings.
//
// The level is left where newTestApp leaves it, at INFO, deliberately.
// At DEBUG the handlers' own miss lines log the client-chosen
// entrypoint and username untruncated — the first carve-out in the
// README's ceiling section, and https://git.eeqj.de/sneak/webhooker/issues/176's
// to fix, not this one's.
//
// It is deliberately not parallel: it redirects os.Stdout and replaces
// gormlogger.Default, both of which are process-global. Go runs every
// non-parallel top-level test to completion before it resumes the
// parallel ones, so nothing else in this package is running while the
// capture is installed.
// It is deliberately not parallel: it redirects os.Stdout and
// replaces gormlogger.Default, both of which are process-global. Go
// runs every non-parallel top-level test to completion before it
// resumes the parallel ones, so nothing else in this package is
// running while the capture is installed.
//
//nolint:paralleltest // Deliberately sequential; see above.
func TestFlood_NoWriterGrowsWithTheInput(t *testing.T) {
func TestUnauthenticatedFlood_NoWriterGrowsWithTheInput(
t *testing.T,
) {
const (
smallBytes = 128
bigBytes = 8 << 10
@@ -428,12 +337,9 @@ func TestFlood_NoWriterGrowsWithTheInput(t *testing.T) {
gormDefault := captureGORMDefault(t)
capture := captureStdout(t)
var (
h *handlers.Handlers
mgr *database.WebhookDBManager
)
var h *handlers.Handlers
app := newTestApp(t, &h, &mgr)
app := newTestApp(t, &h)
app.RequireStart()
t.Cleanup(app.RequireStop)
@@ -442,12 +348,10 @@ func TestFlood_NoWriterGrowsWithTheInput(t *testing.T) {
capture.drain(t)
floodUnauthenticated(t, h, smallBytes, reps)
floodPerWebhook(t, mgr, smallBytes, reps)
small := capture.drain(t)
requests := floodUnauthenticated(t, h, bigBytes, reps)
requests += floodPerWebhook(t, mgr, bigBytes, reps)
big := capture.drain(t)
assertFloodBounded(t, "small flood", small)

View File

@@ -85,21 +85,14 @@ const (
// The text handler's fixed portion is 286, the smaller of the two,
// which puts its worst case at 2037.
//
// The access log is the widest line this service writes that
// carries client-chosen text, so the figure is also the ceiling on
// the other writer that does: the GORM adapter in
// internal/gormlog, whose widest line spends two logfield.MaxBytes
// budgets (the interpolated SQL and the driver error) against a
// fixed portion smaller than this one's.
// internal/gormlog/gormlog_test.go asserts that against this
// constant directly rather than leaving it as arithmetic.
//
// It is not the widest line the service can write. A handler panic
// arrives through net/http's nil ErrorLog as one record carrying a
// whole goroutine stack, measured at 2,772 bytes. That value is
// the runtime's, not a client's, so it is a carve-out this ceiling
// states rather than covers; see README.md and
// https://git.eeqj.de/sneak/webhooker/issues/187.
// The access log is the widest line this service writes, so the
// figure is also the ceiling on the other writer that carries
// client-chosen text: the GORM adapter in internal/gormlog, whose
// widest line spends two logfield.MaxBytes budgets (the
// interpolated SQL and the driver error) against a fixed portion
// smaller than this one's. internal/gormlog/gormlog_test.go
// asserts that against this constant directly rather than leaving
// it as arithmetic.
MaxAccessLogLineBytes = 2560
)

View File

@@ -2,11 +2,8 @@ package server
import (
"net/http"
"net/url"
"strings"
"github.com/getsentry/sentry-go"
"github.com/go-chi/chi"
)
// sentryRedacted stands in for a withheld field on every event shipped
@@ -14,12 +11,6 @@ import (
// can tell a suppressed value from an absent one.
const sentryRedacted = "(redacted)"
// sentryRedactedPath is what stands in for the request path when the
// route pattern is not reachable. It is deliberately not the concrete
// path: on the receiver route that path carries the entrypoint UUID,
// which is a write capability rather than an identifier.
const sentryRedactedPath = "/" + sentryRedacted
// sentryClientOptions builds the options the SDK is initialised with.
// It is its own function so a test can stand up a client wired exactly
// as production is, with only the transport swapped.
@@ -53,43 +44,18 @@ func sentryClientOptions(dsn, release string) sentry.ClientOptions {
// login password and both password-change fields. None of that may
// reach a third-party service.
//
// URL is the third such field. NewRequest builds it as
// scheme://host/path (interfaces.go:183), and on the receiver route
// that path is /webhook/<uuid> in full — a write capability, not an
// identifier. It is rebuilt here from the chi route pattern, on every
// route, keeping the scheme and the host.
//
// This hook is a floor, not a default: the fields it clears stay
// cleared even if SendDefaultPII is ever turned on.
func scrubSentryRequest(
event *sentry.Event,
hint *sentry.EventHint,
_ *sentry.EventHint,
) *sentry.Event {
if event == nil {
return event
}
pattern := sentryRoutePattern(hint)
// Only transaction events carry a Transaction name, and the SDK
// builds it from the concrete path too (sentryhttp.go:105 via
// tracing.go:553). Rewritten on the same terms.
if event.Transaction != "" {
event.Transaction = sentryTransactionName(
event.Transaction, pattern,
)
}
if event.Request == nil {
if event == nil || event.Request == nil {
return event
}
req := event.Request
if req.URL != "" {
req.URL = sentryRouteURL(req.URL, pattern)
}
if req.QueryString != "" {
req.QueryString = sentryRedacted
}
@@ -105,91 +71,6 @@ func scrubSentryRequest(
return event
}
// sentryRoutePattern returns the chi route pattern for the request the
// hint carries, or "" when it is not reachable.
//
// The request is reachable on the error dispatch only. sentryhttp's
// recover path calls RecoverWithContext with the request on the
// context under sentry.RequestContextKey (sentryhttp.go:124-125), and
// the client copies that context onto the hint (client.go:484-485)
// before handing it to BeforeSend (client.go:631). chi's routing
// context is a pointer placed on the request context before the
// middleware chain runs (chi mux.go:84) and filled in as the mux
// routes, so by the time a handler panics it names the matched route.
//
// The transaction dispatch has no such request: Span.doFinish calls
// hub.CaptureEvent (tracing.go:356), which passes a nil hint that the
// client replaces with an empty one (client.go:620-622). The pattern
// is therefore always "" there, and the callers fall back.
func sentryRoutePattern(hint *sentry.EventHint) string {
if hint == nil || hint.Context == nil {
return ""
}
req, ok := hint.Context.Value(
sentry.RequestContextKey,
).(*http.Request)
if !ok || req == nil {
return ""
}
rctx := chi.RouteContext(req.Context())
if rctx == nil {
return ""
}
// Empty when no route matched, which is the fallback case too.
return rctx.RoutePattern()
}
// sentryRouteURL rebuilds an event's request URL with the route
// pattern in place of the concrete path.
//
// The scheme is load-bearing and is kept: the SDK derives it from
// r.TLS != nil || r.Header.Get("X-Forwarded-Proto") == "https"
// (interfaces.go:180), byte for byte the predicate
// internal/middleware/csrf.go uses, so it is the CSRF TLS decision and
// the reason dropping X-Forwarded-Proto from the header allowlist
// costs nothing. The host is parsed.Host of the SDK's
// scheme://r.Host/path, so it is whatever the client's Host header
// carried: this service validates no hostname. It is kept because that
// same header is on the allowlist, so scrubbing it here would withhold
// nothing that is not sent anyway.
//
// Everything else in the URL is discarded rather than edited, so a
// future SDK that starts appending a query string cannot widen this.
func sentryRouteURL(rawURL, pattern string) string {
parsed, err := url.Parse(rawURL)
if err != nil || parsed.Scheme == "" {
// Not a shape this can safely take apart.
return sentryRedacted
}
if pattern == "" {
pattern = sentryRedactedPath
}
return parsed.Scheme + "://" + parsed.Host + pattern
}
// sentryTransactionName rebuilds the SDK's "METHOD /path" transaction
// name with the route pattern in place of the concrete path. Method is
// kept for the same reason Request.Method is: net/http admits only a
// bounded token there. A name in any other shape is withheld whole,
// since nothing can be said about which part of it is a path.
func sentryTransactionName(name, pattern string) string {
method, _, found := strings.Cut(name, " ")
if !found {
return sentryRedacted
}
if pattern == "" {
pattern = sentryRedactedPath
}
return method + " " + pattern
}
// keptSentryHeaders returns the subset of headers an event may carry
// off-host. Dropping by allowlist rather than by blocklist is what
// makes an unrecognised header safe: the SDK's own filter removes four

View File

@@ -13,13 +13,12 @@ import (
"github.com/getsentry/sentry-go"
sentryhttp "github.com/getsentry/sentry-go/http"
"github.com/go-chi/chi"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"sneak.berlin/go/webhooker/internal/server"
)
// The four markers below are the credentials a captured event could
// The three markers below are the credentials a captured event could
// carry off-host, one per field of sentry.Request that the SDK fills
// from the request without a SendDefaultPII guard.
const (
@@ -34,12 +33,6 @@ const (
// sentryHeaderMarker rides X-Csrf-Token, which gorilla/csrf
// accepts in place of the form field.
sentryHeaderMarker = "QQSENTRYHEADERMARKERQQ"
// sentryReceiverUUID is the entrypoint identifier in the path of
// a receiver request. It is a write capability: anyone holding
// it can POST events this service accepts and its targets then
// deliver, so it may not reach a third-party tracker.
sentryReceiverUUID = "6d1f9c2a-3b7e-4f58-9a0d-c0ffeebadc0d"
)
// sentryKeptUserAgent is a non-secret header value planted so the
@@ -65,41 +58,19 @@ func (c *captureTransport) SendEvent(event *sentry.Event) {
c.events = append(c.events, event)
}
// sentryCase drives one request through the real sentryhttp middleware
// inside a real chi router and returns the events the SDK produced.
// captureThroughSentryHTTP panics inside a form handler wrapped in the
// real sentryhttp middleware and returns the event the SDK produced.
//
// Routing through a chi mux is load-bearing, not decoration. chi puts
// its routing context on the request context before the middleware
// chain runs and fills it in as it matches, so a hand-built request
// carries no route pattern at all and could not distinguish the hook
// working from the hook falling back.
// This is the only construction path on which Request.Data appears:
// sentryhttp calls Scope.SetRequest, which tees r.Body into a 10 KiB
// buffer, ParseForm drains the tee, and Scope.ApplyToEvent copies the
// buffer into the event inside prepareEvent — before BeforeSend runs.
// A hand-built sentry.NewRequest never reads the body and so cannot
// regress-test any of it.
//
// This is also the only construction path on which Request.Data
// appears: sentryhttp calls Scope.SetRequest, which tees r.Body into a
// 10 KiB buffer, ParseForm drains the tee, and Scope.ApplyToEvent
// copies the buffer into the event inside prepareEvent — before
// BeforeSend runs. A hand-built sentry.NewRequest never reads the body
// and so cannot regress-test any of it.
type sentryCase struct {
// scrub selects whether the production BeforeSend hooks are
// installed, so the same path shows both what the SDK collects
// and what survives.
scrub bool
// tracing enables the transaction dispatch, which the service
// leaves off. With it on, a served request produces a
// transaction event through BeforeSendTransaction.
tracing bool
// panics selects the error dispatch, via BeforeSend.
panics bool
// request builds the request to serve, given the client whose
// hub it must carry.
request func(*sentry.Client) *http.Request
}
func (c sentryCase) capture(t *testing.T) []*sentry.Event {
// scrub selects whether the production BeforeSend hooks are installed,
// so the same path shows both what the SDK collects and what survives.
func captureThroughSentryHTTP(t *testing.T, scrub bool) *sentry.Event {
t.Helper()
transport := &captureTransport{}
@@ -109,107 +80,57 @@ func (c sentryCase) capture(t *testing.T) []*sentry.Event {
)
opts.Transport = transport
if !c.scrub {
if !scrub {
opts.BeforeSend = nil
opts.BeforeSendTransaction = nil
}
if c.tracing {
opts.EnableTracing = true
opts.TracesSampleRate = 1.0
}
client, err := sentry.NewClient(opts)
require.NoError(t, err)
c.router().ServeHTTP(httptest.NewRecorder(), c.request(client))
return transport.events
}
// router mirrors setupGlobalMiddleware's ordering over the two route
// patterns these tests need: a recovering middleware first, then the
// sentryhttp handler registered with Use and Repanic set, exactly as
// routes.go registers it. The local recover stands in for chi's
// middleware.Recoverer, which holds that slot in production; it is
// here only to keep panic stacks out of the test output.
func (c sentryCase) router() http.Handler {
handler := func(_ http.ResponseWriter, r *http.Request) {
// This call is what drains the body tee and fills the
// buffer. Its success is asserted by the unscrubbed case
// below, which sees the body in the event.
handler := sentryhttp.New(sentryhttp.Options{}).Handle(
http.HandlerFunc(func(_ http.ResponseWriter, r *http.Request) {
// This call is what drains the tee and fills the
// buffer. Its success is asserted by the unscrubbed
// case below, which sees the body in the event.
_ = r.ParseForm()
if c.panics {
panic("boom")
}
}
router := chi.NewRouter()
router.Use(recoveringMiddleware)
router.Use(
sentryhttp.New(sentryhttp.Options{Repanic: true}).Handle,
}),
)
router.HandleFunc("/pages/login", handler)
router.HandleFunc("/webhook/{uuid}", handler)
return router
}
func recoveringMiddleware(next http.Handler) http.Handler {
return http.HandlerFunc(
func(w http.ResponseWriter, r *http.Request) {
defer func() { _ = recover() }()
next.ServeHTTP(w, r)
},
handler.ServeHTTP(
httptest.NewRecorder(),
sentryLoginRequest(client),
)
require.Len(t, transport.events, 1)
return transport.events[0]
}
// sentryLoginRequest builds the password POST most cases drive, with a
// credential planted in the body, the query and a header.
// sentryLoginRequest builds the password POST the capture above drives,
// with a credential planted in the body, the query and a header.
func sentryLoginRequest(client *sentry.Client) *http.Request {
form := url.Values{}
form.Set("username", "admin")
form.Set("password", sentryBodyMarker)
req := sentryRequest(
client,
"/pages/login?url=https://hooks.slack.com/services/"+
sentryQueryMarker,
form.Encode(),
)
req.Header.Set("X-Csrf-Token", sentryHeaderMarker)
return req
}
// sentryReceiverRequest builds a POST to the receiver route, whose
// concrete path carries the entrypoint capability.
func sentryReceiverRequest(client *sentry.Client) *http.Request {
return sentryRequest(
client, "/webhook/"+sentryReceiverUUID, "payload=hello",
)
}
func sentryRequest(
client *sentry.Client,
target, body string,
) *http.Request {
req := httptest.NewRequestWithContext(
sentry.SetHubOnContext(
context.Background(),
sentry.NewHub(client, sentry.NewScope()),
),
http.MethodPost,
target,
strings.NewReader(body),
"/pages/login?url=https://hooks.slack.com/services/"+
sentryQueryMarker,
strings.NewReader(form.Encode()),
)
req.Header.Set(
"Content-Type", "application/x-www-form-urlencoded",
)
req.Header.Set("X-Csrf-Token", sentryHeaderMarker)
req.Header.Set("User-Agent", sentryKeptUserAgent)
return req
@@ -225,27 +146,15 @@ func marshalEvent(t *testing.T, event *sentry.Event) string {
return string(encoded)
}
// onlyEvent asserts a single event was captured and returns it.
func onlyEvent(t *testing.T, events []*sentry.Event) *sentry.Event {
t.Helper()
require.Len(t, events, 1)
require.NotNil(t, events[0].Request)
return events[0]
}
// TestSentryScrub_SDKCollectsTheRequestUnscrubbed pins the premise the
// hook exists for. Without it the SDK ships the whole POST body, the
// raw query, the CSRF header and the concrete request path, none of
// which SendDefaultPII=false suppresses.
// raw query and the CSRF header, none of which SendDefaultPII=false
// suppresses.
func TestSentryScrub_SDKCollectsTheRequestUnscrubbed(t *testing.T) {
t.Parallel()
event := onlyEvent(t, sentryCase{
panics: true,
request: sentryLoginRequest,
}.capture(t))
event := captureThroughSentryHTTP(t, false)
require.NotNil(t, event.Request)
assert.Contains(
t, event.Request.Data, sentryBodyMarker,
@@ -256,18 +165,6 @@ func TestSentryScrub_SDKCollectsTheRequestUnscrubbed(t *testing.T) {
assert.Contains(
t, marshalEvent(t, event), sentryHeaderMarker,
)
receiver := onlyEvent(t, sentryCase{
panics: true,
request: sentryReceiverRequest,
}.capture(t))
assert.Contains(
t, receiver.Request.URL, sentryReceiverUUID,
"the SDK is expected to build Request.URL from the "+
"concrete path; if it no longer does, the route "+
"pattern rewrite's premise changed",
)
}
// TestSentryScrub_RedactsTheCapturedRequest is the regression test: no
@@ -276,11 +173,8 @@ func TestSentryScrub_SDKCollectsTheRequestUnscrubbed(t *testing.T) {
func TestSentryScrub_RedactsTheCapturedRequest(t *testing.T) {
t.Parallel()
event := onlyEvent(t, sentryCase{
scrub: true,
panics: true,
request: sentryLoginRequest,
}.capture(t))
event := captureThroughSentryHTTP(t, true)
require.NotNil(t, event.Request)
encoded := marshalEvent(t, event)
@@ -295,45 +189,16 @@ func TestSentryScrub_RedactsTheCapturedRequest(t *testing.T) {
assert.Empty(t, event.Request.Env)
}
// TestSentryScrub_ReplacesTheCapabilityPathWithTheRoutePattern is the
// regression test for the receiver URL: the entrypoint UUID is a write
// capability and may not reach the tracker, while the route it names
// must still be readable there.
func TestSentryScrub_ReplacesTheCapabilityPathWithTheRoutePattern(
t *testing.T,
) {
t.Parallel()
event := onlyEvent(t, sentryCase{
scrub: true,
panics: true,
request: sentryReceiverRequest,
}.capture(t))
assert.NotContains(
t, marshalEvent(t, event), sentryReceiverUUID,
)
assert.Equal(
t, "http://example.com/webhook/{uuid}", event.Request.URL,
)
}
// TestSentryScrub_KeepsTheRoutingContext checks the hook does not cost
// the debugging signal: the route, its scheme and host, the method and
// the metadata headers still identify what failed. On a static route
// the pattern is the path, so the URL is unchanged there.
// the debugging signal: the route, the method and the metadata headers
// still identify what failed.
func TestSentryScrub_KeepsTheRoutingContext(t *testing.T) {
t.Parallel()
event := onlyEvent(t, sentryCase{
scrub: true,
panics: true,
request: sentryLoginRequest,
}.capture(t))
event := captureThroughSentryHTTP(t, true)
require.NotNil(t, event.Request)
assert.Equal(
t, "http://example.com/pages/login", event.Request.URL,
)
assert.Contains(t, event.Request.URL, "/pages/login")
assert.Equal(t, http.MethodPost, event.Request.Method)
assert.Equal(
t,
@@ -347,127 +212,6 @@ func TestSentryScrub_KeepsTheRoutingContext(t *testing.T) {
)
}
// TestSentryScrub_RedactsTheTransactionDispatch covers the other hook.
// Span.doFinish captures with a nil hint, so BeforeSendTransaction
// gets one with no context and no request: the route pattern is out of
// reach and both the URL and the SDK-built transaction name have to
// fall back. Tracing is off in this service, so no transaction event
// is produced today; the hook is a floor against that changing.
func TestSentryScrub_RedactsTheTransactionDispatch(t *testing.T) {
t.Parallel()
events := sentryCase{
scrub: true,
tracing: true,
request: sentryReceiverRequest,
}.capture(t)
event := onlyEvent(t, events)
require.Equal(t, "transaction", event.Type)
assert.NotContains(
t, marshalEvent(t, event), sentryReceiverUUID,
)
assert.Equal(
t, "http://example.com/(redacted)", event.Request.URL,
)
assert.Equal(t, "POST /(redacted)", event.Transaction)
}
// TestSentryScrub_TransactionDispatchIsUnscrubbedWithoutTheHook pins
// that dispatch's premise the same way, since it is the one the
// service does not exercise today.
func TestSentryScrub_TransactionDispatchIsUnscrubbedWithoutTheHook(
t *testing.T,
) {
t.Parallel()
event := onlyEvent(t, sentryCase{
tracing: true,
request: sentryReceiverRequest,
}.capture(t))
require.Equal(t, "transaction", event.Type)
assert.Contains(t, event.Request.URL, sentryReceiverUUID)
assert.Contains(t, event.Transaction, sentryReceiverUUID)
}
// TestSentryScrub_FallsBackWithoutARoutePattern covers every way the
// pattern can be missing. None of them may fall back to the concrete
// path, and all of them keep the scheme, which is the CSRF TLS
// decision.
func TestSentryScrub_FallsBackWithoutARoutePattern(t *testing.T) {
t.Parallel()
concrete := "https://example.com/webhook/" + sentryReceiverUUID
// A request with no chi routing context on it at all, which is
// what an event captured outside the router would carry.
unrouted := httptest.NewRequestWithContext(
context.Background(), http.MethodPost, concrete, nil,
)
for name, hint := range map[string]*sentry.EventHint{
"no hint": nil,
"no context": {},
"no request": {Context: context.Background()},
"unrouted request": {
Context: context.WithValue(
context.Background(),
sentry.RequestContextKey,
unrouted,
),
},
} {
t.Run(name, func(t *testing.T) {
t.Parallel()
event := sentry.NewEvent()
event.Request = &sentry.Request{URL: concrete}
event.Transaction = "POST /webhook/" +
sentryReceiverUUID
scrubbed := server.ScrubSentryRequestForTest(
event, hint,
)
require.NotNil(t, scrubbed)
assert.Equal(
t,
"https://example.com/(redacted)",
scrubbed.Request.URL,
)
assert.Equal(
t, "POST /(redacted)", scrubbed.Transaction,
)
assert.NotContains(
t,
marshalEvent(t, scrubbed),
sentryReceiverUUID,
)
})
}
}
// TestSentryScrub_WithholdsUnparseableValues covers the shapes the
// rewrite cannot take apart. Withholding them whole is the safe
// answer, since nothing can be said about which part is a path.
func TestSentryScrub_WithholdsUnparseableValues(t *testing.T) {
t.Parallel()
event := sentry.NewEvent()
event.Request = &sentry.Request{
URL: "/webhook/" + sentryReceiverUUID,
}
event.Transaction = "/webhook/" + sentryReceiverUUID
scrubbed := server.ScrubSentryRequestForTest(event, nil)
require.NotNil(t, scrubbed)
assert.Equal(t, "(redacted)", scrubbed.Request.URL)
assert.Equal(t, "(redacted)", scrubbed.Transaction)
}
// TestSentryScrub_ToleratesEventsWithoutARequest covers the events the
// hook sees outside an HTTP handler, where no request is attached.
func TestSentryScrub_ToleratesEventsWithoutARequest(t *testing.T) {
@@ -479,6 +223,5 @@ func TestSentryScrub_ToleratesEventsWithoutARequest(t *testing.T) {
require.NotNil(t, scrubbed)
assert.Nil(t, scrubbed.Request)
assert.Empty(t, scrubbed.Transaction)
assert.Nil(t, server.ScrubSentryRequestForTest(nil, nil))
}