feat(monitoring): record who the gates turn away, instead of nothing - #417
Conversation
Until now a member refused at the apex, MTG or music gate left no trace anywhere, and neither did an operator refused at /beheer. So a gate that had quietly broken produced exactly the same evidence as an evening with no visitors: none. That is rebrand task mon-1, which replaced 6f evidence item 7 for this reason. Two separate faults were keeping the log out of Loki, and fixing either one alone would have looked like a fix and changed nothing: - the old log_settings snippet wrote to a file inside the container, and Alloy only ever tails container stdout through the Docker API; - it set level WARN, and Caddy logs a 403, a 302 and a 200 all at INFO, so the level alone discarded every entry except the 5xx ones. The three gated hosts now use a gate_access_log snippet instead: stdout, JSON, no level. The Plex and Jellyfin blocks keep the old file logger. Successful requests are dropped in Alloy rather than in Caddy. That is normally the wrong place, so the reason matters: Caddy's log directive has no status-code filter and its level does not vary with the status, so the source genuinely cannot tell a served page from a refused one. 304 is dropped with the 2xx, because "you already have this, unchanged" is a request that worked. Each gated host also appends the portal's answer as two log fields. It has to be explicit: the request.headers an access entry records are a snapshot taken before any handler runs, so they carry what the CLIENT sent, which on these hosts is precisely the value the Remote-* strips throw away. Without the appended fields a /beheer 403 would say somebody was refused and never who, which is the evidence the 6e sitting could not reconstruct. They sit after the gate, so a refused request carries no identity, which is correct. Verified against the pinned caddy:2.11.4-alpine image rather than the docs: the uniform INFO level, the pre-handler header snapshot, that log_append reports the post-gate identity, and that Cookie, Set-Cookie and Authorization are redacted in both directions, so a kept 302 carrying a fresh session cookie holds no credential. Not proven yet: a real refusal has to be caused on purpose and watched land in Loki before any of this counts as evidence (the #401 lesson). That happens on deploy.
|
Follow-up worth recording, from Legolas in #418 (fix/authentik-idle-session), found independently while this was in review. After an hour idle the gate session expires and the outpost does a full OAuth round trip per request instead of refreshing. The page and every icon race through it at once and clobber each other's state cookie, so the losers render broken until a second reload. Diagnosing that needed the outpost's own logs, precisely because Caddy's access log was at WARN and a 302 left no trace. That is a good concrete answer to "what would this have caught": once deployed it shows up as a burst of 302s on asset paths, readable as Order note: this merged first, so #418 rebases. The two edits to the mtg route block are adjacent rather than overlapping (its @public handle goes before the gate macro call, the log_identity() call after it), and log_identity() has to stay after the gate for the reason in the PR body. |
|
Blind spot in this change, found by Legolas in #418 and worth writing down next to the code rather than in a thread nobody re-reads. A failed OAuth callback is a 200, so this drop discards it. When a gate session expires mid-page-load, the outpost round trips per request and the parallel callbacks clobber each other's state cookie. From Caddy's point of view those callbacks return 200; the failure is only visible in the outpost's own log as That is a genuine limit of "non-2xx only" and not something to fix by widening the drop, which would just restore the firehose. The targeted fix, if it turns out to be worth it once the gates are on authentik, is to exempt Queued rather than done here: mon-1 is merged and this is a separate objective. Cross-reference: #418 fixes the underlying race by pinning |
|
Correction to my comment above. I wrote that the So the follow-up is live work, not future work:
Nothing about the merged change is wrong; the code does not depend on which portal answers. Only my note about when the follow-up matters was. |
1 participant
Rebrand claim-board row mon-1, which replaced 6f evidence item 7 in #414.
Sibling mon-2 shipped in #416.
The gap
There is no record of who was refused at the apex, MTG or music gate, and none
of an operator refused at
/beheer. So a gate that had quietly broken and anevening with no visitors produce identical evidence: nothing. That is also why
6f evidence item 2 could not be corroborated from anything but somebody's
memory of a browser session, and it gets worse once Authelia is retired and
there is no second portal to sanity-check against.
What was actually wrong
Two separate faults, and fixing either alone would have looked like a fix and
changed nothing.
log_settingssnippet writes to/config/access.log, a file insidethe container. Alloy only ever tails container stdout through the Docker
API, so nothing in that file could reach Loki no matter what went into it.
level WARN. Caddy emits an access entry for a 403, a 302 anda 200 at the same INFO level (verified below), so the level alone was
discarding every entry except the 5xx ones.
The three gated hosts now import a new
gate_access_logsnippet: stdout, JSON,no level. Plex and Jellyfin keep the old file logger.
Why the filter lives in Alloy
Normally the right answer is to fix noisy logs at the source, and the repo's own
policy says so. It does not apply here, and the reason is the same one that made
the Gatus probe line an exception: Caddy's
logdirective has no status-codefilter, and its level does not vary with the status, so the source cannot tell
a served page from a refused one. The cut is made in
monitoring/alloy/config.alloyon the way to Loki, anchored on both the access-log message and the status.
304 is dropped alongside the 2xx. "You already have this, unchanged" is a request
that worked, and on the MTG SPA and the music cover art it is most of the
traffic. That is the one deliberate widening past the "non-2xx only" brief.
Identity, which needed doing explicitly
The
request.headersan access entry records are a snapshot taken before anyhandler runs. So they show what the CLIENT sent, which on a gated host is
precisely the value the
request_header -Remote-*strips exist to throw away,and never what the gate injected. Without something extra, a
/beheer403 wouldrecord that somebody was refused and never who.
Each gated host therefore carries two
log_appendlines after its gate, puttingthe portal's answer in
remote_userandremote_groups. Side effect worthhaving: a forged
Remote-Userfrom a client and the portal's real answer bothappear, in different fields, so a spoof attempt is legible instead of hidden.
They must stay after the
forward_auth; above it they would record the client'sown claim and label it as the portal's, which
tests/test-caddy-site.shnowpins.
A refused request carries no identity, because the gate answers first and the
appends never run. That is correct: at that point there is none. What the entry
has is the address, host and path, and on the two tunnel hosts the member's real
address is in the logged
X-Forwarded-For/Cf-Connecting-Ip.Verified against the pinned image, not the docs
Ran
caddy:2.11.4-alpinein a throwaway container with a config shaped like thereal gates:
level":"info", which iswhat confirms fault 2 above.
request.headersshowed a client-suppliedRemote-Userthat theroute had already stripped, which is what proves the snapshot is pre-handler.
log_appendreports the post-gate value, as a top-level field.Cookie,Set-CookieandAuthorizationareREDACTEDin both directions,so a kept 302 carrying a fresh session cookie holds no credential.
Also run locally: both rendered Caddyfiles through
caddy validate(default andall-gates-on-authentik),
alloy fmtplus a realalloy runload so the newregex is proved to compile as a component and not just to parse, the full
tests/run.sh(40 files, 0 failures),pre-commit --all-files, and shellcheckon the two changed tests.
Reading it
Everything that arrives there is already a request that did not succeed, so
there is no status filter to type.
| jsongivesstatus,request_host,request_uri,request_remote_ip,remote_user,remote_groups.Not proven yet
Per the #401 lesson, none of this is evidence until a refusal has been caused on
purpose and watched land. That happens at deploy time and the claim-board row
stays short of DEPLOYED until it has.
Deploy note
deploy.ymlrenders the Caddyfile and reloads Caddy (SITE-7). Alloy is not inthe DEP-6 hash list and its config is a bind mount, so it additionally needs
docker compose up -d --force-recreate alloyor the new drop stage is notloaded and every successful request lands in Loki.
Scope
No alert and no dashboard: mon-1 is the record, mon-2 was the alerting half. The
gates themselves, the portals and the Plex/Jellyfin blocks are untouched.