Documentation

Shipping from a site

Every site in this repo carries its own copy of web/. The shipper lives in web/shipper.go, and turning it on is two lines in that site's main.go, after web.SetupLogging() and before anything else logs:

web.SetupLogging()

shipper := web.ShipLogs("blog", web.HTTPSink())
defer shipper.Close()

The first argument is the source name and should be the first label of the site's hostname, which is also how its container is named, so a row on the dashboard and a line in docker ps say the same word.

ShipLogs wraps whatever handler is already installed rather than replacing it. Records still go to stdout exactly as before, and a copy goes onto a bounded queue that a goroutine flushes every five seconds or every five hundred records, whichever comes first. Nothing blocks: a full queue drops, a failed POST drops, and a 429 from this site drops. The failure mode is missing lines on a dashboard, never a stalled site.

The shipper never calls slog itself. A shipper that logged its own failures would enqueue a record about failing to ship, and a logging site coming back up would be handed a backlog of complaints about itself. It writes one line to stderr when it starts failing and one when it recovers, and nothing in between.

The endpoint

POST http://orchard-logging:8000/ingest, by container name on the orchard-edge bridge. Never over the tunnel, and there is no token: the public hostname refuses this path at Caddy, so the only way to reach it is from inside the network, and anything inside the network is already trusted. That is the same reasoning the alert path uses, and it is what keeps the two FROM scratch sites reading zero environment variables.

The body is one JSON object:

{
  "source": "blog",
  "records": [
    {
      "t": 1756500000000,
      "l": "INFO",
      "m": "request",
      "a": {"status": 200, "method": "GET", "path": "/", "ms": 0.412,
            "host": "blog.bythewood.me", "ip": "203.0.113.7",
            "cf_ray": "9a1f2c88e410-IAD", "bytes": 4211}
    }
  ]
}

t is unix milliseconds in UTC, l the level, m the message and a the attributes. Eight attributes get real columns because every dashboard query filters or sorts on them: component, method, path, host, ip, cf_ray, status and ms. Everything else is kept verbatim in a JSON column, so nothing is lost by not being on the list.

Answers are 202 when the batch is queued, 204 for an empty one, 400 for a body that will not parse or a missing source, 413 past two thousand records, and 429 when the write queue is full. A 429 is a healthy answer from a healthy service: it is this site shedding load rather than holding a request open on a site it is supposed to be watching.

What happens to a record

Records go onto one channel and one goroutine drains it, because SQLite takes a database-wide write lock and a second writer buys contention rather than throughput. The flusher commits every quarter second or every five hundred rows, and in the same transaction it upserts the hourly rollup those rows belong to. One transaction for both is what stops a graph from disagreeing with its own search results.

Raw lines are deleted after thirty days, in chunks, by a sweeper that runs hourly and once at startup. The hourly rollups are never deleted. That is the whole retention policy, and it is why the volume chart can cover a year while the file stays a few hundred megabytes: a year of counters for five sources is a small table, and a year of raw request logs is not.

Because deleting rows in SQLite frees pages onto a freelist rather than returning them to the filesystem, the database is created with auto_vacuum=INCREMENTAL and the sweeper runs PRAGMA incremental_vacuum after a delete. That pragma only takes effect on an empty file, so it had to be right on the first boot.

Reading it

Counts and the volume chart read the rollups, so they are correct over any window including one older than the raw retention. Percentiles, the slowest paths, the direct-hit count and the search read raw rows, so they cover the last thirty days and say so rather than quietly returning less.

Percentiles are exact rather than interpolated: the count comes from an aggregate that is wanted anyway, and each percentile is one indexed row read at an offset. Paths are ranked by p95 rather than by mean, with a floor of five samples, so one cold start cannot put a path at the top of the table.

Running it

make run SITE=logging.bythewood.me     # vite watch + go run, on :8000
make deploy SITE=logging.bythewood.me # rebuild and replace the container

# a dashboard is unreadable against an empty database, so:
cd sites/logging.bythewood.me && make seed

There is no password to set. Signing in happens on auth.bythewood.me, which pushes a six digit code to a phone, and this site asks that one over the internal bridge whether the cookie on a request is a live session. It asks on every request rather than caching the answer, so revoking a session there takes effect here immediately.

Seeding writes through the same commit path the ingest endpoint uses, rollups included, so seeded data and real data are indistinguishable downstream and a panel that looks right on one is not lying about the query it will run against the other.

Shipping from Caddy

Caddy can't carry a Go handler, so it doesn't use the shipper at all. It writes its access log straight to a socket instead, using its own net writer, and this site listens on orchard-logging:9001 for it. The lines arrive as newline delimited JSON on one connection Caddy opens and holds, and each one is turned into the same record a site would have posted, with the same attribute names, so a Caddy row is stored, rolled up, swept and watched exactly like everything else. It lands under the source caddy.

log ship {
    output net tcp/orchard-logging:9001 {
        soft_start
    }
    format filter {
        wrap json
        fields {
            request>headers delete
            request>tls delete
            resp_headers delete
        }
    }
}

soft_start is what keeps Caddy booting when this site is down, and it has to be there, since make up starts the edge before any site. The headers are filtered out because they're most of the bytes on the wire and the sites already record what matters from them, and log_append puts cf_ray back as a field of its own.

Caddy keeps a second logger writing the same events to stderr, so docker logs orchard-caddy is unchanged and stdout is still the source of truth here too. Only the access log ships, never Caddy's own runtime log, because the runtime log is where a failing net writer reports itself and shipping that over the connection that's failing would be a loop.

The interesting rows are the ones no site can produce. A 502 from a container that's down never reaches an app, so nothing else logs it, and Caddy records it at error level.

The silence rule gives caddy fifteen minutes rather than five. It has no self probe, and its heartbeat is status checking the public hostnames every three minutes, so five minutes is under two beats and one missed cycle during a status deploy would fire.

What is not covered

cloudflared and ntfy. Both log to stdout and neither can write to a network address, and pointing either at a file takes its stdout away, which would cost docker logs on the two containers where it's the only thing to read. Reading their stdout instead would mean a container holding the Docker socket, and that's root on the host if it's ever compromised, so it isn't worth it for two low volume sources. A tunnel drop still isn't visible here, though Cloudflare emails on every tunnel state change, so it was never invisible, only invisible to this site.