Compare commits
3 Commits
04f370a050
...
31228608d1
| Author | SHA1 | Date | |
|---|---|---|---|
| 31228608d1 | |||
| a13e5b7ded | |||
| bb30b3ad64 |
89
README.md
89
README.md
@@ -107,14 +107,26 @@ TTY detection, and security headers are always applied.
|
|||||||
| `DATA_DIR` | Directory for all SQLite databases | `/var/lib/webhooker` |
|
| `DATA_DIR` | Directory for all SQLite databases | `/var/lib/webhooker` |
|
||||||
| `DEBUG` | Enable debug logging | `false` |
|
| `DEBUG` | Enable debug logging | `false` |
|
||||||
| `MAINTENANCE_MODE` | Report `maintenanceMode: true` in the healthcheck JSON. It does not change how any request is served — no maintenance page exists | `false` |
|
| `MAINTENANCE_MODE` | Report `maintenanceMode: true` in the healthcheck JSON. It does not change how any request is served — no maintenance page exists | `false` |
|
||||||
| `METRICS_USERNAME` | Basic auth username for `/metrics` | `""` |
|
| `METRICS_USERNAME` | Basic auth username for `/metrics`. Must be set together with `METRICS_PASSWORD`; one without the other fails startup | `""` |
|
||||||
| `METRICS_PASSWORD` | Basic auth password for `/metrics` | `""` |
|
| `METRICS_PASSWORD` | Basic auth password for `/metrics`. Must be set together with `METRICS_USERNAME`; one without the other fails startup | `""` |
|
||||||
| `SENTRY_DSN` | Sentry error reporting DSN | `""` |
|
| `SENTRY_DSN` | Sentry error reporting DSN | `""` |
|
||||||
| `RETENTION_SWEEP_INTERVAL` | How often the retention reaper and archive sweeper run (Go duration, must be positive) | `1h` |
|
| `RETENTION_SWEEP_INTERVAL` | How often the retention reaper and archive sweeper run (Go duration, must be positive) | `1h` |
|
||||||
| `SESSION_IDLE_TIMEOUT` | Idle session timeout (Go duration) | `24h` |
|
| `SESSION_IDLE_TIMEOUT` | Idle session timeout (Go duration) | `24h` |
|
||||||
| `RECEIVER_RATE_LIMIT` | Receiver requests/minute per IP per entrypoint (10x that per IP across the route) | `120` |
|
| `RECEIVER_RATE_LIMIT` | Receiver requests/minute per IP per entrypoint (10x that per IP across the route) | `120` |
|
||||||
| `TRUSTED_PROXIES` | CIDRs whose forwarded headers are trusted (unset: all clients behind a proxy share one rate-limit bucket; a correct login password is never throttled either way) | `""` (none) |
|
| `TRUSTED_PROXIES` | CIDRs whose forwarded headers are trusted (unset: all clients behind a proxy share one rate-limit bucket; a correct login password is never throttled either way) | `""` (none) |
|
||||||
|
|
||||||
|
#### Metrics credentials
|
||||||
|
|
||||||
|
`METRICS_USERNAME` and `METRICS_PASSWORD` are set together or not at
|
||||||
|
all. With both set, `/metrics` is served behind basic auth. With
|
||||||
|
neither set, the route is not registered and returns 404. With one set
|
||||||
|
and the other empty or unset, the process refuses to start and exits
|
||||||
|
non-zero with an error naming both variables — mounting the endpoint
|
||||||
|
on the username alone would publish it behind a password that is the
|
||||||
|
empty string, and quietly withholding it would deny an endpoint that
|
||||||
|
was asked for. The `hasMetricsAuth` field in the startup log and the
|
||||||
|
existence of the route are the same value, so they cannot disagree.
|
||||||
|
|
||||||
#### Trusted proxies
|
#### Trusted proxies
|
||||||
|
|
||||||
`TRUSTED_PROXIES` is a comma-separated list of CIDR blocks (a bare
|
`TRUSTED_PROXIES` is a comma-separated list of CIDR blocks (a bare
|
||||||
@@ -244,6 +256,51 @@ On first startup, webhooker creates an `admin` user
|
|||||||
with a randomly generated password and logs it to stdout. This password
|
with a randomly generated password and logs it to stdout. This password
|
||||||
is only displayed once.
|
is only displayed once.
|
||||||
|
|
||||||
|
#### What `DEBUG=true` exposes
|
||||||
|
|
||||||
|
`DEBUG=true` lowers the log level to `DEBUG`, which turns on every
|
||||||
|
statement GORM runs, the two by-design lookup misses on the
|
||||||
|
unauthenticated routes, and the rate limiter's own rejections. It is
|
||||||
|
meant to be safe to turn on while diagnosing a live service and safe to
|
||||||
|
paste the output of into a bug report.
|
||||||
|
|
||||||
|
What it does **not** put in the log:
|
||||||
|
|
||||||
|
- **Values bound to a SQL statement.** Statements are logged with their
|
||||||
|
placeholders, never with the values substituted into them, at every
|
||||||
|
level. That is what keeps the session encryption key out of the first
|
||||||
|
boot's `INSERT INTO settings` and the `admin` account's Argon2id
|
||||||
|
password hash out of its `INSERT INTO users` — the two statements
|
||||||
|
that made a debug log worth stealing. It applies to every table and
|
||||||
|
every statement rather than to a list of tables known to hold a
|
||||||
|
secret, so a table added later is covered without anyone remembering
|
||||||
|
to add it. The cost is that a failing statement can no longer be
|
||||||
|
replayed from the log alone: the statement, the table, the driver
|
||||||
|
error and the row count are all still there, but its values have to
|
||||||
|
come from the database.
|
||||||
|
`internal/gormlog/firstboot_test.go` boots the real graph with
|
||||||
|
`DEBUG=true` against an empty `DATA_DIR` and asserts that neither
|
||||||
|
secret appears in what that boot wrote to stdout.
|
||||||
|
The one exception is `(*gorm.DB).Scan`, which GORM logs through its
|
||||||
|
own trace recorder rather than through this filter. No production
|
||||||
|
code path calls it, and `internal/gormlog/scan_guard_test.go` fails
|
||||||
|
if a non-test file adds one.
|
||||||
|
- **Session cookies, API keys or target credentials.** None of these is
|
||||||
|
logged at any level.
|
||||||
|
|
||||||
|
What is in the log regardless of `DEBUG`, and is not a debug-logging
|
||||||
|
decision:
|
||||||
|
|
||||||
|
- **The initial `admin` password**, in the clear, once, at `INFO`, on
|
||||||
|
the first boot that creates the account. That line is the only place
|
||||||
|
it is ever shown; the database stores the hash. A first boot's output
|
||||||
|
is not safe to paste anywhere until that account's password has been
|
||||||
|
changed.
|
||||||
|
- **An authenticated operator's own configuration**, echoed back
|
||||||
|
untruncated — webhook names, target hostnames. See the logging
|
||||||
|
section under Security for the full list and for the per-line size
|
||||||
|
bound that covers unauthenticated traffic.
|
||||||
|
|
||||||
### Running with Docker
|
### Running with Docker
|
||||||
|
|
||||||
```bash
|
```bash
|
||||||
@@ -1406,6 +1463,24 @@ and the driver error — against a smaller fixed portion than the access
|
|||||||
log's, and `internal/gormlog/gormlog_test.go` asserts each line against
|
log's, and `internal/gormlog/gormlog_test.go` asserts each line against
|
||||||
`MaxAccessLogLineBytes` directly rather than leaving it as arithmetic.
|
`MaxAccessLogLineBytes` directly rather than leaving it as arithmetic.
|
||||||
|
|
||||||
|
The adapter also logs no bound value at all: it implements
|
||||||
|
`gorm.ParamsFilter` and discards the parameters, so GORM renders the
|
||||||
|
statement with its placeholders intact instead of substituting the
|
||||||
|
values into it. That is a separate property from the size bound and it
|
||||||
|
is what a bound is no substitute for — the session encryption key is 44
|
||||||
|
base64 characters and an Argon2id hash under 100, so both fit inside
|
||||||
|
every budget above and a truncated secret is still a secret. It holds
|
||||||
|
on all three arms of `Trace`, including the routine one an operator
|
||||||
|
reaches at `DEBUG`, which is the only level at which a successful
|
||||||
|
`INSERT` is written at all. One GORM path does not consult the filter —
|
||||||
|
`(*gorm.DB).Scan`, which records the statement through GORM's own trace
|
||||||
|
recorder. No production code path calls it; its one caller is
|
||||||
|
`internal/database/database_test.go:91`, whose `SELECT 1` binds
|
||||||
|
nothing, and `internal/gormlog/scan_guard_test.go` fails if a non-test
|
||||||
|
file calls it. `Pluck`, `Row` and `Raw` all run through the normal
|
||||||
|
callback processor and are filtered.
|
||||||
|
See `#### What DEBUG=true exposes` under Configuration.
|
||||||
|
|
||||||
What that ceiling does **not** cover, stated here so the figure is not
|
What that ceiling does **not** cover, stated here so the figure is not
|
||||||
read as more than it is:
|
read as more than it is:
|
||||||
|
|
||||||
@@ -1682,7 +1757,7 @@ abuse limit later; they are tracked as future work.
|
|||||||
|
|
||||||
| Method | Path | Description |
|
| Method | Path | Description |
|
||||||
| ------ | ---------- | ----------- |
|
| ------ | ---------- | ----------- |
|
||||||
| `GET` | `/metrics` | Prometheus metrics, behind basic auth. The route is registered only when `METRICS_USERNAME` is set; otherwise it does not exist and returns 404 |
|
| `GET` | `/metrics` | Prometheus metrics, behind basic auth. The route is registered only when `METRICS_USERNAME` and `METRICS_PASSWORD` are both set; with neither set it does not exist and returns 404, and with only one set the process refuses to start |
|
||||||
|
|
||||||
#### API (Planned)
|
#### API (Planned)
|
||||||
|
|
||||||
@@ -1837,7 +1912,8 @@ Applied to all routes in this order:
|
|||||||
Permissions-Policy)
|
Permissions-Policy)
|
||||||
3. **Logging** — Structured request logging (method, URL, status,
|
3. **Logging** — Structured request logging (method, URL, status,
|
||||||
latency, remote IP, user agent, request ID)
|
latency, remote IP, user agent, request ID)
|
||||||
4. **Metrics** — Prometheus HTTP metrics (if `METRICS_USERNAME` is set)
|
4. **Metrics** — Prometheus HTTP metrics (if `METRICS_USERNAME` and
|
||||||
|
`METRICS_PASSWORD` are both set)
|
||||||
5. **CORS** — Cross-origin resource sharing headers
|
5. **CORS** — Cross-origin resource sharing headers
|
||||||
6. **Timeout** — 60-second request timeout
|
6. **Timeout** — 60-second request timeout
|
||||||
7. **Recoverer** — Panic recovery: one `ERROR` record through
|
7. **Recoverer** — Panic recovery: one `ERROR` record through
|
||||||
@@ -1869,8 +1945,9 @@ being read and without reaching CSRF, the route group's remaining
|
|||||||
middleware, or the handler. It is not rejected before *any* other
|
middleware, or the handler. It is not rejected before *any* other
|
||||||
middleware, though: the global entries listed above all run first, so
|
middleware, though: the global entries listed above all run first, so
|
||||||
such a request is still logged and given the security headers — and
|
such a request is still logged and given the security headers — and
|
||||||
counted in the metrics, on a deployment where `METRICS_USERNAME` is
|
counted in the metrics, on a deployment where the `/metrics`
|
||||||
set and the Metrics middleware is therefore registered at all. The
|
credentials are set and the Metrics middleware is therefore registered
|
||||||
|
at all. The
|
||||||
rejection itself is logged at `WARN` with the method, path and
|
rejection itself is logged at `WARN` with the method, path and
|
||||||
declared length. A chunked request, or
|
declared length. A chunked request, or
|
||||||
one that lies about its length, is hard-capped by
|
one that lies about its length, is hard-capped by
|
||||||
|
|||||||
@@ -71,6 +71,16 @@ var ErrInvalidPort = errors.New("invalid port")
|
|||||||
// nor a bare IP address.
|
// nor a bare IP address.
|
||||||
var ErrInvalidCIDR = errors.New("invalid CIDR")
|
var ErrInvalidCIDR = errors.New("invalid CIDR")
|
||||||
|
|
||||||
|
// ErrIncompleteMetricsAuth is returned when exactly one of
|
||||||
|
// METRICS_USERNAME and METRICS_PASSWORD carries a value. Neither
|
||||||
|
// fallback is acceptable: serving /metrics on the username alone
|
||||||
|
// publishes an endpoint whose password is the empty string, and
|
||||||
|
// silently leaving it unmounted withholds an endpoint the operator
|
||||||
|
// asked for. Half-set is a configuration error, so startup fails.
|
||||||
|
var ErrIncompleteMetricsAuth = errors.New(
|
||||||
|
"incomplete metrics credentials",
|
||||||
|
)
|
||||||
|
|
||||||
//nolint:revive // ConfigParams is a standard fx naming convention.
|
//nolint:revive // ConfigParams is a standard fx naming convention.
|
||||||
type ConfigParams struct {
|
type ConfigParams struct {
|
||||||
fx.In
|
fx.In
|
||||||
@@ -128,6 +138,21 @@ func (c *Config) IsProd() bool {
|
|||||||
return c.Environment == EnvironmentProd
|
return c.Environment == EnvironmentProd
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// MetricsAuthEnabled reports whether /metrics is served behind basic
|
||||||
|
// auth. It is the only answer to that question in the codebase: the
|
||||||
|
// route mount, the Prometheus recording middleware and the startup
|
||||||
|
// log's hasMetricsAuth field all read this one method, so the log
|
||||||
|
// cannot report auth as off while the route is mounted.
|
||||||
|
//
|
||||||
|
// It requires both credentials rather than the username alone.
|
||||||
|
// loadFromEnv already rejects a half-set pair, but a Config built in
|
||||||
|
// code bypasses that, and the failure mode this guards is an endpoint
|
||||||
|
// mounted with a credential map whose only password is the empty
|
||||||
|
// string.
|
||||||
|
func (c *Config) MetricsAuthEnabled() bool {
|
||||||
|
return c.MetricsUsername != "" && c.MetricsPassword != ""
|
||||||
|
}
|
||||||
|
|
||||||
// envString returns the value of the named environment variable,
|
// envString returns the value of the named environment variable,
|
||||||
// or an empty string if not set.
|
// or an empty string if not set.
|
||||||
func envString(key string) string {
|
func envString(key string) string {
|
||||||
@@ -329,6 +354,30 @@ func envPrefixList(key string) ([]netip.Prefix, error) {
|
|||||||
return prefixes, nil
|
return prefixes, nil
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// resolveMetricsAuth reads the /metrics basic-auth credentials and
|
||||||
|
// rejects a half-set pair, naming both variables either way. The
|
||||||
|
// error carries neither value: the password is a secret.
|
||||||
|
func resolveMetricsAuth() (string, string, error) {
|
||||||
|
username := envString("METRICS_USERNAME")
|
||||||
|
password := envString("METRICS_PASSWORD")
|
||||||
|
|
||||||
|
if (username == "") == (password == "") {
|
||||||
|
return username, password, nil
|
||||||
|
}
|
||||||
|
|
||||||
|
set, empty := "METRICS_USERNAME", "METRICS_PASSWORD"
|
||||||
|
if username == "" {
|
||||||
|
set, empty = empty, set
|
||||||
|
}
|
||||||
|
|
||||||
|
return "", "", fmt.Errorf(
|
||||||
|
"%w: %s is set but %s is empty; METRICS_USERNAME and "+
|
||||||
|
"METRICS_PASSWORD must both be set to serve /metrics, "+
|
||||||
|
"or both be empty to leave it unmounted",
|
||||||
|
ErrIncompleteMetricsAuth, set, empty,
|
||||||
|
)
|
||||||
|
}
|
||||||
|
|
||||||
// resolveEnvironment reads WEBHOOKER_ENVIRONMENT, defaulting to
|
// resolveEnvironment reads WEBHOOKER_ENVIRONMENT, defaulting to
|
||||||
// dev, and rejects unrecognised values.
|
// dev, and rejects unrecognised values.
|
||||||
func resolveEnvironment() (string, error) {
|
func resolveEnvironment() (string, error) {
|
||||||
@@ -406,13 +455,18 @@ func loadFromEnv() (*Config, error) {
|
|||||||
return nil, err
|
return nil, err
|
||||||
}
|
}
|
||||||
|
|
||||||
|
metricsUsername, metricsPassword, err := resolveMetricsAuth()
|
||||||
|
if err != nil {
|
||||||
|
return nil, err
|
||||||
|
}
|
||||||
|
|
||||||
return &Config{
|
return &Config{
|
||||||
DataDir: envString("DATA_DIR"),
|
DataDir: envString("DATA_DIR"),
|
||||||
Debug: debug,
|
Debug: debug,
|
||||||
MaintenanceMode: maintenanceMode,
|
MaintenanceMode: maintenanceMode,
|
||||||
Environment: environment,
|
Environment: environment,
|
||||||
MetricsUsername: envString("METRICS_USERNAME"),
|
MetricsUsername: metricsUsername,
|
||||||
MetricsPassword: envString("METRICS_PASSWORD"),
|
MetricsPassword: metricsPassword,
|
||||||
Port: port,
|
Port: port,
|
||||||
SentryDSN: envString("SENTRY_DSN"),
|
SentryDSN: envString("SENTRY_DSN"),
|
||||||
RetentionSweepInterval: retentionSweepInterval,
|
RetentionSweepInterval: retentionSweepInterval,
|
||||||
@@ -512,8 +566,7 @@ func New(lc fx.Lifecycle, params ConfigParams) (*Config, error) {
|
|||||||
"receiverRateLimit", s.ReceiverRateLimit,
|
"receiverRateLimit", s.ReceiverRateLimit,
|
||||||
"trustedProxies", len(s.TrustedProxies),
|
"trustedProxies", len(s.TrustedProxies),
|
||||||
"hasSentryDSN", s.SentryDSN != "",
|
"hasSentryDSN", s.SentryDSN != "",
|
||||||
"hasMetricsAuth",
|
"hasMetricsAuth", s.MetricsAuthEnabled(),
|
||||||
s.MetricsUsername != "" && s.MetricsPassword != "",
|
|
||||||
)
|
)
|
||||||
|
|
||||||
s.warnSharedRateLimitBucket(log)
|
s.warnSharedRateLimitBucket(log)
|
||||||
|
|||||||
@@ -26,6 +26,12 @@ const (
|
|||||||
// cidrPrivateV4 is the sample trusted-proxy block the
|
// cidrPrivateV4 is the sample trusted-proxy block the
|
||||||
// TRUSTED_PROXIES cases are built from.
|
// TRUSTED_PROXIES cases are built from.
|
||||||
cidrPrivateV4 = "10.0.0.0/8"
|
cidrPrivateV4 = "10.0.0.0/8"
|
||||||
|
|
||||||
|
// metricsAuthValue is the sample METRICS_PASSWORD the metrics
|
||||||
|
// credential cases are built from. It is asserted absent from
|
||||||
|
// the startup error, so it must not be a substring of either
|
||||||
|
// variable name that error prints.
|
||||||
|
metricsAuthValue = "s3cret"
|
||||||
)
|
)
|
||||||
|
|
||||||
func TestEnvironmentConfig(t *testing.T) {
|
func TestEnvironmentConfig(t *testing.T) {
|
||||||
@@ -726,3 +732,168 @@ func TestSharedRateLimitBucketWarning(t *testing.T) {
|
|||||||
})
|
})
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// metricsEnv describes what one subtest below puts in the
|
||||||
|
// environment for a single METRICS_ variable. A variable that is
|
||||||
|
// set to the empty string and one that is not set at all are
|
||||||
|
// distinct inputs here, because the reported bug arrived through
|
||||||
|
// the first of them.
|
||||||
|
type metricsEnv struct {
|
||||||
|
set bool
|
||||||
|
value string
|
||||||
|
}
|
||||||
|
|
||||||
|
// unset leaves the variable out of the environment entirely.
|
||||||
|
func unset() metricsEnv {
|
||||||
|
return metricsEnv{set: false, value: ""}
|
||||||
|
}
|
||||||
|
|
||||||
|
// setTo sets the variable, including to the empty string.
|
||||||
|
func setTo(value string) metricsEnv {
|
||||||
|
return metricsEnv{set: true, value: value}
|
||||||
|
}
|
||||||
|
|
||||||
|
// metricsAuthCase is one row of the table in TestMetricsAuthConfig,
|
||||||
|
// named so the table can live in its own function and keep the test
|
||||||
|
// itself short.
|
||||||
|
type metricsAuthCase struct {
|
||||||
|
name string
|
||||||
|
username metricsEnv
|
||||||
|
password metricsEnv
|
||||||
|
expectError bool
|
||||||
|
expectAuth bool
|
||||||
|
}
|
||||||
|
|
||||||
|
// metricsAuthCases enumerates every combination of the two
|
||||||
|
// credentials, counting "set to the empty string" and "not set at
|
||||||
|
// all" as separate inputs on each side.
|
||||||
|
func metricsAuthCases() []metricsAuthCase {
|
||||||
|
return []metricsAuthCase{
|
||||||
|
{
|
||||||
|
name: "both unset leaves metrics unmounted",
|
||||||
|
username: unset(),
|
||||||
|
password: unset(),
|
||||||
|
},
|
||||||
|
{
|
||||||
|
name: "both empty leaves metrics unmounted",
|
||||||
|
username: setTo(""),
|
||||||
|
password: setTo(""),
|
||||||
|
},
|
||||||
|
{
|
||||||
|
name: "both set enables metrics auth",
|
||||||
|
username: setTo("metrics"),
|
||||||
|
password: setTo(metricsAuthValue),
|
||||||
|
expectAuth: true,
|
||||||
|
},
|
||||||
|
{
|
||||||
|
name: "username with unset password fails",
|
||||||
|
username: setTo("metrics"),
|
||||||
|
password: unset(),
|
||||||
|
expectError: true,
|
||||||
|
},
|
||||||
|
{
|
||||||
|
name: "username with empty password fails",
|
||||||
|
username: setTo("metrics"),
|
||||||
|
password: setTo(""),
|
||||||
|
expectError: true,
|
||||||
|
},
|
||||||
|
{
|
||||||
|
name: "password with unset username fails",
|
||||||
|
username: unset(),
|
||||||
|
password: setTo(metricsAuthValue),
|
||||||
|
expectError: true,
|
||||||
|
},
|
||||||
|
{
|
||||||
|
name: "password with empty username fails",
|
||||||
|
username: setTo(""),
|
||||||
|
password: setTo(metricsAuthValue),
|
||||||
|
expectError: true,
|
||||||
|
},
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// TestMetricsAuthConfig covers every combination of METRICS_USERNAME
|
||||||
|
// and METRICS_PASSWORD. Either both carry a value, in which case
|
||||||
|
// /metrics is served behind basic auth, or neither does, in which
|
||||||
|
// case the route is never mounted. One without the other is a
|
||||||
|
// startup error rather than a fallback: mounting on the username
|
||||||
|
// alone published /metrics behind a credential map that accepted an
|
||||||
|
// empty password, which is the defect this test exists to pin. See
|
||||||
|
// https://git.eeqj.de/sneak/webhooker/issues/205.
|
||||||
|
func TestMetricsAuthConfig(t *testing.T) {
|
||||||
|
for _, tt := range metricsAuthCases() {
|
||||||
|
t.Run(tt.name, func(t *testing.T) {
|
||||||
|
// Cannot use t.Parallel() here because t.Setenv
|
||||||
|
// is incompatible with parallel subtests.
|
||||||
|
if tt.username.set {
|
||||||
|
t.Setenv("METRICS_USERNAME", tt.username.value)
|
||||||
|
} else {
|
||||||
|
require.NoError(
|
||||||
|
t, os.Unsetenv("METRICS_USERNAME"),
|
||||||
|
)
|
||||||
|
}
|
||||||
|
|
||||||
|
if tt.password.set {
|
||||||
|
t.Setenv("METRICS_PASSWORD", tt.password.value)
|
||||||
|
} else {
|
||||||
|
require.NoError(
|
||||||
|
t, os.Unsetenv("METRICS_PASSWORD"),
|
||||||
|
)
|
||||||
|
}
|
||||||
|
|
||||||
|
if tt.expectError {
|
||||||
|
assertMetricsAuthRejected(t)
|
||||||
|
|
||||||
|
return
|
||||||
|
}
|
||||||
|
|
||||||
|
assertMetricsAuthAccepted(t, tt.expectAuth)
|
||||||
|
})
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// assertMetricsAuthRejected requires that fx refused to build the
|
||||||
|
// graph, that the failure is ErrIncompleteMetricsAuth, and that the
|
||||||
|
// operator is told both variable names — the point of failing here
|
||||||
|
// rather than degrading is that the message says what to fix.
|
||||||
|
func assertMetricsAuthRejected(t *testing.T) {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
var cfg *config.Config
|
||||||
|
|
||||||
|
app := fx.New(
|
||||||
|
fx.NopLogger,
|
||||||
|
fx.Provide(globals.New, logger.New, config.New),
|
||||||
|
fx.Populate(&cfg),
|
||||||
|
)
|
||||||
|
|
||||||
|
err := app.Err()
|
||||||
|
require.Error(t, err)
|
||||||
|
require.ErrorIs(t, err, config.ErrIncompleteMetricsAuth)
|
||||||
|
assert.Contains(t, err.Error(), "METRICS_USERNAME")
|
||||||
|
assert.Contains(t, err.Error(), "METRICS_PASSWORD")
|
||||||
|
// The password is a secret and must not reach a startup error.
|
||||||
|
assert.NotContains(t, err.Error(), metricsAuthValue)
|
||||||
|
}
|
||||||
|
|
||||||
|
// assertMetricsAuthAccepted requires that startup succeeded and that
|
||||||
|
// MetricsAuthEnabled — the single value the /metrics mount and the
|
||||||
|
// startup log both read — reports what the environment asked for.
|
||||||
|
func assertMetricsAuthAccepted(t *testing.T, expectAuth bool) {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
var cfg *config.Config
|
||||||
|
|
||||||
|
app := fxtest.New(
|
||||||
|
t,
|
||||||
|
fx.Provide(globals.New, logger.New, config.New),
|
||||||
|
fx.Populate(&cfg),
|
||||||
|
)
|
||||||
|
require.NoError(t, app.Err())
|
||||||
|
|
||||||
|
app.RequireStart()
|
||||||
|
|
||||||
|
defer app.RequireStop()
|
||||||
|
|
||||||
|
assert.Equal(t, expectAuth, cfg.MetricsAuthEnabled())
|
||||||
|
}
|
||||||
|
|||||||
229
internal/gormlog/firstboot_test.go
Normal file
229
internal/gormlog/firstboot_test.go
Normal file
@@ -0,0 +1,229 @@
|
|||||||
|
package gormlog_test
|
||||||
|
|
||||||
|
import (
|
||||||
|
"context"
|
||||||
|
"database/sql"
|
||||||
|
"os"
|
||||||
|
"path/filepath"
|
||||||
|
"testing"
|
||||||
|
|
||||||
|
"github.com/stretchr/testify/assert"
|
||||||
|
"github.com/stretchr/testify/require"
|
||||||
|
"go.uber.org/fx"
|
||||||
|
"go.uber.org/fx/fxtest"
|
||||||
|
_ "modernc.org/sqlite" // Pure Go SQLite driver.
|
||||||
|
"sneak.berlin/go/webhooker/internal/config"
|
||||||
|
"sneak.berlin/go/webhooker/internal/database"
|
||||||
|
"sneak.berlin/go/webhooker/internal/globals"
|
||||||
|
"sneak.berlin/go/webhooker/internal/logger"
|
||||||
|
"sneak.berlin/go/webhooker/internal/session"
|
||||||
|
)
|
||||||
|
|
||||||
|
// argon2Prefix opens every encoded Argon2id hash this service
|
||||||
|
// produces. It is asserted on separately from the hash itself, so that
|
||||||
|
// a change to the password encoding cannot quietly turn the hash
|
||||||
|
// assertion into a comparison against a string the log never held.
|
||||||
|
const argon2Prefix = "$argon2id$"
|
||||||
|
|
||||||
|
// settingsInsert and usersInsert are the two statements a first boot
|
||||||
|
// runs that carry a secret. The sqlite dialector quotes identifiers
|
||||||
|
// with backticks.
|
||||||
|
const (
|
||||||
|
settingsInsert = "INSERT INTO `settings`"
|
||||||
|
usersInsert = "INSERT INTO `users`"
|
||||||
|
)
|
||||||
|
|
||||||
|
// captureStdoutToFile redirects os.Stdout into a file for the rest of
|
||||||
|
// the test and returns a function that reads back everything written
|
||||||
|
// to it.
|
||||||
|
//
|
||||||
|
// A file rather than a pipe: internal/logger writes synchronously to
|
||||||
|
// whatever os.Stdout is when it builds its handler, so once fx's start
|
||||||
|
// returns, every byte the boot produced is already in the file and no
|
||||||
|
// draining goroutine is needed to prove it. Redirecting the variable
|
||||||
|
// before the application is built is what puts the service logger —
|
||||||
|
// and therefore the GORM adapter, which writes through it — into the
|
||||||
|
// capture.
|
||||||
|
//
|
||||||
|
// The redirect also decides the handler: a regular file is not a
|
||||||
|
// character device, so internal/logger installs its JSON handler, the
|
||||||
|
// one it installs in production under a log collector.
|
||||||
|
func captureStdoutToFile(t *testing.T) func() string {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
path := filepath.Join(t.TempDir(), "stdout.log")
|
||||||
|
|
||||||
|
//nolint:gosec // The path is this test's own t.TempDir().
|
||||||
|
f, err := os.Create(path)
|
||||||
|
require.NoError(t, err)
|
||||||
|
|
||||||
|
orig := os.Stdout
|
||||||
|
os.Stdout = f
|
||||||
|
|
||||||
|
t.Cleanup(func() {
|
||||||
|
os.Stdout = orig
|
||||||
|
_ = f.Close()
|
||||||
|
})
|
||||||
|
|
||||||
|
return func() string {
|
||||||
|
require.NoError(t, f.Sync())
|
||||||
|
|
||||||
|
//nolint:gosec // As above.
|
||||||
|
b, readErr := os.ReadFile(path)
|
||||||
|
require.NoError(t, readErr)
|
||||||
|
|
||||||
|
return string(b)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// firstBootSecrets are the two values a first boot generates and
|
||||||
|
// stores, read back out of the database.
|
||||||
|
type firstBootSecrets struct {
|
||||||
|
sessionKey string
|
||||||
|
passwordHash string
|
||||||
|
}
|
||||||
|
|
||||||
|
// readFirstBootSecrets reads those two secrets straight out of the
|
||||||
|
// SQLite file with database/sql rather than through GORM, so that
|
||||||
|
// reading them cannot itself add a line to the log under test.
|
||||||
|
func readFirstBootSecrets(
|
||||||
|
t *testing.T, dataDir string,
|
||||||
|
) firstBootSecrets {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
db, err := sql.Open("sqlite", filepath.Join(
|
||||||
|
dataDir, "webhooker.db",
|
||||||
|
))
|
||||||
|
require.NoError(t, err)
|
||||||
|
|
||||||
|
defer func() { require.NoError(t, db.Close()) }()
|
||||||
|
|
||||||
|
ctx := context.Background()
|
||||||
|
|
||||||
|
var got firstBootSecrets
|
||||||
|
|
||||||
|
require.NoError(t, db.QueryRowContext(
|
||||||
|
ctx, `SELECT value FROM settings WHERE key = 'session_key'`,
|
||||||
|
).Scan(&got.sessionKey))
|
||||||
|
|
||||||
|
require.NoError(t, db.QueryRowContext(
|
||||||
|
ctx, `SELECT password FROM users WHERE username = 'admin'`,
|
||||||
|
).Scan(&got.passwordHash))
|
||||||
|
|
||||||
|
require.NotEmpty(t, got.sessionKey)
|
||||||
|
require.Contains(t, got.passwordHash, argon2Prefix)
|
||||||
|
|
||||||
|
return got
|
||||||
|
}
|
||||||
|
|
||||||
|
// bootAtDebug starts and stops the real application graph against
|
||||||
|
// dataDir with DEBUG=true, and returns everything it wrote to standard
|
||||||
|
// output.
|
||||||
|
//
|
||||||
|
// config.New reads DEBUG from the environment exactly as the binary
|
||||||
|
// does, internal/logger builds the handler it builds in production,
|
||||||
|
// database.New runs the migrations and creates the admin user, and
|
||||||
|
// session.New takes the session key. Those four are the whole of the
|
||||||
|
// path that writes either secret.
|
||||||
|
func bootAtDebug(t *testing.T, dataDir string) string {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
t.Setenv("DEBUG", "true")
|
||||||
|
t.Setenv("DATA_DIR", dataDir)
|
||||||
|
|
||||||
|
read := captureStdoutToFile(t)
|
||||||
|
|
||||||
|
var sess *session.Session
|
||||||
|
|
||||||
|
app := fxtest.New(
|
||||||
|
t,
|
||||||
|
fx.Provide(
|
||||||
|
globals.New,
|
||||||
|
logger.New,
|
||||||
|
config.New,
|
||||||
|
database.New,
|
||||||
|
session.New,
|
||||||
|
),
|
||||||
|
fx.Populate(&sess),
|
||||||
|
)
|
||||||
|
|
||||||
|
app.RequireStart()
|
||||||
|
app.RequireStop()
|
||||||
|
|
||||||
|
return read()
|
||||||
|
}
|
||||||
|
|
||||||
|
// requireFirstBootWasLogged is the non-vacuity half of the test below.
|
||||||
|
// Without it a build that logged no SQL at all, or that never reached
|
||||||
|
// DEBUG, would satisfy every absence assertion.
|
||||||
|
func requireFirstBootWasLogged(t *testing.T, out string) {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
require.Contains(
|
||||||
|
t, out, `"level":"DEBUG"`,
|
||||||
|
"DEBUG=true did not reach the logger",
|
||||||
|
)
|
||||||
|
require.Contains(
|
||||||
|
t, out, settingsInsert,
|
||||||
|
"the session key INSERT was not logged, so its absence "+
|
||||||
|
"proves nothing",
|
||||||
|
)
|
||||||
|
require.Contains(
|
||||||
|
t, out, usersInsert,
|
||||||
|
"the admin user INSERT was not logged, so its absence "+
|
||||||
|
"proves nothing",
|
||||||
|
)
|
||||||
|
}
|
||||||
|
|
||||||
|
// TestFirstBootAtDebug_LogsNeitherSecret is the definition of done.
|
||||||
|
//
|
||||||
|
// A first boot is the only boot that writes either secret. The
|
||||||
|
// settings INSERT carries the base64 session encryption key, which is
|
||||||
|
// the whole of the session security model: anyone holding it can forge
|
||||||
|
// an authenticated session cookie. The users INSERT carries the admin
|
||||||
|
// account's Argon2id hash. Under interpolated statement logging both
|
||||||
|
// landed in the log an operator diagnosing a startup problem pastes
|
||||||
|
// into an issue.
|
||||||
|
//
|
||||||
|
// The secrets are read back out of the database file afterwards, so
|
||||||
|
// the assertions are made against the values this boot actually
|
||||||
|
// generated rather than against a pattern that might not match them.
|
||||||
|
//
|
||||||
|
// What this test does not cover: the initial admin password itself,
|
||||||
|
// which internal/database logs once in the clear, on purpose, because
|
||||||
|
// that line is the only place an operator ever sees it. That is a
|
||||||
|
// separate decision from the SQL log, and it is documented in the
|
||||||
|
// README rather than asserted here.
|
||||||
|
//
|
||||||
|
// Not parallel: it redirects os.Stdout and sets environment variables,
|
||||||
|
// both process-global.
|
||||||
|
//
|
||||||
|
//nolint:paralleltest // Deliberately sequential; see above.
|
||||||
|
func TestFirstBootAtDebug_LogsNeitherSecret(t *testing.T) {
|
||||||
|
dataDir := t.TempDir()
|
||||||
|
|
||||||
|
// An empty DATA_DIR is what makes this a first boot: with a
|
||||||
|
// database already in place neither INSERT runs.
|
||||||
|
entries, err := os.ReadDir(dataDir)
|
||||||
|
require.NoError(t, err)
|
||||||
|
require.Empty(t, entries, "DATA_DIR was not empty")
|
||||||
|
|
||||||
|
out := bootAtDebug(t, dataDir)
|
||||||
|
|
||||||
|
requireFirstBootWasLogged(t, out)
|
||||||
|
|
||||||
|
secrets := readFirstBootSecrets(t, dataDir)
|
||||||
|
|
||||||
|
assert.NotContains(
|
||||||
|
t, out, secrets.sessionKey,
|
||||||
|
"the session encryption key reached the debug log",
|
||||||
|
)
|
||||||
|
assert.NotContains(
|
||||||
|
t, out, secrets.passwordHash,
|
||||||
|
"the admin password hash reached the debug log",
|
||||||
|
)
|
||||||
|
assert.NotContains(
|
||||||
|
t, out, argon2Prefix,
|
||||||
|
"an encoded Argon2id hash reached the debug log",
|
||||||
|
)
|
||||||
|
}
|
||||||
@@ -17,6 +17,10 @@
|
|||||||
// level the operator controls, they are shaped by whichever handler
|
// level the operator controls, they are shaped by whichever handler
|
||||||
// internal/logger selected, and every value a client can influence is
|
// internal/logger selected, and every value a client can influence is
|
||||||
// spent through logfield.Truncate.
|
// spent through logfield.Truncate.
|
||||||
|
//
|
||||||
|
// It also logs no bound value at all. See ParamsFilter: the statement
|
||||||
|
// is written with its placeholders intact, at every level, so the
|
||||||
|
// values a statement carries never reach the log in the first place.
|
||||||
package gormlog
|
package gormlog
|
||||||
|
|
||||||
import (
|
import (
|
||||||
@@ -26,6 +30,7 @@ import (
|
|||||||
"log/slog"
|
"log/slog"
|
||||||
"time"
|
"time"
|
||||||
|
|
||||||
|
"gorm.io/gorm"
|
||||||
gormlogger "gorm.io/gorm/logger"
|
gormlogger "gorm.io/gorm/logger"
|
||||||
"sneak.berlin/go/webhooker/internal/logfield"
|
"sneak.berlin/go/webhooker/internal/logfield"
|
||||||
)
|
)
|
||||||
@@ -47,8 +52,14 @@ type Logger struct {
|
|||||||
}
|
}
|
||||||
|
|
||||||
// Interface compliance is asserted here rather than discovered at the
|
// Interface compliance is asserted here rather than discovered at the
|
||||||
// gorm.Open call sites.
|
// gorm.Open call sites. gorm.ParamsFilter is the optional half: GORM
|
||||||
var _ gormlogger.Interface = (*Logger)(nil)
|
// type-asserts for it and silently keeps interpolating if it is
|
||||||
|
// missing, so losing it would cost no build error and no test that
|
||||||
|
// does not look at the emitted SQL.
|
||||||
|
var (
|
||||||
|
_ gormlogger.Interface = (*Logger)(nil)
|
||||||
|
_ gorm.ParamsFilter = (*Logger)(nil)
|
||||||
|
)
|
||||||
|
|
||||||
// New returns a GORM logger that writes through log.
|
// New returns a GORM logger that writes through log.
|
||||||
func New(log *slog.Logger) *Logger {
|
func New(log *slog.Logger) *Logger {
|
||||||
@@ -71,6 +82,46 @@ func (l *Logger) LogMode(gormlogger.LogLevel) gormlogger.Interface {
|
|||||||
return l
|
return l
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// ParamsFilter drops every bound value before GORM renders a statement
|
||||||
|
// for the log, so what is logged is the statement's shape — its
|
||||||
|
// placeholders — and never the values in it.
|
||||||
|
//
|
||||||
|
// GORM builds the string it hands to Trace by calling
|
||||||
|
// Dialector.Explain(sql, vars...), which substitutes each value into
|
||||||
|
// the statement. Discarding vars here leaves the '?' placeholders in
|
||||||
|
// place, because ExplainSQL only substitutes while it still has a
|
||||||
|
// value for the next one. That happens before Trace is reached, so it
|
||||||
|
// holds on all three of its arms: the failed statement, the slow one,
|
||||||
|
// and the routine one an operator sees at DEBUG.
|
||||||
|
//
|
||||||
|
// This is the whole of the fix, and it is deliberately unconditional
|
||||||
|
// rather than a list of tables to redact. At first boot the two
|
||||||
|
// statements that carry a secret are the INSERT into settings holding
|
||||||
|
// the base64 session key — which is the entire session security model,
|
||||||
|
// since anyone with it can mint a valid cookie — and the INSERT into
|
||||||
|
// users holding the Argon2id hash. A denylist would have had to be
|
||||||
|
// extended by hand for every table added afterwards, and the cost of
|
||||||
|
// missing one is a credential in a log that gets pasted into issues.
|
||||||
|
//
|
||||||
|
// What is given up is the ability to read a value out of the log. The
|
||||||
|
// statement, the table, the error and the row count are all still
|
||||||
|
// there, which is what identifies a failing statement; reproducing it
|
||||||
|
// needs the values, and those an operator now gets from the database
|
||||||
|
// rather than from the log.
|
||||||
|
//
|
||||||
|
// One GORM path does not consult this: (*gorm.DB).Scan records the
|
||||||
|
// statement through gorm's own traceRecorder, which does not implement
|
||||||
|
// this interface. No production code path calls it; its one caller is
|
||||||
|
// internal/database/database_test.go:91, whose SELECT 1 binds nothing.
|
||||||
|
// scan_guard_test.go fails if a non-test file calls it.
|
||||||
|
// (*gorm.DB).Pluck, Row and Raw all run through the normal callback
|
||||||
|
// processor and are filtered.
|
||||||
|
func (l *Logger) ParamsFilter(
|
||||||
|
_ context.Context, sql string, _ ...any,
|
||||||
|
) (string, []any) {
|
||||||
|
return sql, nil
|
||||||
|
}
|
||||||
|
|
||||||
// Info logs one of GORM's own informational messages.
|
// Info logs one of GORM's own informational messages.
|
||||||
func (l *Logger) Info(
|
func (l *Logger) Info(
|
||||||
ctx context.Context, msg string, data ...any,
|
ctx context.Context, msg string, data ...any,
|
||||||
@@ -93,9 +144,9 @@ func (l *Logger) Error(
|
|||||||
}
|
}
|
||||||
|
|
||||||
// Trace reports the outcome of a single statement. GORM calls it for
|
// Trace reports the outcome of a single statement. GORM calls it for
|
||||||
// every statement it runs, so the cheap paths stay cheap: fc()
|
// every statement it runs, so the cheap paths stay cheap: fc() renders
|
||||||
// renders the interpolated SQL and is called only on a branch that
|
// the statement — with placeholders, per ParamsFilter — and is called
|
||||||
// will actually emit.
|
// only on a branch that will actually emit.
|
||||||
//
|
//
|
||||||
// The arms are ordered exactly as GORM's own Trace orders them —
|
// The arms are ordered exactly as GORM's own Trace orders them —
|
||||||
// non-record-not-found error, then slow, then the routine case — so
|
// non-record-not-found error, then slow, then the routine case — so
|
||||||
|
|||||||
@@ -232,7 +232,7 @@ func TestSlowRecordNotFound_IsStillReportedSlow(t *testing.T) {
|
|||||||
require.ErrorIs(t, err, gorm.ErrRecordNotFound)
|
require.ErrorIs(t, err, gorm.ErrRecordNotFound)
|
||||||
|
|
||||||
assert.Contains(
|
assert.Contains(
|
||||||
t, buf.String(), "slow sql statement",
|
t, buf.String(), slowLine,
|
||||||
"a slow statement that missed was not "+
|
"a slow statement that missed was not "+
|
||||||
"reported as slow",
|
"reported as slow",
|
||||||
)
|
)
|
||||||
@@ -284,9 +284,11 @@ func TestRecordNotFoundFlood_DoesNotGrowWithInput(t *testing.T) {
|
|||||||
}
|
}
|
||||||
|
|
||||||
// TestStatementError_LineIsBounded covers the branch that does log.
|
// TestStatementError_LineIsBounded covers the branch that does log.
|
||||||
// A driver error is not ErrRecordNotFound, so the interpolated
|
// A driver error is not ErrRecordNotFound, so the statement is
|
||||||
// statement is written — and on an insert the interpolated value is
|
// written, and the driver's own error text can quote what the client
|
||||||
// still whatever the client supplied.
|
// supplied. The statement's parameters are no longer part of that —
|
||||||
|
// see TestBoundValues_NeverReachTheLog — but the budget is what holds
|
||||||
|
// the line when the statement itself, or the error, is the long part.
|
||||||
func TestStatementError_LineIsBounded(t *testing.T) {
|
func TestStatementError_LineIsBounded(t *testing.T) {
|
||||||
t.Parallel()
|
t.Parallel()
|
||||||
|
|
||||||
@@ -313,7 +315,7 @@ func TestStatementError_LineIsBounded(t *testing.T) {
|
|||||||
require.Error(t, err)
|
require.Error(t, err)
|
||||||
|
|
||||||
assert.Contains(
|
assert.Contains(
|
||||||
t, buf.String(), "sql statement failed",
|
t, buf.String(), errorLine,
|
||||||
)
|
)
|
||||||
assertBounded(t, buf.String())
|
assertBounded(t, buf.String())
|
||||||
})
|
})
|
||||||
@@ -329,22 +331,22 @@ func TestStatementError_LineIsBounded(t *testing.T) {
|
|||||||
// and would have cost this report, which is the one thing GORM's
|
// and would have cost this report, which is the one thing GORM's
|
||||||
// logger gave an operator that nothing else in this service does.
|
// logger gave an operator that nothing else in this service does.
|
||||||
// - routine. The branch an operator reaches by turning the level
|
// - routine. The branch an operator reaches by turning the level
|
||||||
// down to DEBUG: every statement is reported, so every
|
// down to DEBUG: every statement is reported, so every statement
|
||||||
// statement's interpolated parameters have to be bounded too.
|
// has to be bounded too.
|
||||||
func TestSucceedingStatement_LineIsBoundedOnEitherArm(t *testing.T) {
|
func TestSucceedingStatement_LineIsBoundedOnEitherArm(t *testing.T) {
|
||||||
t.Parallel()
|
t.Parallel()
|
||||||
|
|
||||||
// "sql statement" is a substring of "slow sql statement", so the
|
// routineLine is a substring of slowLine, so the routine arm
|
||||||
// routine arm carries notWant as well: Contains alone cannot tell
|
// carries notWant as well: Contains alone cannot tell the two arms
|
||||||
// the two arms apart in that direction.
|
// apart in that direction.
|
||||||
arms := []struct {
|
arms := []struct {
|
||||||
name string
|
name string
|
||||||
slow time.Duration
|
slow time.Duration
|
||||||
want string
|
want string
|
||||||
notWant string
|
notWant string
|
||||||
}{
|
}{
|
||||||
{"slow", alwaysSlow, "slow sql statement", ""},
|
{"slow", alwaysSlow, slowLine, ""},
|
||||||
{"routine", neverSlow, "sql statement", "slow sql statement"},
|
{"routine", neverSlow, routineLine, slowLine},
|
||||||
}
|
}
|
||||||
|
|
||||||
for _, a := range arms {
|
for _, a := range arms {
|
||||||
|
|||||||
260
internal/gormlog/scan_guard_test.go
Normal file
260
internal/gormlog/scan_guard_test.go
Normal file
@@ -0,0 +1,260 @@
|
|||||||
|
package gormlog_test
|
||||||
|
|
||||||
|
import (
|
||||||
|
"fmt"
|
||||||
|
"go/ast"
|
||||||
|
"go/parser"
|
||||||
|
"go/token"
|
||||||
|
"io/fs"
|
||||||
|
"os"
|
||||||
|
"path/filepath"
|
||||||
|
"strings"
|
||||||
|
"testing"
|
||||||
|
|
||||||
|
"github.com/stretchr/testify/require"
|
||||||
|
)
|
||||||
|
|
||||||
|
// minNonTestFiles guards the walk below against passing because it
|
||||||
|
// found nothing to look at. The tree held 60 non-test .go files when
|
||||||
|
// this was written.
|
||||||
|
const minNonTestFiles = 40
|
||||||
|
|
||||||
|
// isRowProducer reports whether name is a method that returns a
|
||||||
|
// database/sql row handle. GORM's Row and Rows return *sql.Row and
|
||||||
|
// *sql.Rows, so Scan on the result of one of them is database/sql's
|
||||||
|
// Scan and never (*gorm.DB).Scan.
|
||||||
|
func isRowProducer(name string) bool {
|
||||||
|
switch name {
|
||||||
|
case "Row", "Rows", "QueryRow", "QueryRowContext":
|
||||||
|
return true
|
||||||
|
default:
|
||||||
|
return false
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// receiverIsRowHandle reports whether x is syntactically a call to a
|
||||||
|
// row producer, which is the only receiver form this check accepts for
|
||||||
|
// a Scan.
|
||||||
|
func receiverIsRowHandle(x ast.Expr) bool {
|
||||||
|
call, ok := x.(*ast.CallExpr)
|
||||||
|
if !ok {
|
||||||
|
return false
|
||||||
|
}
|
||||||
|
|
||||||
|
sel, ok := call.Fun.(*ast.SelectorExpr)
|
||||||
|
if !ok {
|
||||||
|
return false
|
||||||
|
}
|
||||||
|
|
||||||
|
return isRowProducer(sel.Sel.Name)
|
||||||
|
}
|
||||||
|
|
||||||
|
// unguardedScans returns the position of every Scan call in file whose
|
||||||
|
// receiver is not a row handle. It fails closed: a receiver it cannot
|
||||||
|
// resolve syntactically — a local variable, a struct field — is
|
||||||
|
// reported rather than assumed safe.
|
||||||
|
func unguardedScans(
|
||||||
|
fset *token.FileSet, file *ast.File,
|
||||||
|
) []token.Position {
|
||||||
|
var found []token.Position
|
||||||
|
|
||||||
|
ast.Inspect(file, func(n ast.Node) bool {
|
||||||
|
call, ok := n.(*ast.CallExpr)
|
||||||
|
if !ok {
|
||||||
|
return true
|
||||||
|
}
|
||||||
|
|
||||||
|
sel, ok := call.Fun.(*ast.SelectorExpr)
|
||||||
|
if !ok || sel.Sel.Name != "Scan" {
|
||||||
|
return true
|
||||||
|
}
|
||||||
|
|
||||||
|
if !receiverIsRowHandle(sel.X) {
|
||||||
|
found = append(found, fset.Position(sel.Sel.Pos()))
|
||||||
|
}
|
||||||
|
|
||||||
|
return true
|
||||||
|
})
|
||||||
|
|
||||||
|
return found
|
||||||
|
}
|
||||||
|
|
||||||
|
// moduleRoot walks up from the working directory to the directory
|
||||||
|
// holding go.mod.
|
||||||
|
func moduleRoot(t *testing.T) string {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
dir, err := os.Getwd()
|
||||||
|
require.NoError(t, err)
|
||||||
|
|
||||||
|
for {
|
||||||
|
_, statErr := os.Stat(filepath.Join(dir, "go.mod"))
|
||||||
|
if statErr == nil {
|
||||||
|
return dir
|
||||||
|
}
|
||||||
|
|
||||||
|
parent := filepath.Dir(dir)
|
||||||
|
require.NotEqual(t, parent, dir, "no go.mod above %s", dir)
|
||||||
|
|
||||||
|
dir = parent
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// skipDir reports whether a directory holds no source this check
|
||||||
|
// governs.
|
||||||
|
func skipDir(name string) bool {
|
||||||
|
switch name {
|
||||||
|
case ".git", "bin", "node_modules", "testdata":
|
||||||
|
return true
|
||||||
|
default:
|
||||||
|
return false
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// walkNonTestGo parses every non-test .go file under root and returns
|
||||||
|
// how many it parsed along with every unguarded Scan it found.
|
||||||
|
func walkNonTestGo(t *testing.T, root string) (int, []string) {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
var (
|
||||||
|
parsed int
|
||||||
|
hits []string
|
||||||
|
)
|
||||||
|
|
||||||
|
fset := token.NewFileSet()
|
||||||
|
|
||||||
|
require.NoError(t, filepath.WalkDir(
|
||||||
|
root,
|
||||||
|
func(path string, d fs.DirEntry, err error) error {
|
||||||
|
if err != nil {
|
||||||
|
return err
|
||||||
|
}
|
||||||
|
|
||||||
|
if d.IsDir() {
|
||||||
|
if skipDir(d.Name()) {
|
||||||
|
return fs.SkipDir
|
||||||
|
}
|
||||||
|
|
||||||
|
return nil
|
||||||
|
}
|
||||||
|
|
||||||
|
if !isNonTestGo(d.Name()) {
|
||||||
|
return nil
|
||||||
|
}
|
||||||
|
|
||||||
|
file, err := parser.ParseFile(fset, path, nil, 0)
|
||||||
|
if err != nil {
|
||||||
|
return err
|
||||||
|
}
|
||||||
|
|
||||||
|
parsed++
|
||||||
|
|
||||||
|
for _, pos := range unguardedScans(fset, file) {
|
||||||
|
hits = append(hits, relPosition(root, pos))
|
||||||
|
}
|
||||||
|
|
||||||
|
return nil
|
||||||
|
},
|
||||||
|
))
|
||||||
|
|
||||||
|
return parsed, hits
|
||||||
|
}
|
||||||
|
|
||||||
|
// isNonTestGo reports whether a file name is Go source this check
|
||||||
|
// governs.
|
||||||
|
func isNonTestGo(name string) bool {
|
||||||
|
return strings.HasSuffix(name, ".go") &&
|
||||||
|
!strings.HasSuffix(name, "_test.go")
|
||||||
|
}
|
||||||
|
|
||||||
|
// relPosition renders pos with its path relative to root, so a failure
|
||||||
|
// names the file the way the repository does.
|
||||||
|
func relPosition(root string, pos token.Position) string {
|
||||||
|
name := pos.Filename
|
||||||
|
|
||||||
|
rel, err := filepath.Rel(root, name)
|
||||||
|
if err == nil {
|
||||||
|
name = rel
|
||||||
|
}
|
||||||
|
|
||||||
|
return fmt.Sprintf("%s:%d:%d", name, pos.Line, pos.Column)
|
||||||
|
}
|
||||||
|
|
||||||
|
// TestGormScanIsNeverCalledOutsideTests keeps (*gorm.DB).Scan out of
|
||||||
|
// non-test code.
|
||||||
|
//
|
||||||
|
// It is the one statement path (*Logger).ParamsFilter does not reach:
|
||||||
|
// Scan swaps GORM's own trace recorder in for the adapter, and that
|
||||||
|
// recorder does not implement gorm.ParamsFilter, so the statement is
|
||||||
|
// logged with its values interpolated. The package comment states the
|
||||||
|
// limit; this fails when someone adds a call site anyway.
|
||||||
|
//
|
||||||
|
// The current tree has one caller, internal/database/database_test.go,
|
||||||
|
// which this check does not govern: it is test-only and its SELECT 1
|
||||||
|
// binds nothing.
|
||||||
|
func TestGormScanIsNeverCalledOutsideTests(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
parsed, offenders := walkNonTestGo(t, moduleRoot(t))
|
||||||
|
|
||||||
|
require.GreaterOrEqual(
|
||||||
|
t, parsed, minNonTestFiles,
|
||||||
|
"parsed %d non-test .go files, so this check found "+
|
||||||
|
"nothing to look at", parsed,
|
||||||
|
)
|
||||||
|
require.Empty(
|
||||||
|
t, offenders,
|
||||||
|
"Scan called on a receiver this check cannot show is a "+
|
||||||
|
"database/sql row handle. (*gorm.DB).Scan logs the "+
|
||||||
|
"statement with its bound values interpolated — use "+
|
||||||
|
"Find, Pluck, or Raw(...).Row().Scan instead. A "+
|
||||||
|
"database/sql Scan reached through a variable is "+
|
||||||
|
"reported too; write it as <producer>().Scan rather "+
|
||||||
|
"than widening this check.",
|
||||||
|
)
|
||||||
|
}
|
||||||
|
|
||||||
|
// scanGuardCase is one planted snippet and whether the check above
|
||||||
|
// should report it.
|
||||||
|
type scanGuardCase struct {
|
||||||
|
name string
|
||||||
|
body string
|
||||||
|
want int
|
||||||
|
}
|
||||||
|
|
||||||
|
func scanGuardCases() []scanGuardCase {
|
||||||
|
return []scanGuardCase{
|
||||||
|
{"gorm chain", `db.DB().Raw("SELECT 1").Scan(&v)`, 1},
|
||||||
|
{"gorm receiver", `gdb.Scan(&v)`, 1},
|
||||||
|
{"gorm via variable", "q := gdb.Raw(\"x\")\nq.Scan(&v)", 1},
|
||||||
|
{"gorm model chain", `gdb.Model(&x).Scan(&v)`, 1},
|
||||||
|
{"sql row", `gdb.Raw("SELECT 1").Row().Scan(&v)`, 0},
|
||||||
|
{"sql rows", `gdb.Raw("SELECT 1").Rows().Scan(&v)`, 0},
|
||||||
|
{"unrelated call", `gdb.Find(&v)`, 0},
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// TestScanGuard_ReportsPlantedCalls proves the check fires. Without it
|
||||||
|
// a detector that matched nothing would satisfy the walk above no
|
||||||
|
// matter what the tree contained.
|
||||||
|
func TestScanGuard_ReportsPlantedCalls(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
for _, tc := range scanGuardCases() {
|
||||||
|
t.Run(tc.name, func(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
fset := token.NewFileSet()
|
||||||
|
src := fmt.Sprintf(
|
||||||
|
"package p\n\nfunc f() {\n\t%s\n}\n", tc.body,
|
||||||
|
)
|
||||||
|
|
||||||
|
file, err := parser.ParseFile(
|
||||||
|
fset, tc.name+".go", src, 0,
|
||||||
|
)
|
||||||
|
require.NoError(t, err)
|
||||||
|
|
||||||
|
require.Len(t, unguardedScans(fset, file), tc.want)
|
||||||
|
})
|
||||||
|
}
|
||||||
|
}
|
||||||
185
internal/gormlog/values_test.go
Normal file
185
internal/gormlog/values_test.go
Normal file
@@ -0,0 +1,185 @@
|
|||||||
|
package gormlog_test
|
||||||
|
|
||||||
|
import (
|
||||||
|
"bytes"
|
||||||
|
"strings"
|
||||||
|
"testing"
|
||||||
|
"time"
|
||||||
|
|
||||||
|
"github.com/stretchr/testify/assert"
|
||||||
|
"github.com/stretchr/testify/require"
|
||||||
|
"gorm.io/gorm"
|
||||||
|
)
|
||||||
|
|
||||||
|
// secretValue is bound as a parameter by every case below. Nothing
|
||||||
|
// else in this package writes it, so finding it in captured output
|
||||||
|
// means a bound value was rendered into the log.
|
||||||
|
const secretValue = "QQBOUNDVALUEMARKERQQ"
|
||||||
|
|
||||||
|
// The three messages Trace emits under, one per arm.
|
||||||
|
//
|
||||||
|
// routineLine is a substring of slowLine, so a case that wants the
|
||||||
|
// routine arm has to rule the slow one out as well rather than rely on
|
||||||
|
// Contains alone.
|
||||||
|
const (
|
||||||
|
routineLine = "sql statement"
|
||||||
|
slowLine = "slow sql statement"
|
||||||
|
errorLine = "sql statement failed"
|
||||||
|
)
|
||||||
|
|
||||||
|
// boundValueCase is one arm of Trace, driven by a statement that binds
|
||||||
|
// secretValue.
|
||||||
|
type boundValueCase struct {
|
||||||
|
name string
|
||||||
|
slow time.Duration
|
||||||
|
want string
|
||||||
|
drive func(t *testing.T, gdb *gorm.DB)
|
||||||
|
}
|
||||||
|
|
||||||
|
// insertSecret returns a driver that inserts one row whose Name is the
|
||||||
|
// secret.
|
||||||
|
func insertSecret(id string) func(*testing.T, *gorm.DB) {
|
||||||
|
return func(t *testing.T, gdb *gorm.DB) {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
require.NoError(t, gdb.Create(&thing{
|
||||||
|
ID: id, Name: secretValue,
|
||||||
|
}).Error)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// insertSecretTwice drives the error arm: the same primary key a
|
||||||
|
// second time is a UNIQUE constraint failure, which is an error GORM
|
||||||
|
// logs with the statement.
|
||||||
|
func insertSecretTwice(t *testing.T, gdb *gorm.DB) {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
require.NoError(t, gdb.Create(&thing{
|
||||||
|
ID: secretValue, Name: secretValue,
|
||||||
|
}).Error)
|
||||||
|
require.Error(t, gdb.Create(&thing{
|
||||||
|
ID: secretValue, Name: "other",
|
||||||
|
}).Error)
|
||||||
|
}
|
||||||
|
|
||||||
|
// selectSecret drives a query whose WHERE clause binds the secret,
|
||||||
|
// covering the read side as well as the write side.
|
||||||
|
func selectSecret(t *testing.T, gdb *gorm.DB) {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
var got []thing
|
||||||
|
|
||||||
|
require.NoError(
|
||||||
|
t, gdb.Where("name = ?", secretValue).Find(&got).Error,
|
||||||
|
)
|
||||||
|
}
|
||||||
|
|
||||||
|
func boundValueCases() []boundValueCase {
|
||||||
|
return []boundValueCase{
|
||||||
|
{
|
||||||
|
name: "routine", slow: neverSlow,
|
||||||
|
want: routineLine, drive: insertSecret("routine"),
|
||||||
|
},
|
||||||
|
{
|
||||||
|
name: "slow", slow: alwaysSlow,
|
||||||
|
want: slowLine, drive: insertSecret("slow"),
|
||||||
|
},
|
||||||
|
{
|
||||||
|
name: "error", slow: neverSlow,
|
||||||
|
want: errorLine, drive: insertSecretTwice,
|
||||||
|
},
|
||||||
|
{
|
||||||
|
name: "select", slow: neverSlow,
|
||||||
|
want: routineLine, drive: selectSecret,
|
||||||
|
},
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// TestBoundValues_NeverReachTheLog states the values-off property
|
||||||
|
// directly, on each arm of Trace that emits.
|
||||||
|
//
|
||||||
|
// Truncation is not what is being asserted. A bounded secret is still
|
||||||
|
// a secret: the session key is 44 base64 characters and an Argon2id
|
||||||
|
// hash under 100, so both fit inside every budget this package
|
||||||
|
// applies. What keeps them out is that the adapter logs the
|
||||||
|
// statement's shape and discards its parameters — see
|
||||||
|
// (*Logger).ParamsFilter — and that has to hold at DEBUG as much as on
|
||||||
|
// an error, because DEBUG is the level at which a successful INSERT is
|
||||||
|
// written at all.
|
||||||
|
//
|
||||||
|
// Each case also requires a placeholder in the logged statement.
|
||||||
|
// Without that, the absence of the value would be satisfied by a
|
||||||
|
// logger that wrote nothing useful.
|
||||||
|
func TestBoundValues_NeverReachTheLog(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
for _, tc := range boundValueCases() {
|
||||||
|
for _, h := range handlers() {
|
||||||
|
t.Run(tc.name+"/"+h.name, func(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
var buf bytes.Buffer
|
||||||
|
|
||||||
|
gdb := openDB(t, &buf, h.make(&buf), tc.slow)
|
||||||
|
|
||||||
|
tc.drive(t, gdb)
|
||||||
|
|
||||||
|
assertNoBoundValue(t, buf.String(), tc.want)
|
||||||
|
})
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// assertNoBoundValue holds one captured arm to the property: it wrote
|
||||||
|
// the line it was supposed to write, that line kept its placeholders,
|
||||||
|
// and it carried no bound value.
|
||||||
|
func assertNoBoundValue(t *testing.T, out, want string) {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
require.Contains(
|
||||||
|
t, out, want,
|
||||||
|
"the arm under test wrote nothing, so the assertions "+
|
||||||
|
"below are vacuous",
|
||||||
|
)
|
||||||
|
assert.NotContains(
|
||||||
|
t, out, secretValue,
|
||||||
|
"a bound parameter was rendered into the log",
|
||||||
|
)
|
||||||
|
assert.Contains(
|
||||||
|
t, out, "?",
|
||||||
|
"the statement was logged without its placeholders",
|
||||||
|
)
|
||||||
|
}
|
||||||
|
|
||||||
|
// TestInsert_KeepsOnePlaceholderPerBoundValue pins the shape of the
|
||||||
|
// INSERT specifically, since that is the statement that carries both
|
||||||
|
// first-boot secrets. A statement that dropped one value and kept the
|
||||||
|
// other would satisfy the assertions above.
|
||||||
|
func TestInsert_KeepsOnePlaceholderPerBoundValue(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
var buf bytes.Buffer
|
||||||
|
|
||||||
|
gdb := openDB(t, &buf, handlers()[0].make(&buf), neverSlow)
|
||||||
|
|
||||||
|
require.NoError(t, gdb.Create(&thing{
|
||||||
|
ID: "m", Name: secretValue,
|
||||||
|
}).Error)
|
||||||
|
|
||||||
|
out := buf.String()
|
||||||
|
|
||||||
|
require.Contains(t, out, "INSERT INTO")
|
||||||
|
assert.NotContains(t, out, secretValue)
|
||||||
|
|
||||||
|
for line := range strings.SplitSeq(out, "\n") {
|
||||||
|
if !strings.Contains(line, "INSERT INTO") {
|
||||||
|
continue
|
||||||
|
}
|
||||||
|
|
||||||
|
assert.GreaterOrEqual(
|
||||||
|
t, strings.Count(line, "?"), 2,
|
||||||
|
"insert logged fewer placeholders than it bound "+
|
||||||
|
"values: %s", line,
|
||||||
|
)
|
||||||
|
}
|
||||||
|
}
|
||||||
@@ -43,10 +43,7 @@ func (s *Server) serveUntilShutdown() {
|
|||||||
err := s.httpServer.ListenAndServe()
|
err := s.httpServer.ListenAndServe()
|
||||||
if err != nil && !errors.Is(err, http.ErrServerClosed) {
|
if err != nil && !errors.Is(err, http.ErrServerClosed) {
|
||||||
s.log.Error("listen error", "error", err)
|
s.log.Error("listen error", "error", err)
|
||||||
|
s.shutdownOnListenFailure()
|
||||||
if s.cancelFunc != nil {
|
|
||||||
s.cancelFunc()
|
|
||||||
}
|
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
|||||||
95
internal/server/listen_failure_test.go
Normal file
95
internal/server/listen_failure_test.go
Normal file
@@ -0,0 +1,95 @@
|
|||||||
|
package server_test
|
||||||
|
|
||||||
|
import (
|
||||||
|
"context"
|
||||||
|
"net"
|
||||||
|
"testing"
|
||||||
|
"time"
|
||||||
|
|
||||||
|
"github.com/stretchr/testify/require"
|
||||||
|
"go.uber.org/fx"
|
||||||
|
"sneak.berlin/go/webhooker/internal/globals"
|
||||||
|
"sneak.berlin/go/webhooker/internal/server"
|
||||||
|
)
|
||||||
|
|
||||||
|
// listenFailureDeadline is how long the app gets to give up after a
|
||||||
|
// listen it cannot satisfy. The defect this pins left the process
|
||||||
|
// reporting RUNNING for 183 seconds with nothing bound; a bind error
|
||||||
|
// is known instantly, so anything past a moment here is that defect
|
||||||
|
// back.
|
||||||
|
const listenFailureDeadline = 2 * time.Second
|
||||||
|
|
||||||
|
// lifecycleTimeout bounds the app's start and stop sequences so a
|
||||||
|
// wedged hook fails the test instead of hanging it.
|
||||||
|
const lifecycleTimeout = 15 * time.Second
|
||||||
|
|
||||||
|
// TestListenFailure_ShutsDownTheApp pins that a listener the server
|
||||||
|
// cannot bind terminates the application with a non-zero status.
|
||||||
|
//
|
||||||
|
// The fx OnStart hook returns as soon as the serving goroutine is
|
||||||
|
// spawned, so a bind failure is discovered after fx has already
|
||||||
|
// reported RUNNING. Nothing else in the graph observes it, and the
|
||||||
|
// process used to stay alive with no listener: down, but indis-
|
||||||
|
// tinguishable from healthy to systemd's Restart=on-failure and to
|
||||||
|
// Docker's restart policies, which is the state this test exists to
|
||||||
|
// keep from returning.
|
||||||
|
//
|
||||||
|
// The port is occupied by a listener this test holds open, on a
|
||||||
|
// kernel-chosen port, so the failure is the real EADDRINUSE the
|
||||||
|
// operator hits when a second instance starts. Loopback is enough to
|
||||||
|
// collide with the server's wildcard bind: a listening socket on a
|
||||||
|
// specific address blocks the wildcard from claiming the same port.
|
||||||
|
func TestListenFailure_ShutsDownTheApp(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
var listenCfg net.ListenConfig
|
||||||
|
|
||||||
|
occupied, err := listenCfg.Listen(
|
||||||
|
t.Context(), "tcp", "127.0.0.1:0",
|
||||||
|
)
|
||||||
|
require.NoError(t, err)
|
||||||
|
|
||||||
|
t.Cleanup(func() { _ = occupied.Close() })
|
||||||
|
|
||||||
|
addr, ok := occupied.Addr().(*net.TCPAddr)
|
||||||
|
require.True(t, ok, "listener is not TCP")
|
||||||
|
|
||||||
|
// The collaborators come from the wired graph rather than stubs,
|
||||||
|
// so the Server under test is the one that ships. Only the port
|
||||||
|
// is test-specific.
|
||||||
|
env := newTestEnv(t)
|
||||||
|
env.cfg.Port = addr.Port
|
||||||
|
|
||||||
|
app := fx.New(
|
||||||
|
fx.NopLogger,
|
||||||
|
fx.Supply(env.log, env.cfg, env.mw, env.hnd),
|
||||||
|
fx.Provide(globals.New, server.New),
|
||||||
|
fx.Invoke(func(*server.Server) {}),
|
||||||
|
)
|
||||||
|
|
||||||
|
startCtx, cancelStart := context.WithTimeout(
|
||||||
|
context.Background(), lifecycleTimeout,
|
||||||
|
)
|
||||||
|
defer cancelStart()
|
||||||
|
|
||||||
|
require.NoError(t, app.Start(startCtx))
|
||||||
|
|
||||||
|
select {
|
||||||
|
case sig := <-app.Wait():
|
||||||
|
require.Equal(
|
||||||
|
t, server.ListenFailureExitCode, sig.ExitCode,
|
||||||
|
"listen failure must exit non-zero",
|
||||||
|
)
|
||||||
|
case <-time.After(listenFailureDeadline):
|
||||||
|
t.Fatal("listen failure left the app running")
|
||||||
|
}
|
||||||
|
|
||||||
|
// The stop sequence still has to complete: the fix must reach
|
||||||
|
// shutdown through fx rather than around it.
|
||||||
|
stopCtx, cancelStop := context.WithTimeout(
|
||||||
|
context.Background(), lifecycleTimeout,
|
||||||
|
)
|
||||||
|
defer cancelStop()
|
||||||
|
|
||||||
|
require.NoError(t, app.Stop(stopCtx))
|
||||||
|
}
|
||||||
@@ -55,8 +55,11 @@ func (s *Server) setupGlobalMiddleware() {
|
|||||||
s.router.Use(s.mw.SecurityHeaders())
|
s.router.Use(s.mw.SecurityHeaders())
|
||||||
s.router.Use(s.mw.Logging())
|
s.router.Use(s.mw.Logging())
|
||||||
|
|
||||||
// Metrics middleware (only if credentials are configured)
|
// Metrics recording middleware, registered only when the
|
||||||
if s.params.Config.MetricsUsername != "" {
|
// endpoint that exposes what it records is served. The
|
||||||
|
// condition is the same MetricsAuthEnabled the /metrics mount
|
||||||
|
// in setupRoutes reads.
|
||||||
|
if s.params.Config.MetricsAuthEnabled() {
|
||||||
s.router.Use(s.mw.Metrics())
|
s.router.Use(s.mw.Metrics())
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -103,8 +106,14 @@ func (s *Server) setupRoutes() {
|
|||||||
s.h.HandleHealthCheck(),
|
s.h.HandleHealthCheck(),
|
||||||
)
|
)
|
||||||
|
|
||||||
// set up authenticated /metrics route:
|
// Authenticated /metrics route. The condition is
|
||||||
if s.params.Config.MetricsUsername != "" {
|
// Config.MetricsAuthEnabled and never the username alone: a
|
||||||
|
// username with an empty password would otherwise mount the
|
||||||
|
// endpoint behind a credential map that accepts an empty
|
||||||
|
// password. Config rejects that combination at startup, and
|
||||||
|
// this reads the same value the startup log reports, so the
|
||||||
|
// two cannot disagree about whether the route exists.
|
||||||
|
if s.params.Config.MetricsAuthEnabled() {
|
||||||
s.router.Group(func(r chi.Router) {
|
s.router.Group(func(r chi.Router) {
|
||||||
r.Use(s.mw.MetricsAuth())
|
r.Use(s.mw.MetricsAuth())
|
||||||
r.Get(
|
r.Get(
|
||||||
|
|||||||
@@ -34,6 +34,13 @@ import (
|
|||||||
// the CSRF middleware executed.
|
// the CSRF middleware executed.
|
||||||
const csrfCookieName = "_gorilla_csrf"
|
const csrfCookieName = "_gorilla_csrf"
|
||||||
|
|
||||||
|
const (
|
||||||
|
// metricsUser and metricsAuthValue are the /metrics basic-auth
|
||||||
|
// credentials the metrics routing tests below configure.
|
||||||
|
metricsUser = "metrics"
|
||||||
|
metricsAuthValue = "s3cret"
|
||||||
|
)
|
||||||
|
|
||||||
type noopNotifier struct{}
|
type noopNotifier struct{}
|
||||||
|
|
||||||
func (n *noopNotifier) Notify([]delivery.Task) {}
|
func (n *noopNotifier) Notify([]delivery.Task) {}
|
||||||
@@ -69,9 +76,23 @@ type testEnv struct {
|
|||||||
func newTestEnv(t *testing.T) *testEnv {
|
func newTestEnv(t *testing.T) *testEnv {
|
||||||
t.Helper()
|
t.Helper()
|
||||||
|
|
||||||
|
return newTestEnvWithConfig(t, &config.Config{
|
||||||
|
DataDir: t.TempDir(),
|
||||||
|
Environment: config.EnvironmentDev,
|
||||||
|
})
|
||||||
|
}
|
||||||
|
|
||||||
|
// newTestEnvWithConfig is newTestEnv over a caller-supplied Config,
|
||||||
|
// for the routes whose existence the configuration decides. The same
|
||||||
|
// pointer reaches the router and every middleware, so a test cannot
|
||||||
|
// accidentally configure one and not the other.
|
||||||
|
func newTestEnvWithConfig(
|
||||||
|
t *testing.T, cfg *config.Config,
|
||||||
|
) *testEnv {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
var (
|
var (
|
||||||
log *logger.Logger
|
log *logger.Logger
|
||||||
cfg *config.Config
|
|
||||||
mw *middleware.Middleware
|
mw *middleware.Middleware
|
||||||
hnd *handlers.Handlers
|
hnd *handlers.Handlers
|
||||||
sess *session.Session
|
sess *session.Session
|
||||||
@@ -84,12 +105,7 @@ func newTestEnv(t *testing.T) *testEnv {
|
|||||||
fx.Provide(
|
fx.Provide(
|
||||||
globals.New,
|
globals.New,
|
||||||
logger.New,
|
logger.New,
|
||||||
func() *config.Config {
|
func() *config.Config { return cfg },
|
||||||
return &config.Config{
|
|
||||||
DataDir: t.TempDir(),
|
|
||||||
Environment: config.EnvironmentDev,
|
|
||||||
}
|
|
||||||
},
|
|
||||||
database.New,
|
database.New,
|
||||||
database.NewWebhookDBManager,
|
database.NewWebhookDBManager,
|
||||||
healthcheck.New,
|
healthcheck.New,
|
||||||
@@ -99,7 +115,7 @@ func newTestEnv(t *testing.T) *testEnv {
|
|||||||
middleware.New,
|
middleware.New,
|
||||||
handlers.New,
|
handlers.New,
|
||||||
),
|
),
|
||||||
fx.Populate(&log, &cfg, &mw, &hnd, &sess, &db, &dbMgr),
|
fx.Populate(&log, &mw, &hnd, &sess, &db, &dbMgr),
|
||||||
)
|
)
|
||||||
app.RequireStart()
|
app.RequireStart()
|
||||||
t.Cleanup(app.RequireStop)
|
t.Cleanup(app.RequireStop)
|
||||||
@@ -657,3 +673,119 @@ func TestSourceLogsBody_OtherUser404s(t *testing.T) {
|
|||||||
assert.Equal(t, http.StatusSeeOther, anon.Code)
|
assert.Equal(t, http.StatusSeeOther, anon.Code)
|
||||||
assert.Equal(t, "/pages/login", anon.Header().Get("Location"))
|
assert.Equal(t, "/pages/login", anon.Header().Get("Location"))
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// metricsConfig is a Config differing from the routing default only
|
||||||
|
// in the two /metrics credentials.
|
||||||
|
func metricsConfig(
|
||||||
|
t *testing.T, username, password string,
|
||||||
|
) *config.Config {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
return &config.Config{
|
||||||
|
DataDir: t.TempDir(),
|
||||||
|
Environment: config.EnvironmentDev,
|
||||||
|
MetricsUsername: username,
|
||||||
|
MetricsPassword: password,
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// metricsRequest asks the real router for /metrics with the given
|
||||||
|
// basic-auth credentials, or with no Authorization header when
|
||||||
|
// username is empty.
|
||||||
|
func (e *testEnv) metricsRequest(
|
||||||
|
username, password string,
|
||||||
|
) *httptest.ResponseRecorder {
|
||||||
|
req := httptest.NewRequestWithContext(
|
||||||
|
context.Background(), http.MethodGet, "/metrics", nil,
|
||||||
|
)
|
||||||
|
|
||||||
|
if username != "" {
|
||||||
|
req.SetBasicAuth(username, password)
|
||||||
|
}
|
||||||
|
|
||||||
|
w := httptest.NewRecorder()
|
||||||
|
e.router.ServeHTTP(w, req)
|
||||||
|
|
||||||
|
return w
|
||||||
|
}
|
||||||
|
|
||||||
|
// TestMetricsRouteUnmountedWithoutCredentials pins that with neither
|
||||||
|
// credential configured the route does not exist, which is the
|
||||||
|
// documented behaviour and the only valid way for /metrics to be
|
||||||
|
// absent.
|
||||||
|
func TestMetricsRouteUnmountedWithoutCredentials(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
env := newTestEnvWithConfig(t, metricsConfig(t, "", ""))
|
||||||
|
|
||||||
|
assert.Equal(
|
||||||
|
t, http.StatusNotFound,
|
||||||
|
env.metricsRequest("", "").Code,
|
||||||
|
)
|
||||||
|
}
|
||||||
|
|
||||||
|
// TestMetricsRouteRequiresCredentials pins that with both credentials
|
||||||
|
// configured the route exists and every request that does not carry
|
||||||
|
// the configured pair is refused — including the empty password that
|
||||||
|
// a half-set configuration used to make sufficient.
|
||||||
|
func TestMetricsRouteRequiresCredentials(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
env := newTestEnvWithConfig(
|
||||||
|
t, metricsConfig(t, metricsUser, metricsAuthValue),
|
||||||
|
)
|
||||||
|
|
||||||
|
assert.Equal(
|
||||||
|
t, http.StatusUnauthorized,
|
||||||
|
env.metricsRequest("", "").Code,
|
||||||
|
"no credentials must not reach the metrics handler",
|
||||||
|
)
|
||||||
|
assert.Equal(
|
||||||
|
t, http.StatusUnauthorized,
|
||||||
|
env.metricsRequest(metricsUser, "").Code,
|
||||||
|
"an empty password must not reach the metrics handler",
|
||||||
|
)
|
||||||
|
assert.Equal(
|
||||||
|
t, http.StatusUnauthorized,
|
||||||
|
env.metricsRequest(metricsUser, "wrong").Code,
|
||||||
|
)
|
||||||
|
|
||||||
|
ok := env.metricsRequest(metricsUser, metricsAuthValue)
|
||||||
|
assert.Equal(t, http.StatusOK, ok.Code)
|
||||||
|
assert.Contains(t, ok.Body.String(), "go_goroutines")
|
||||||
|
}
|
||||||
|
|
||||||
|
// TestMetricsRouteUnmountedOnHalfSetConfig pins the defect from
|
||||||
|
// https://git.eeqj.de/sneak/webhooker/issues/205 at the routing
|
||||||
|
// layer. Config rejects a half-set pair at startup, so this Config
|
||||||
|
// cannot be reached from the environment; the assertion is that the
|
||||||
|
// route tree does not publish an endpoint accepting an empty
|
||||||
|
// password even when handed one anyway, because the mount and the
|
||||||
|
// startup log's hasMetricsAuth read the same value.
|
||||||
|
func TestMetricsRouteUnmountedOnHalfSetConfig(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
for _, tc := range []struct {
|
||||||
|
name string
|
||||||
|
username string
|
||||||
|
password string
|
||||||
|
}{
|
||||||
|
{name: "username only", username: metricsUser},
|
||||||
|
{name: "password only", password: metricsAuthValue},
|
||||||
|
} {
|
||||||
|
t.Run(tc.name, func(t *testing.T) {
|
||||||
|
t.Parallel()
|
||||||
|
|
||||||
|
cfg := metricsConfig(t, tc.username, tc.password)
|
||||||
|
env := newTestEnvWithConfig(t, cfg)
|
||||||
|
|
||||||
|
assert.False(t, cfg.MetricsAuthEnabled())
|
||||||
|
assert.Equal(
|
||||||
|
t, http.StatusNotFound,
|
||||||
|
env.metricsRequest(
|
||||||
|
tc.username, tc.password,
|
||||||
|
).Code,
|
||||||
|
)
|
||||||
|
})
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|||||||
@@ -50,6 +50,13 @@ const (
|
|||||||
minSentryFlush = 250 * time.Millisecond
|
minSentryFlush = 250 * time.Millisecond
|
||||||
)
|
)
|
||||||
|
|
||||||
|
// ListenFailureExitCode is the status the process exits with when the
|
||||||
|
// HTTP listener cannot be established, or dies for a reason other
|
||||||
|
// than a requested shutdown. It must stay non-zero: systemd
|
||||||
|
// `Restart=on-failure` and Docker's restart policies key off it, and a
|
||||||
|
// zero exit would read as a deliberate stop.
|
||||||
|
const ListenFailureExitCode = 1
|
||||||
|
|
||||||
// SentryFlushBudget reports how long the Sentry flush may run when
|
// SentryFlushBudget reports how long the Sentry flush may run when
|
||||||
// remaining is the time left on the fx stop context after the HTTP
|
// remaining is the time left on the fx stop context after the HTTP
|
||||||
// drain. sentry.Flush takes a bare duration and honours no context,
|
// drain. sentry.Flush takes a bare duration and honours no context,
|
||||||
@@ -75,13 +82,13 @@ type ServerParams struct {
|
|||||||
Config *config.Config
|
Config *config.Config
|
||||||
Middleware *middleware.Middleware
|
Middleware *middleware.Middleware
|
||||||
Handlers *handlers.Handlers
|
Handlers *handlers.Handlers
|
||||||
|
Shutdowner fx.Shutdowner
|
||||||
}
|
}
|
||||||
|
|
||||||
// Server is the main HTTP server that wires up routes and manages
|
// Server is the main HTTP server that wires up routes and manages
|
||||||
// graceful shutdown.
|
// graceful shutdown.
|
||||||
type Server struct {
|
type Server struct {
|
||||||
startupTime time.Time
|
startupTime time.Time
|
||||||
exitCode int
|
|
||||||
sentryEnabled bool
|
sentryEnabled bool
|
||||||
log *slog.Logger
|
log *slog.Logger
|
||||||
cancelFunc context.CancelFunc
|
cancelFunc context.CancelFunc
|
||||||
@@ -159,7 +166,12 @@ func (s *Server) enableSentry() {
|
|||||||
s.sentryEnabled = true
|
s.sentryEnabled = true
|
||||||
}
|
}
|
||||||
|
|
||||||
func (s *Server) serve() int {
|
// serve installs the signal watcher, starts the listener and blocks
|
||||||
|
// until the server's context is cancelled. The process exit status is
|
||||||
|
// fx's to decide — from a signal, or from the code
|
||||||
|
// shutdownOnListenFailure hands the Shutdowner — so this reports
|
||||||
|
// nothing back to its caller.
|
||||||
|
func (s *Server) serve() {
|
||||||
ctx, cancelFunc := context.WithCancel(context.Background())
|
ctx, cancelFunc := context.WithCancel(context.Background())
|
||||||
s.cancelFunc = cancelFunc
|
s.cancelFunc = cancelFunc
|
||||||
|
|
||||||
@@ -185,7 +197,30 @@ func (s *Server) serve() int {
|
|||||||
<-ctx.Done()
|
<-ctx.Done()
|
||||||
// Shutdown is handled by the fx OnStop hook (cleanShutdown).
|
// Shutdown is handled by the fx OnStop hook (cleanShutdown).
|
||||||
// Do not call cleanShutdown() here to avoid double invocation.
|
// Do not call cleanShutdown() here to avoid double invocation.
|
||||||
return s.exitCode
|
}
|
||||||
|
|
||||||
|
// shutdownOnListenFailure ends the application after the HTTP
|
||||||
|
// listener failed. The fx OnStart hook returns as soon as the serving
|
||||||
|
// goroutine is spawned, so nothing downstream of it ever learns that
|
||||||
|
// the listen failed: fx reports RUNNING and the process sits alive
|
||||||
|
// with nothing bound, which is invisible to systemd and Docker
|
||||||
|
// restart policies. Asking the Shutdowner to stop the app with a
|
||||||
|
// non-zero code is what turns that into a visible failure.
|
||||||
|
//
|
||||||
|
// The context cancel that follows only unwinds serve()'s own wait.
|
||||||
|
// The shutdown itself runs through fx's normal stop sequence, so the
|
||||||
|
// clean-shutdown drain in cleanShutdown is reached unchanged.
|
||||||
|
func (s *Server) shutdownOnListenFailure() {
|
||||||
|
err := s.params.Shutdowner.Shutdown(
|
||||||
|
fx.ExitCode(ListenFailureExitCode),
|
||||||
|
)
|
||||||
|
if err != nil {
|
||||||
|
s.log.Error("shutdown request failed", "error", err)
|
||||||
|
}
|
||||||
|
|
||||||
|
if s.cancelFunc != nil {
|
||||||
|
s.cancelFunc()
|
||||||
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
func (s *Server) cleanupForExit() {
|
func (s *Server) cleanupForExit() {
|
||||||
@@ -193,9 +228,6 @@ func (s *Server) cleanupForExit() {
|
|||||||
}
|
}
|
||||||
|
|
||||||
func (s *Server) cleanShutdown(ctx context.Context) {
|
func (s *Server) cleanShutdown(ctx context.Context) {
|
||||||
// initiate clean shutdown
|
|
||||||
s.exitCode = 0
|
|
||||||
|
|
||||||
ctxShutdown, shutdownCancel := context.WithTimeout(
|
ctxShutdown, shutdownCancel := context.WithTimeout(
|
||||||
ctx, ShutdownTimeout,
|
ctx, ShutdownTimeout,
|
||||||
)
|
)
|
||||||
|
|||||||
Reference in New Issue
Block a user