4 Commits
Author SHA1 Message Date
sneak 0fb647e8be Unset TRUSTED_PROXIES trusts RFC 1918, empty trusts none (closes #129)
check / check (push) Canceled after 0s
The backend's own TRUSTED_PROXIES now follows the ruling for every app:
unset, it trusts 10.0.0.0/8, 172.16.0.0/12 and 192.168.0.0/16, and no
longer loopback; a list replaces that; set and empty, it trusts no
proxy.

viper reads an empty environment variable as unset, so an empty value
got the default. config.New now reads this one setting with
os.LookupEnv first. viper's AllowEmptyEnv would apply to every setting,
so an empty PORT or DEBUG would stop the start instead of counting as
unset, as README.md says it does.

bin/entrypoint.sh still starts the backend with
TRUSTED_PROXIES=127.0.0.1/32.

Model: opus-5-5
2026-10-14 11:48:30 +00:00
clawbot cff7b07bbc Reports refused while report files cannot be written (closes #123)
check / check (push) Canceled after 0s
A failed write of a report file used to drop its reports, and
POST /api/v1/reports kept answering 200 for as long as writes failed.
Now a failed write puts its reports back in the buffer, still counted
against DATA_DIR_MAX_BYTES, and Append refuses every report, which the
handler answers 500, until a write succeeds. The minute flush tries
the held reports again, so storing resumes with no restart once
writing works, and the buffer takes nothing new while writes fail.
Tests also cover a report appended while a write that fails runs, and
the cap once a failed write's reports are written.

Model: opus-5-5
2026-10-14 13:47:14 +02:00
clawbot e628dfe6cf A handler's panic is logged and counted as 500 (closes #125)
check / check (push) Canceled after 0s
Recoverer comes first, so it wrote the 500 only after the panic had
passed the request log and the metrics, which both recorded 200.
Write500OnPanic, placed after the request log and after the metrics,
writes the 500 as the panic passes and panics again, so Sentry and
Recoverer still get it. Recoverer now writes its 500 only when no
status was written, so the server logs no superfluous WriteHeader call.
The test also requires Recoverer's log line for the handler's panic, so
it fails if Write500OnPanic stops passing the panic on.

Model: opus-5-5
2026-10-14 13:30:11 +02:00
clawbot cbcde098dc Unset TRUSTED_PROXIES trusts the RFC 1918 ranges (closes #119)
check / check (push) Canceled after 0s
With TRUSTED_PROXIES unset, bin/entrypoint.sh gives nginx one
set_real_ip_from line for each of 10.0.0.0/8, 172.16.0.0/12 and
192.168.0.0/16, as sneak ruled on 2026-09-22 for every app. A list
replaces them, and set and empty trusts no proxy; each entry is checked
as before. The backend inside the container still trusts only
127.0.0.1/32. README.md, configs/nginx.conf and the comment in
script/frontend-viewport-test say the new default.

Model: opus-5-5
2026-10-14 13:01:34 +02:00
13 changed files with 629 additions and 74 deletions
+46 -34
View File
@@ -199,23 +199,25 @@ image, `make run` builds it and runs it on port 8080.
| `DATA_DIR` | `./data/reports` | Directory for compressed reports |
| `DATA_DIR_MAX_BYTES` | `1073741824` (1 GiB) | Most bytes of report files kept in `DATA_DIR`, oldest deleted first; see [Report limits](#report-limits) |
| `DEBUG` | `false` | Enable debug logging |
| `TRUSTED_PROXIES` | loopback + RFC1918 | Comma-separated CIDRs whose `X-Forwarded-For` / `X-Real-IP` headers are trusted for client IP resolution |
| `TRUSTED_PROXIES` | RFC 1918 ranges | Comma-separated CIDRs whose `X-Forwarded-For` / `X-Real-IP` headers are trusted for client IP resolution |
| `REPORTS_PER_MINUTE` | `60` | Reports each client address may send a minute; see [Report limits](#report-limits) |
| `CORS_ALLOWED_ORIGINS` | empty | Comma-separated origins whose pages may call the API; see [CORS](#cors) |
| `METRICS_USERNAME` | empty | Basic auth user name for `/metrics`; see [Metrics](#metrics) |
| `METRICS_PASSWORD` | empty | Basic auth password for `/metrics`; see [Metrics](#metrics) |
| `SENTRY_DSN` | empty | DSN of the Sentry project to send errors to; see [Sentry](#sentry) |
`TRUSTED_PROXIES` defaults to
`127.0.0.1/32,::1/128,10.0.0.0/8,172.16.0.0/12,192.168.0.0/16`. The loopback
entries cover a reverse proxy on the same host. A request whose direct peer is
outside this set has its forwarded headers ignored, and the direct peer is
logged and rate-limited instead. The container image does not use this default;
see [Deployment](#deployment).
`TRUSTED_PROXIES` defaults to `10.0.0.0/8,172.16.0.0/12,192.168.0.0/16`. A list
replaces the default; set and empty, the server trusts no proxy. Loopback is not
in the default, so a reverse proxy on the same host has to be named, as in
`TRUSTED_PROXIES=127.0.0.1/32`. A request whose direct peer is outside this set
has its forwarded headers ignored, and the direct peer is logged and
rate-limited instead. The container image does not use this default; see
[Deployment](#deployment).
A variable set to a value the server cannot use, such as `PORT=abc`,
`DEBUG=maybe` or a `BIND_ADDRESS` that is not an IP address, stops it from
starting, with an error naming the variable. An empty variable counts as unset.
starting, with an error naming the variable. An empty variable counts as unset,
except `TRUSTED_PROXIES`.
#### Report storage
@@ -228,6 +230,14 @@ the numbers: its file, if it was created, is removed. The file stays, counted
toward `DATA_DIR_MAX_BYTES` from the next start, only if removing it fails too.
Files are created with `O_EXCL` to prevent overwrites.
The reports of a failed write stay in memory, and the next flush, within a
minute, tries again to write them. From the failed write until a write succeeds,
`POST /api/v1/reports` refuses every report with 500 and keeps nothing of it, so
the page keeps its samples and sends them again at its next report. Reports
already answered 200 are lost only if the server stops before a write succeeds;
the final flush at stop tries them too, and if it fails, the process exits
non-zero.
#### Report limits
`POST /api/v1/reports` takes reports from anyone who can reach it, without
@@ -252,16 +262,16 @@ credentials, so it is bounded instead. Each refusal below answers with the same
`X-RateLimit-Reset` headers.
- **Size cap.** The report files in `DATA_DIR` may total at most
`DATA_DIR_MAX_BYTES`, counting the files already there at start. Reports
waiting in memory count at their uncompressed size until they are written;
those lost to a failed write stop counting, and the part of its file written
is removed. When a report would take the total past the cap, the oldest report
files are deleted to make room, and each deletion is logged with the file's
name and size; a file still being written is never deleted. A report is
refused with 507, and nothing of it is stored, only when the reports waiting
to be written fill the cap on their own, and then no file is deleted. At
start, report files past the cap, as after lowering it, are deleted the same
way. So the cap is how much of the newest reports is kept: the default of 1
GiB is small enough for any host; set it to the space you can give `DATA_DIR`.
waiting in memory count at their uncompressed size until they are written,
those of a failed write included; the part of its file written is removed.
When a report would take the total past the cap, the oldest report files are
deleted to make room, and each deletion is logged with the file's name and
size; a file still being written is never deleted. A report is refused with
507, and nothing of it is stored, only when the reports waiting to be written
fill the cap on their own, and then no file is deleted. At start, report files
past the cap, as after lowering it, are deleted the same way. So the cap is
how much of the newest reports is kept: the default of 1 GiB is small enough
for any host; set it to the space you can give `DATA_DIR`.
#### CORS
@@ -412,9 +422,10 @@ address nginx passes on and no other. The image:
- Listens on port 8080 by default (override with `PORT` env var)
- Takes the client address from `X-Forwarded-For` only on requests from the
reverse proxies named in `TRUSTED_PROXIES`, and by default from none.
`bin/entrypoint.sh` checks each entry with `netwatch-server check-cidr`, which
parses it as the backend parses its own `TRUSTED_PROXIES`
reverse proxies named in `TRUSTED_PROXIES`, by default from any address in
`10.0.0.0/8`, `172.16.0.0/12` or `192.168.0.0/16`. `bin/entrypoint.sh` checks
each entry with `netwatch-server check-cidr`, which parses it as the backend
parses its own `TRUSTED_PROXIES`
- Sends access logs to stdout
- Caches static assets with immutable headers
- Sends the security headers `REPO_POLICIES.md` requires on every response, as
@@ -433,9 +444,9 @@ What the [upaas](https://git.eeqj.de/sneak/upaas) app for netwatch needs:
- **Port:** container port `8080`.
- **Volume:** container path `/data`; the reports are kept in `/data/reports`.
- **Environment variables:** none is required. An empty one counts as unset, and
one set to a value netwatch cannot use stops the container at start, with the
reason in its log.
- **Environment variables:** none is required. An empty one counts as unset,
except `TRUSTED_PROXIES`, and one set to a value netwatch cannot use stops the
container at start, with the reason in its log.
- `PORT`, default `8080`: the container port, from 1 to 65535. `8081` cannot
be used: the backend listens on it inside the container
- `REPORTS_PER_MINUTE`, default `60`: reports each client address may send a
@@ -449,16 +460,17 @@ What the [upaas](https://git.eeqj.de/sneak/upaas) app for netwatch needs:
in: `/data` or a path below it, with no `.` or `..` part and no extra `/`.
The container also stops if the path goes through a symbolic link that
leads out of `/data` or is written as a full path
- `TRUSTED_PROXIES`, default empty: set it to the address the reverse proxy
in front of the container connects from, as an IP address or CIDR; several
are separated by commas. nginx takes the client address from
`X-Forwarded-For` only on a request from one of them, and the rate limit
counts that address. Unset, `X-Forwarded-For` is ignored and every client
behind the proxy shares the proxy's one allowance of `REPORTS_PER_MINUTE`.
Name only addresses nothing but the proxy connects from: any client that
connects from one can write its own `X-Forwarded-For`, and through a port
Docker publishes, every client may connect from the Docker network's
gateway, such as `172.17.0.1`.
- `TRUSTED_PROXIES`, default `10.0.0.0/8,172.16.0.0/12,192.168.0.0/16`: the
addresses the reverse proxy in front of the container connects from, as IP
addresses or CIDRs separated by commas. nginx takes the client address
from `X-Forwarded-For` only on a request from one of them, and the rate
limit counts that address. A list replaces the default. Set and empty,
`X-Forwarded-For` is ignored and every client behind the proxy shares the
proxy's one allowance of `REPORTS_PER_MINUTE`. Any client that connects
from one of these addresses can write its own `X-Forwarded-For`, and
through a port Docker publishes, every client may connect from the Docker
network's gateway, such as `172.17.0.1`, which the default includes; where
that matters, name only the addresses nothing but the proxy connects from.
- `METRICS_USERNAME` and `METRICS_PASSWORD`, default empty: with both set,
the backend records Prometheus metrics of its requests and serves them at
`/metrics` on the container port, to requests with this user name and
+31
View File
@@ -21,6 +21,37 @@ Run `make frontend-viewport-test` in CI as its own step; it is not part of
# Completed Steps
- 2026-10-14: unset, the backend's own `TRUSTED_PROXIES` trusts `10.0.0.0/8`,
`172.16.0.0/12` and `192.168.0.0/16`, and no longer loopback; a list replaces
that; set and empty, it trusts no proxy, where it used to get the default, as
viper reads an empty environment variable as unset
([#129](https://git.eeqj.de/sneak/netwatch/issues/129)). A value it cannot
parse still stops the start, and the image still starts the backend with
`TRUSTED_PROXIES=127.0.0.1/32`. Tests load the config with it unset, empty and
set to a list
- 2026-10-14: while report files cannot be written, `POST /api/v1/reports`
answers 500, and storing recovers once writing works again, with no restart
([#123](https://git.eeqj.de/sneak/netwatch/issues/123)). A failed write puts
its reports back in the report buffer, still counted against
`DATA_DIR_MAX_BYTES`, where they used to be lost; the next flush, within a
minute, tries them again. Until a write succeeds, every report is refused and
nothing of it is kept, so the buffer does not grow while writes fail. A test
posts reports through the report handler before, during and after a failure;
others check that a report appended while a write runs is kept, behind that
write's own, when the write fails, and that the cap still holds exactly once a
failed write's reports are written
- 2026-10-14: a request whose handler panics is logged with status 500 and
counted with `code` 500 in the metrics
([#125](https://git.eeqj.de/sneak/netwatch/issues/125)), not 200. `Recoverer`
is still the first middleware; `Write500OnPanic`, after the request log and
after the metrics, writes the 500 as the panic passes and lets it go on to
Sentry and `Recoverer`, which now writes a 500 only when no status was written
- 2026-10-14: with `TRUSTED_PROXIES` unset, the container's nginx trusts the
three private ranges of RFC 1918, `10.0.0.0/8`, `172.16.0.0/12` and
`192.168.0.0/16` ([#119](https://git.eeqj.de/sneak/netwatch/issues/119)), as
sneak ruled on 2026-09-22 for every app; it trusted no proxy before. A list
replaces them, and set and empty it trusts none. The backend inside the
container still trusts only `127.0.0.1/32`
- 2026-10-14: `POST /api/v1/reports` takes only a report sent with
`Content-Type: application/json`, parameters such as `charset` allowed, and
refuses any other with 415 and the usual error body, storing nothing
+6 -4
View File
@@ -34,9 +34,11 @@ fi
# TRUSTED_PROXIES names the reverse proxies in front of the container,
# as IP addresses or CIDRs separated by commas. nginx takes the client
# address from X-Forwarded-For only on a request from one of them, so
# unset or empty, it trusts no one. configs/nginx.conf includes the file
# written here, one set_real_ip_from line per entry.
# address from X-Forwarded-For only on a request from one of them.
# Unset, they are the three private ranges of RFC 1918; set and empty,
# nginx trusts no one, which is why the default below follows - and not
# :-. configs/nginx.conf includes the file written here, one
# set_real_ip_from line per entry.
#
# nginx looks up an entry it cannot read as an address as a hostname,
# and trusts what it finds (1.2.3 is found as 1.2.0.3). So each entry
@@ -45,7 +47,7 @@ fi
# TRUSTED_PROXIES. Its error, naming the CIDR, is dropped for the one
# below, naming the entry as written. set -f keeps a * in an entry from
# becoming a list of file names.
TRUSTED_PROXIES="${TRUSTED_PROXIES:-}"
TRUSTED_PROXIES="${TRUSTED_PROXIES-10.0.0.0/8,172.16.0.0/12,192.168.0.0/16}"
set -f
for proxy in $(printf '%s' "$TRUSTED_PROXIES" | tr ',' ' '); do
case "$proxy" in
+4 -3
View File
@@ -18,9 +18,10 @@ server {
# The client address comes from X-Forwarded-For only on a request
# from the reverse proxies in TRUSTED_PROXIES: bin/entrypoint.sh
# writes one set_real_ip_from line for each into this file, and
# leaves it empty when TRUSTED_PROXIES is unset, so that by default
# the client address is the one each request comes from.
# writes one set_real_ip_from line for each into this file. Unset,
# TRUSTED_PROXIES is the three private ranges of RFC 1918; set and
# empty, the file is empty and the client address is the one each
# request comes from.
include /etc/nginx/trusted-proxies.conf;
real_ip_header X-Forwarded-For;
real_ip_recursive on;
+13 -6
View File
@@ -9,6 +9,7 @@ import (
"math"
"net/netip"
"net/url"
"os"
"strconv"
"strings"
@@ -21,13 +22,11 @@ import (
)
// defaultTrustedProxies lists the networks whose forwarded
// headers are honoured by default: IPv4 and IPv6 loopback,
// for a reverse proxy on the same host, and the RFC1918
// ranges. The container image does not use it:
// headers are honoured when TRUSTED_PROXIES is unset: the
// RFC 1918 ranges. The container image does not use it:
// bin/entrypoint.sh gives the server 127.0.0.1/32, since
// nginx is its only client there.
const defaultTrustedProxies = "127.0.0.1/32,::1/128," +
"10.0.0.0/8,172.16.0.0/12,192.168.0.0/16"
const defaultTrustedProxies = "10.0.0.0/8,172.16.0.0/12,192.168.0.0/16"
// Default limits on stored reports; README.md gives the reasons for
// these values.
@@ -135,6 +134,14 @@ func New(
viper.GetString("DEBUG"), errNotBool)
}
// An empty TRUSTED_PROXIES trusts no proxy, but viper reads an
// empty environment variable as unset and would give the default,
// so the environment is read first.
trustedProxies, set := os.LookupEnv("TRUSTED_PROXIES")
if !set {
trustedProxies = viper.GetString("TRUSTED_PROXIES")
}
s := &Config{
BindAddress: viper.GetString("BIND_ADDRESS"),
CORSAllowedOrigins: splitList(viper.GetString("CORS_ALLOWED_ORIGINS")),
@@ -146,7 +153,7 @@ func New(
Port: port,
ReportsPerMinute: viper.GetInt("REPORTS_PER_MINUTE"),
SentryDSN: viper.GetString("SENTRY_DSN"),
TrustedProxies: splitList(viper.GetString("TRUSTED_PROXIES")),
TrustedProxies: splitList(trustedProxies),
log: log,
params: &params,
}
+58
View File
@@ -1,6 +1,8 @@
package config_test
import (
"os"
"slices"
"strings"
"testing"
@@ -29,6 +31,62 @@ func requireConfigError(t *testing.T, setting string) {
}
}
// requireTrustedProxies builds the config as main does and fails the
// test unless its TrustedProxies are want.
func requireTrustedProxies(t *testing.T, want []string) {
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()
if err != nil {
t.Fatalf("config error = %v", err)
}
if !slices.Equal(cfg.TrustedProxies, want) {
t.Fatalf("TrustedProxies = %q, want %q", cfg.TrustedProxies, want)
}
}
// TestTrustedProxiesUnsetTrustsRFC1918: unset, the server trusts the
// RFC 1918 ranges and nothing else, loopback included.
func TestTrustedProxiesUnsetTrustsRFC1918(t *testing.T) {
// t.Setenv first, so the variable is put back as it was after the
// test.
t.Setenv("TRUSTED_PROXIES", "")
err := os.Unsetenv("TRUSTED_PROXIES")
if err != nil {
t.Fatal(err)
}
requireTrustedProxies(t,
[]string{"10.0.0.0/8", "172.16.0.0/12", "192.168.0.0/16"})
}
// TestTrustedProxiesEmptyTrustsNothing: set and empty, the server
// trusts no proxy. viper alone would read the empty variable as unset
// and give the default.
func TestTrustedProxiesEmptyTrustsNothing(t *testing.T) {
t.Setenv("TRUSTED_PROXIES", "")
requireTrustedProxies(t, []string{})
}
// TestTrustedProxiesListReplacesDefault: a list is used as given, with
// none of the default ranges added.
func TestTrustedProxiesListReplacesDefault(t *testing.T) {
t.Setenv("TRUSTED_PROXIES", "172.17.0.1/32, 2001:db8::/32")
requireTrustedProxies(t, []string{"172.17.0.1/32", "2001:db8::/32"})
}
// TestSettingsLoadAsGiven: valid values pass the checks and are used
// as given. bin/entrypoint.sh starts the server with these
// BIND_ADDRESS and PORT values.
+1 -1
View File
@@ -93,7 +93,7 @@ func (s *Handlers) decodeErrorStatus(err error) int {
// appendErrorStatus logs a failure to store a report and returns
// the status to send: 507 when the reports waiting to be written fill
// the size cap, otherwise 500.
// the size cap, otherwise 500, as when report files cannot be written.
func (s *Handlers) appendErrorStatus(err error) int {
if errors.Is(err, reportbuf.ErrFull) {
s.log.Warn("report refused: " +
+41 -4
View File
@@ -297,12 +297,16 @@ func (s *Middleware) MaxBodyBytes(
// Recoverer returns middleware that recovers from a panic in a
// downstream handler, logs the panic and stack trace through
// slog, and responds 500 with no body. http.ErrAbortHandler is
// re-panicked so the server can abort the response as intended.
// slog, and responds 500 with no body, unless a status was already
// written, as Write500OnPanic writes one for a handler's panic.
// http.ErrAbortHandler is re-panicked so the server can abort the
// response as intended.
func (s *Middleware) Recoverer() func(http.Handler) http.Handler {
return func(next http.Handler) http.Handler {
return http.HandlerFunc(
func(w http.ResponseWriter, r *http.Request) {
ww := middleware.NewWrapResponseWriter(w, r.ProtoMajor)
defer func() {
rec := recover()
if rec == nil {
@@ -320,10 +324,43 @@ func (s *Middleware) Recoverer() func(http.Handler) http.Handler {
"stack", string(debug.Stack()),
)
w.WriteHeader(http.StatusInternalServerError)
if ww.Status() == 0 {
ww.WriteHeader(http.StatusInternalServerError)
}
}()
next.ServeHTTP(w, r)
next.ServeHTTP(ww, r)
},
)
}
}
// Write500OnPanic returns middleware that writes 500 when a downstream
// handler panics before writing a status, and lets the panic go on to
// Sentry and Recoverer. Recoverer, which comes first, would write its
// 500 only after the request log and the metrics had recorded the
// status they saw; placed after each of them, this makes them record
// the 500.
func (s *Middleware) Write500OnPanic() func(http.Handler) http.Handler {
return func(next http.Handler) http.Handler {
return http.HandlerFunc(
func(w http.ResponseWriter, r *http.Request) {
ww := middleware.NewWrapResponseWriter(w, r.ProtoMajor)
defer func() {
rec := recover()
if rec == nil {
return
}
if ww.Status() == 0 {
ww.WriteHeader(http.StatusInternalServerError)
}
panic(rec)
}()
next.ServeHTTP(ww, r)
},
)
}
+169
View File
@@ -4,6 +4,7 @@ import (
"bytes"
"encoding/json"
"errors"
"log"
"log/slog"
"net/http"
"net/http/httptest"
@@ -16,7 +17,9 @@ import (
"sneak.berlin/go/netwatch/internal/logger"
"sneak.berlin/go/netwatch/internal/middleware"
"github.com/go-chi/chi/v5"
chimiddleware "github.com/go-chi/chi/v5/middleware"
"github.com/prometheus/client_golang/prometheus"
)
const (
@@ -323,6 +326,172 @@ func TestRecovererRepanicsOnAbortHandler(t *testing.T) {
}
}
// TestHandlerPanicIsLoggedAndCountedAs500 sends a request to a handler
// that panics through the middleware SetupRoutes puts around a route
// with metrics, in its order, leaving out those that write no status
// for a panic and Sentry, which TestSentry covers. The request log line
// and the metrics must give the 500 the client gets, and the panic must
// still reach Recoverer, which logs it.
func TestHandlerPanicIsLoggedAndCountedAs500(t *testing.T) {
t.Parallel()
var logbuf bytes.Buffer
mw := middleware.NewWithLogger(
slog.New(slog.NewJSONHandler(&logbuf, nil)),
)
registry := prometheus.NewRegistry()
handler := chi.Chain(
mw.Recoverer(),
chimiddleware.RequestID,
mw.Logging(),
mw.Write500OnPanic(),
mw.Metrics(registry),
mw.Write500OnPanic(),
).HandlerFunc(func(http.ResponseWriter, *http.Request) {
panic("boom")
})
rec := httptest.NewRecorder()
req := httptest.NewRequestWithContext(t.Context(), http.MethodGet, "/", http.NoBody)
handler.ServeHTTP(rec, req)
if rec.Code != http.StatusInternalServerError {
t.Fatalf("status = %d, want %d",
rec.Code, http.StatusInternalServerError)
}
request := findLogLine(t, logbuf.Bytes(), "request")
if request.Status != http.StatusInternalServerError {
t.Errorf("request log status = %d, want %d",
request.Status, http.StatusInternalServerError)
}
recovered := findLogLine(t, logbuf.Bytes(), "panic recovered")
if recovered.Panic != "boom" {
t.Errorf("panic recovered line has panic %q, want %q",
recovered.Panic, "boom")
}
for _, name := range []string{
"http_request_duration_seconds", "http_response_size_bytes",
} {
codes := metricCodes(t, registry, name)
if len(codes) != 1 || codes[0] != "500" {
t.Errorf("%s code labels = %v, want [500]", name, codes)
}
}
}
// loggedLine holds the fields the tests read from a JSON log line.
type loggedLine struct {
Msg string `json:"msg"`
Status int `json:"status"`
Panic string `json:"panic"`
}
// findLogLine returns the first of the JSON log lines in logged whose
// message is msg.
func findLogLine(t *testing.T, logged []byte, msg string) loggedLine {
t.Helper()
dec := json.NewDecoder(bytes.NewReader(logged))
for {
var line loggedLine
err := dec.Decode(&line)
if err != nil {
t.Fatalf("no %q line in the log: %v (%q)", msg, err, logged)
}
if line.Msg == msg {
return line
}
}
}
// metricCodes returns the code label of each series of the metric
// family name in registry.
func metricCodes(
t *testing.T,
registry *prometheus.Registry,
name string,
) []string {
t.Helper()
families, err := registry.Gather()
if err != nil {
t.Fatalf("gather metrics: %v", err)
}
var codes []string
for _, family := range families {
if family.GetName() != name {
continue
}
for _, metric := range family.GetMetric() {
for _, label := range metric.GetLabel() {
if label.GetName() == "code" {
codes = append(codes, label.GetValue())
}
}
}
}
return codes
}
// TestRecovererWritesNoSecondStatus checks, on a real server, that
// Recoverer does not write its 500 again after Write500OnPanic has
// written one, which the server would log as a superfluous
// WriteHeader call.
func TestRecovererWritesNoSecondStatus(t *testing.T) {
t.Parallel()
var serverLog bytes.Buffer
mw := middleware.NewWithLogger(slog.New(slog.DiscardHandler))
server := httptest.NewUnstartedServer(chi.Chain(
mw.Recoverer(),
mw.Write500OnPanic(),
).HandlerFunc(func(http.ResponseWriter, *http.Request) {
panic("boom")
}))
server.Config.ErrorLog = log.New(&serverLog, "", 0)
server.Start()
req, err := http.NewRequestWithContext(t.Context(),
http.MethodGet, server.URL, http.NoBody)
if err != nil {
t.Fatalf("new request: %v", err)
}
resp, err := server.Client().Do(req)
if err != nil {
t.Fatalf("request: %v", err)
}
_ = resp.Body.Close()
// Close waits for the handler to return, so whatever the server
// logs for this request is in serverLog after it.
server.Close()
if resp.StatusCode != http.StatusInternalServerError {
t.Errorf("status = %d, want %d",
resp.StatusCode, http.StatusInternalServerError)
}
if serverLog.Len() != 0 {
t.Errorf("server logged %q", serverLog.String())
}
}
// TestLoggingCutsRequestStringsToBound sends an over-long URL and
// over-long header values, and checks the request log writes each
// one cut to logger.MaxLoggedFieldBytes.
+33 -11
View File
@@ -91,6 +91,11 @@ type Buffer struct {
// of the report files in dataDir, plus the reports waiting to
// be written to one at their uncompressed size.
usedBytes int64
// writeErr is the error of the last write of a report file to
// finish, nil if it succeeded or none has. While it is set, Append
// refuses reports, and the reports of that write wait in buf for
// the next flush.
writeErr error
}
// New creates a Buffer and registers lifecycle hooks to
@@ -167,11 +172,12 @@ func New(
}
// Append marshals v as a single JSON line and appends it to
// the buffer. If the line would take usedBytes past maxBytes, the
// oldest report files are deleted to make room; it stores nothing
// and returns ErrFull if that cannot make room. If the buffer
// reaches the size threshold, it is drained and written to disk
// asynchronously.
// the buffer. It stores nothing and returns an error if the last
// write of a report file failed, until a write succeeds again. If the
// line would take usedBytes past maxBytes, the oldest report files are
// deleted to make room; it stores nothing and returns ErrFull if that
// cannot make room. If the buffer reaches the size threshold, it is
// drained and written to disk asynchronously.
func (b *Buffer) Append(v any) error {
line, err := json.Marshal(v)
if err != nil {
@@ -182,6 +188,13 @@ func (b *Buffer) Append(v any) error {
b.mu.Lock()
if b.writeErr != nil {
err = fmt.Errorf("report files cannot be written: %w", b.writeErr)
b.mu.Unlock()
return err
}
b.deleteOldestFiles(lineBytes)
if b.usedBytes+lineBytes > b.maxBytes {
@@ -291,7 +304,8 @@ func (b *Buffer) drainBuf() []byte {
}
// writeFile writes data, reports drained from the buffer, to a new
// timestamped zstd-compressed JSONL file in the data directory.
// timestamped zstd-compressed JSONL file in the data directory. If the
// write fails, it puts the reports back in the buffer.
func (b *Buffer) writeFile(data []byte) error {
// The timestamp comes first, so the names sort by time; the number
// after it tells apart files named in the same millisecond.
@@ -300,19 +314,27 @@ func (b *Buffer) writeFile(data []byte) error {
size, err := b.createFile(filepath.Join(b.dataDir, name), data)
// The reports no longer wait to be written, so they stop counting
// at their uncompressed size. If the write failed they are lost;
// otherwise they count as the file, which from here on may be
// deleted to make room.
b.mu.Lock()
defer b.mu.Unlock()
b.usedBytes -= int64(len(data))
b.writeErr = err
if err != nil {
// The reports go back in front of any appended since, for the
// next flush to write, and still count at their uncompressed
// size.
appended := bytes.Clone(b.buf.Bytes())
b.buf.Reset()
b.buf.Write(data)
b.buf.Write(appended)
return err
}
// The reports no longer wait to be written, so they stop counting
// at their uncompressed size and count as the file, which from here
// on may be deleted to make room.
b.usedBytes -= int64(len(data))
b.usedBytes += size
b.filesBytes += size
+218 -7
View File
@@ -5,6 +5,8 @@ import (
"errors"
"fmt"
"io/fs"
"net/http"
"net/http/httptest"
"os"
"path/filepath"
"slices"
@@ -17,6 +19,8 @@ import (
"sneak.berlin/go/netwatch/internal/config"
"sneak.berlin/go/netwatch/internal/globals"
"sneak.berlin/go/netwatch/internal/handlers"
"sneak.berlin/go/netwatch/internal/healthcheck"
"sneak.berlin/go/netwatch/internal/logger"
"sneak.berlin/go/netwatch/internal/reportbuf"
@@ -507,13 +511,17 @@ func TestFileBeingWrittenIsNeverDeleted(t *testing.T) {
}
}
// TestFailedWriteStopsCounting makes a write fail once its file is
// created. Its reports are lost, so they stop counting, and the part of
// the file written is removed, so it takes no room.
func TestFailedWriteStopsCounting(t *testing.T) {
report := map[string]string{"id": "failed"}
// TestFailedWriteKeepsItsReports makes a write fail once its file is
// created, under a cap with room for one report. The part of the file
// written is removed, so it takes no room, and the report waits in
// memory for the next flush, which writes it. Once written, it counts
// as its file and no longer as a report waiting, so the cap still holds
// exactly: one more report is taken and the one after it is refused.
func TestFailedWriteKeepsItsReports(t *testing.T) {
report := map[string]string{"id": "kept"}
dir := t.TempDir()
t.Setenv("DATA_DIR", t.TempDir())
t.Setenv("DATA_DIR", dir)
t.Setenv("DATA_DIR_MAX_BYTES", strconv.Itoa(lineBytes(t, report)))
buf := startBuffer(t)
@@ -544,10 +552,213 @@ func TestFailedWriteStopsCounting(t *testing.T) {
// Writes from here on, the final one at stop included, succeed.
buf.OnFileCreated(func(*os.File) {})
err = buf.Flush()
if err != nil {
t.Fatalf("flush after the failed write: %v", err)
}
files, err := readReportFiles(dir)
if err != nil {
t.Fatalf("read report files: %v", err)
}
want := `{"id":"kept"}` + "\n"
if len(files) != 1 || files[0] != want {
t.Fatalf("report files = %q, want one holding %q", files, want)
}
// The file is deleted to make room if need be.
err = buf.Append(report)
if err != nil {
t.Fatalf("report after the failed write: %v", err)
t.Fatalf("report after the written one: %v", err)
}
err = buf.Append(report)
if !errors.Is(err, reportbuf.ErrFull) {
t.Fatalf("report past the cap: error = %v, want ErrFull", err)
}
}
// TestFailedWriteKeepsReportsAppendedDuringIt holds a write open,
// appends a report while it is held, then makes the held write fail.
// Both reports are kept, and the next flush writes them in the order
// they were appended, the held write's first.
func TestFailedWriteKeepsReportsAppendedDuringIt(t *testing.T) {
dir := t.TempDir()
t.Setenv("DATA_DIR", dir)
buf := startBuffer(t)
created := make(chan *os.File)
release := make(chan struct{})
buf.OnFileCreated(func(f *os.File) {
created <- f
<-release
})
err := buf.Append(map[string]string{"id": "held"})
if err != nil {
t.Fatalf("report of the held write: %v", err)
}
flushed := make(chan error)
go func() { flushed <- buf.Flush() }()
held := <-created
// Errorf, not Fatalf, until the held write is released, so that a
// failure here does not leave it held.
err = buf.Append(map[string]string{"id": "appended"})
if err != nil {
t.Errorf("report appended while the write was held: %v", err)
}
// Closing the file under the write makes the write fail.
_ = held.Close()
close(release)
err = <-flushed
if err == nil {
t.Fatal("held write succeeded, though its file was closed under it")
}
// Writes from here on, the final one at stop included, succeed.
buf.OnFileCreated(func(*os.File) {})
err = buf.Flush()
if err != nil {
t.Fatalf("flush after the failed write: %v", err)
}
files, err := readReportFiles(dir)
if err != nil {
t.Fatalf("read report files: %v", err)
}
want := `{"id":"held"}` + "\n" + `{"id":"appended"}` + "\n"
if len(files) != 1 || files[0] != want {
t.Fatalf("report files = %q, want one holding %q", files, want)
}
}
// TestReportsRefusedWhileWritesFail posts reports through the report
// handler, as the page does. Once a write has failed, a report is
// refused with 500 until a write succeeds again; the reports taken
// before and after are stored, and the one refused is not.
func TestReportsRefusedWhileWritesFail(t *testing.T) {
dir := t.TempDir()
t.Setenv("DATA_DIR", dir)
buf, h := startBufferWithHandlers(t)
if code := postReport(t, h, "before"); code != http.StatusOK {
t.Fatalf("report before the failed write: status = %d, want %d",
code, http.StatusOK)
}
// With the data directory gone, the write has nowhere to go.
err := os.Remove(dir)
if err != nil {
t.Fatalf("remove data dir: %v", err)
}
err = buf.Flush()
if err == nil {
t.Fatal("flush succeeded with the data directory gone")
}
if code := postReport(t, h, "refused"); code != http.StatusInternalServerError {
t.Fatalf("report after the failed write: status = %d, want %d",
code, http.StatusInternalServerError)
}
err = os.Mkdir(dir, 0o750)
if err != nil {
t.Fatalf("make data dir: %v", err)
}
err = buf.Flush()
if err != nil {
t.Fatalf("flush with the data directory back: %v", err)
}
if code := postReport(t, h, "after"); code != http.StatusOK {
t.Fatalf("report after a write succeeded: status = %d, want %d",
code, http.StatusOK)
}
err = buf.Flush()
if err != nil {
t.Fatalf("flush of the report after: %v", err)
}
files, err := readReportFiles(dir)
if err != nil {
t.Fatalf("read report files: %v", err)
}
stored := strings.Join(files, "")
for _, clientID := range []string{"before", "after"} {
if !strings.Contains(stored, `"clientId":"`+clientID+`"`) {
t.Errorf("report %q not stored", clientID)
}
}
if strings.Contains(stored, `"clientId":"refused"`) {
t.Error("refused report stored")
}
}
// startBufferWithHandlers starts a Buffer and the Handlers that store
// reports in it through fx, as main does, with the DATA_DIR the calling
// test has set.
func startBufferWithHandlers(
t *testing.T,
) (*reportbuf.Buffer, *handlers.Handlers) {
t.Helper()
var (
buf *reportbuf.Buffer
h *handlers.Handlers
)
app := fxtest.New(t,
fx.Provide(
config.New,
globals.New,
handlers.New,
healthcheck.New,
logger.New,
reportbuf.New,
),
fx.Populate(&buf, &h),
)
app.RequireStart()
t.Cleanup(app.RequireStop)
return buf, h
}
// postReport posts a report from clientID to the report handler, as the
// page does, and returns the status of the answer.
func postReport(t *testing.T, h *handlers.Handlers, clientID string) int {
t.Helper()
rec := httptest.NewRecorder()
req := httptest.NewRequestWithContext(t.Context(),
http.MethodPost, "/api/v1/reports",
strings.NewReader(`{"clientId":"`+clientID+`","hosts":[]}`),
)
req.Header.Set("Content-Type", "application/json")
h.HandleReport().ServeHTTP(rec, req)
return rec.Code
}
// TestConcurrentAppendsStopAtCap appends from many goroutines at once
+7 -2
View File
@@ -34,13 +34,16 @@ func (s *Server) SetupRoutes() {
s.router.Use(s.mw.Recoverer())
s.router.Use(middleware.RequestID)
s.router.Use(s.mw.Logging())
// s.mw.Recoverer would write a panic's 500 only after the panic has
// passed the request log, so it is written here, where the log sees it.
s.router.Use(s.mw.Write500OnPanic())
s.router.Use(s.mw.SecurityHeaders())
s.router.Use(s.mw.CORS(s.params.Config.CORSAllowedOrigins))
s.router.Use(s.mw.MaxBodyBytes(maxRequestBodyBytes))
s.router.Use(middleware.Timeout(requestTimeout))
// Sentry reports a panic, then panics again, so that s.mw.Recoverer
// still answers 500.
// Sentry reports a panic, then panics again, so that it still
// reaches s.mw.Recoverer.
if s.params.Config.SentryDSN != "" {
s.router.Use(sentryhttp.New(sentryhttp.Options{Repanic: true}).Handle)
}
@@ -64,6 +67,8 @@ func (s *Server) SetupRoutes() {
// other.
if s.params.Config.MetricsUsername != "" {
r.Use(s.mw.Metrics(registry))
// Likewise inside the metrics.
r.Use(s.mw.Write500OnPanic())
}
r.Get("/.well-known/healthcheck", s.h.HandleHealthCheck())
+2 -2
View File
@@ -64,8 +64,8 @@ main() {
# configs/nginx.conf is a template: the image renders it over its own
# default.conf, with the same port and limit bin/entrypoint.sh uses.
# The empty file it includes trusts no proxy, as bin/entrypoint.sh
# writes it when TRUSTED_PROXIES is unset. It also includes the
# security headers, so the page runs under the shipped policy.
# writes it when TRUSTED_PROXIES is set and empty. It also includes
# the security headers, so the page runs under the shipped policy.
docker run -d --rm --name "$SERVER" \
--network "$NETWORK" --network-alias netwatch \
-e PORT=8080 -e NGINX_ENVSUBST_FILTER='^PORT$' \