Skip to content

feat(relay): log reads, logins and connections on access target - #8376

Open
wpfleger96 wants to merge 5 commits into
mainfrom
duncan/relay-access-logging
Open

wpfleger96 wants to merge 5 commits into
mainfrom
duncan/relay-access-logging

Conversation

@wpfleger96

@wpfleger96 wpfleger96 commented Oct 15, 2026 •

Copy link
Copy Markdown
Member

🤖 Adds an access log for relay reads, logins, connections and HTTP requests on the dedicated buzz_relay::access target. It writes to stdout, not audit_log, so reads never take the audit advisory lock. The log is shaped for volume: one line per HTTP request, one line per WebSocket read, and one line per WebSocket connection.

Lines per operation

Operation Lines
HTTP request on a matched route 1 (http), except the skip list below
HTTP request matching no route 1 (http, route="<unmatched>") at status 400 and above, otherwise none
WebSocket connection 1 (close, carrying the login)
WebSocket REQ / COUNT 1 each (req / count), plus the buzz_ws_reads_total counter
WebSocket NIP-42 login 1 (auth) per decided or cut-off attempt, capped after the decision as below
Audio login 1 (auth, at its final admission check)
WebSocket EVENT 1 (Event ingested, not on the access target)

HTTP requests

One middleware, http_access_log, writes every HTTP line. It sits between track_metrics and http_trace_layer, so rebuilt errors, body-limit refusals and localhost refusals all reach it. It writes the line when the response is ready, which is not proof the body was delivered. A request dropped before then logs request=aborted at WARN with no status.

  • Every line carries route (the matched route template, never the raw path), peer_addr when the listener has one, status, time_to_response_ms and http_method (the HTTP verb). The verb stays on the line itself because the http.request span is absent under an access-only filter and when a pending request is dropped.
  • Handlers record what they learn on the request's AccessSlot: the login (method, pubkey, pubkey_verified, community), the decision, the filter summary, and the route's own fields. The decision is outcome (success / denied / failed / challenged) with a fixed reason, or undecided when the route recorded none. A refusal is final: a later admission doesn't replace it, so a replayed NIP-98 proof that verifies and is then refused logs failed / nip98_replay.
  • outcome describes the login. What the route did is in status and the route's fields: a rejected /events write logs outcome=success with status=400, accepted=false and its reject_reason.
  • Route fields:
    • /query and /count: the filter summary and result_count.
    • /events: accepted, kind, event_id, and on a refused write the parse category / line / column or a fixed reject_reason (such as invalid or restricted), never the ingest message.
    • Invite mint: invite_id, expires_at and max_uses. Invite claim: joined.
    • Admin feedback attachment reads: feedback_id and attachment_sha256. With BUZZ_ADMIN_AUTH=disabled they log method=network_trusted with no key, and Host or Origin refusals log their fixed reason.
    • Every other route logs only the login fields.
  • No field can hold an invite code, a token, or a Blossom read hash. Media routes log the /media/{sha256_ext} template.
  • Skip list: NIP-11 and other non-upgrade requests on /, /info, /.well-known/nostr.json, /health, /_liveness, /_readiness, and the SPA and static files the relay serves when enabled (web assets, invite landing pages, git web pages, the admin bundle) at any status. Successful WebSocket upgrades (101) log no http line. Refusals before the upgrade on / and the audio path log one, with the status actually sent.
  • Routes that aren't Nostr-key logins (the command-token disconnect endpoint, the workflow webhook, the git server's internal callback) log outcome=undecided with no key.
  • Dev-mode X-Pubkey requests log method=x_pubkey, pubkey_verified=false.
  • A successful /query or /count that returned nothing (result_count=0) logs at DEBUG: on staging, 93% of /query lines were empty polls. Denied, failed, aborted and error reads, reads with no result_count, writes and logins keep their levels.
  • Other successful lines and git's credential-less first request (challenged, with its 401) are INFO. Refusals, statuses of 400 and above, and aborted requests are WARN. In Enforce mode the line records the remapped status (for example 403). Denial bodies and headers are unchanged.

WebSocket reads

  • REQ / COUNT lines carry pubkey, conn_id, sub_id, the filter summary, the outcome (served / denied / aborted / error plus a fixed reason), and events_queued (REQ) or count (a COUNT that counted). A read logs WARN only when it ends in error. served, denied and aborted are INFO, since aborted means the client closed the connection mid-read.
  • REQ lines stay at INFO even when empty at EOSE, because the subscription can still deliver live events later.
  • Filter summary, shared with HTTP /query and /count: kinds, channel ids, authors and p values each list the first 10 distinct values. The exact kind_count / channel_count / author_count / p_count (summed per filter) appears only when the list is * or shows fewer values than the filters held. A dimension that any filter leaves open logs *. since / until / limit take the widest bound and are absent when any filter leaves them open, so no field understates what the read covered. ids is a count only. NIP-50 search logs search: true, never the text. Only well-formed channel ids and pubkeys are listed. An artifact read's summary uses only the standard dimensions of each raw filter, so artifact predicates and client-defined tags (such as #1) are never logged. The summary is skipped when the access target is off. Under =warn, every WARN line, HTTP or WebSocket, still carries it.
  • Per connection, only the first 16 reads that are refused before they run (auth_required, quota, concurrency, overload) or denied are logged. The rest are counted as reads_suppressed on the close line. A refusal that arrives after the close line has been written, from a read still running when the client left, logs its own line, so every refusal is either logged or counted, never both. Served reads are never capped.

WebSocket read counter

buzz_ws_reads_total{type="req"|"count"} counts every parsed REQ and COUNT frame before admission, exported at zero from startup. It is a metric, so it counts at any RUST_LOG, including production's current error.

WebSocket logins

A NIP-42 login writes one auth line when it is decided. A successful login logs INFO outcome=success at its commit point, decided under the connection's close-reason lock, so a disconnect racing the login (session expiry, admin disconnect, revocation, ban or roster removal) either wins, and the login logs no success, or loses and closes the connection right after the success line. A refused or failed login writes one WARN auth line with outcome, a fixed reason from the shared AuthReason code set, pubkey and pubkey_verified. Root WebSocket auth lines carry peer_addr. AUTH frames after the login is decided are capped at 16 per connection, and the rest are counted as auth_suppressed. An attempt cut off by close or session expiry logs aborted. Audio logins log one auth line at their final admission check.

Connections

The close line is the connection's only line. It is owned by the upgraded socket, so it is written exactly once however the connection ends: a normal close, a refusal while checking the community is active (refused=not_admitted), the connection limit (refused=connection_limit), or the handler being dropped. It carries conn_id, community, peer_addr, duration_ms, the login, events_queued / bytes_queued (frames the writer accepted and flushed, not client delivery), and the two suppression counters.

Error text

  • Database errors log as DbError::kind() (SQLSTATE or variant), including the command-executor event insert. Workflow database and webhook errors log as their codes, since webhook URLs can be secrets.
  • Git NIP-98 failures log a fixed code. Git subprocess stderr moved to DEBUG because hook output can contain message text.

Operator notes

.env.example documents the target, its event values (http, auth, req, count, close), the skip list, the levels, and how to turn it down: buzz_relay::access=warn keeps refusals, errors and aborted HTTP requests, and of WebSocket reads only those that end in error, and =off drops everything. It also lists the removed lines: NIP-42 auth successful/failed, WebSocket connection established/closed, event=connect, HTTP bridge request, Event ingested via pipeline, relay invite minted, relay member added via invite, admin feedback attachment read, and addr (now peer_addr). JSON lines no longer repeat the current span as span, since spans already ends with it. A line logged under an explicit parent: span loses that parent's fields. The default OTel export filter sets buzz_relay::access=off, so access lines aren't exported a second time as span events.

peer_addr is the TCP peer. BUZZ_CLIENT_IP_HEADER optionally names a request header (for example cf-connecting-ip behind Cloudflare or x-real-ip behind nginx, matched case-insensitively). When set, http, auth (root and audio), close and connection-limit lines also log client_ip: the rightmost comma-separated entry of the header's last field, only if it parses as an IP address. It never replaces peer_addr, and it is only trustworthy when every request arrives through a proxy that overwrites the header.

@wpfleger96
wpfleger96 force-pushed the duncan/relay-access-logging branch 2 times, most recently from 2287045 to 1fa935a Compare October 15, 2026 23:02
@wpfleger96 wpfleger96 changed the title feat(relay): log reads, auth attempts and connections on access target feat(relay): log reads, logins and connections on access target Oct 16, 2026
@wpfleger96
wpfleger96 marked this pull request as ready for review October 17, 2026 17:21
@wpfleger96
wpfleger96 requested a review from a team as a code owner October 17, 2026 17:21
@github-actions github-actions Bot added the codex-security-review-current The posted Codex security review matches its recorded range. label Oct 17, 2026
@github-actions

github-actions Bot commented Oct 17, 2026 •

Copy link
Copy Markdown

🔐 Codex Security Review

Note: This is an automated, security-focused review generated by Codex.
Use it as a supplement to human review; false positives are possible.

Scope

  • Exact PR diff: 3ed07e5c758fe14c3712e6e8309dfe90942f1d81...ec8eaa621bd28f6ea78e1fede88e3485bf38238c
  • Model: gpt-6.1-sol

💡 Click "edited" above to see earlier reviews for this PR.


Review Summary

Overall Risk: NONE

No concrete security, correctness, or reliability findings identified in the authorized PR range.

Findings

No concrete security, correctness, or reliability findings were identified.

Notes

  • Review used read-only source inspection. Builds and tests were not executed.

Generated by Codex Security Review |
Requested by: @wpfleger96 |
Workflow run

@github-actions github-actions Bot added codex-security-review-current The posted Codex security review matches its recorded range. and removed codex-security-review-current The posted Codex security review matches its recorded range. labels Oct 17, 2026
@github-actions github-actions Bot added codex-security-review-current The posted Codex security review matches its recorded range. and removed codex-security-review-current The posted Codex security review matches its recorded range. labels Oct 17, 2026
@github-actions github-actions Bot added the codex-security-review-current The posted Codex security review matches its recorded range. label Oct 18, 2026
@github-actions github-actions Bot removed the codex-security-review-current The posted Codex security review matches its recorded range. label Oct 18, 2026
@github-actions github-actions Bot added codex-security-review-current The posted Codex security review matches its recorded range. and removed codex-security-review-current The posted Codex security review matches its recorded range. labels Oct 18, 2026
@github-actions github-actions Bot added the codex-security-review-current The posted Codex security review matches its recorded range. label Oct 18, 2026
@wpfleger96
wpfleger96 force-pushed the duncan/relay-access-logging branch from 1a3e31d to 1ecd8ae Compare October 18, 2026 19:43
@github-actions github-actions Bot added the codex-security-review-current The posted Codex security review matches its recorded range. label Oct 20, 2026

@wesbillman wesbillman left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 Star Lord’s automated source follow-up review via Wes’s account, integrating independent Rocket, Mantis and Groot lanes.

No changes requested in the three-commit follow-up. The previous WebSocket WARN-summary finding is fixed through the real REQ/COUNT constructors. The atomic close marker accounts for late refusals without retaining the close record through detached reads; existing handler permits remain intact. Source assessment: minimalism, elegance and correctness each 9/10 for this follow-up.

Optional separate follow-up: the unchanged HTTP summary guards in AccessSlot::read and ProvenCaller::read_artifact still require INFO, so HTTP failures at WARN can omit read scope. This predates these fixes and is outside the focused follow-up; it is not a change request here.

Reviewed head cdfb12eb399b03be22af05ba324bcd4b5d3ce9a5 against base fcdabcf774203884c4f5b258aad000a740586eb6, focusing on changes since b0a3747bf84b4fcb76e9068fcefcdbfe7f754c00 and affected callers. The public description and discussion contained no attached images or actionable disclosure found in this pass.

Source inspection only: no tests, builds, app launches or live relay requests were run. CI was not checked. Runtime cancellation timing, logging throughput and deployed log collection remain unverified.

@github-actions github-actions Bot removed the codex-security-review-current The posted Codex security review matches its recorded range. label Oct 20, 2026

@wesbillman wesbillman left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 Star Lord’s automated source follow-up review via Wes’s account.

No changes requested. Since the reviewed head cdfb12e, the feature change replaces prev < REFUSAL_LINES || prev >= CLOSED with the equivalent negated half-open range check. Boundary behavior and atomic ordering are preserved. The main merge has no conflict-resolution changes; the existing tracing-subscriber lockfile addition is unchanged. Minimalism, elegance and correctness: 9/10 each for this follow-up.

Reviewed head 93e3daf936243b36ed9b0ff7191ad5d65ad67bad against base a93f3282cc017e8decc8ea803d92967c4c3e36df. This uses the small unchanged-feature follow-up exception to team review; the previous feature review had independent team coverage. Public description and discussion inspected: no attached images or actionable disclosure found.

Source inspection only. No tests, builds, apps or live relay requests were run; CI was not checked. Runtime cancellation, logging throughput and deployed collection remain unverified.

@wpfleger96

Copy link
Copy Markdown
Member Author

🤖 Addressed in fe77157. Thanks for catching the HTTP side. AccessSlot::read and ProvenCaller::read_artifact now build the filter summary at WARN, so a denied, failed or aborted HTTP read keeps its scope under buzz_relay::access=warn. Two tests cover it: access::tests::warn_only_http_read_lines_keep_the_filter_summary, which checks a 500 and an abort through AccessSlot, and api::bridge::postgres_tests::warn_only_artifact_read_lines_keep_the_filter_summary, which checks that the artifact-only #x tag and the search text never appear. Each test fails when its guard is set back to INFO.

@github-actions github-actions Bot added the codex-security-review-current The posted Codex security review matches its recorded range. label Oct 20, 2026
@github-actions github-actions Bot removed the codex-security-review-current The posted Codex security review matches its recorded range. label Oct 20, 2026

@wesbillman wesbillman left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤖 Star Lord’s automated source follow-up review via Wes’s account, integrating independent Rocket, Mantis and Groot lanes.

No changes requested in this two-commit follow-up. The HTTP read-summary guards now retain collected scope under WARN-only logging, including the artifact path. The shared WARN capture exercises the real summary producers and HTTP formatter; the artifact regression is included in the unit-test selection. Minimalism, elegance and correctness: 9/10 each for this follow-up.

Reviewed head 48e62d810eff2a2a1e332de2f8183ed78bbb69f7 against base a93f3282cc017e8decc8ea803d92967c4c3e36df, focusing on changes since reviewed head 93e3daf936243b36ed9b0ff7191ad5d65ad67bad and affected callers. Public description and discussion inspected: no attached images or actionable disclosure found.

Source inspection only: no tests, builds, apps or live requests were run. One CI snapshot showed 71 successful, 3 failed, 27 skipped and 2 running checks. The failures are Desktop Smoke E2E (10) and its two aggregate checks; their cause was not established in this review. Unchanged limitation: artifact cancellation during the query await can occur before its summary is recorded; this follow-up does not fix that ordering. Runtime cancellation, logging throughput and deployed collection remain unverified.

@wpfleger96
wpfleger96 force-pushed the duncan/relay-access-logging branch from 48e62d8 to 5d6a472 Compare October 27, 2026 00:02
@github-actions github-actions Bot added codex-security-review-current The posted Codex security review matches its recorded range. and removed codex-security-review-current The posted Codex security review matches its recorded range. labels Oct 27, 2026
@github-actions github-actions Bot added the codex-security-review-current The posted Codex security review matches its recorded range. label Oct 27, 2026
@github-actions github-actions Bot added codex-security-review-current The posted Codex security review matches its recorded range. and removed codex-security-review-current The posted Codex security review matches its recorded range. labels Oct 27, 2026
Duncan and others added 5 commits October 28, 2026 11:05
Signed-off-by: Duncan <dcfd242e557282d7a1e2cf2e6877522682f1e5c6156dc92ca7d90eaedd3b0f95@buzz.block.builderlab.xyz>
Successful bridge reads that return nothing are mostly polling, so they
drop to DEBUG; WebSocket REQ lines stay at INFO because an empty
subscription can still deliver live events. buzz_ws_reads_total counts
REQ and COUNT frames at any log level to measure the production read rate.

Filter summaries omit *_count when the list already shows every value, and
HTTP lines take the method from the http.request span, now at ERROR level
so it is present wherever an access line is. The HTTP detail becomes one
flat struct, and overlapping router tests are merged.

Signed-off-by: Duncan <dcfd242e557282d7a1e2cf2e6877522682f1e5c6156dc92ca7d90eaedd3b0f95@buzz.block.builderlab.xyz>
Signed-off-by: Duncan <dcfd242e557282d7a1e2cf2e6877522682f1e5c6156dc92ca7d90eaedd3b0f95@buzz.block.builderlab.xyz>
The http.request span is absent under an access-only filter and when a
pending request is dropped, so lines relying on it lost the verb. Keep the
span at INFO and the verb on the line; also test the WS read counter
through the dispatcher.

Co-authored-by: Will Pfleger <pfleger.will@gmail.com>
Signed-off-by: Will Pfleger <pfleger.will@gmail.com>
The capture helpers built a generic flattened JSON layer, which could drift
from the TraceContextJson formatter main.rs installs.

Co-authored-by: Will Pfleger <pfleger.will@gmail.com>
Signed-off-by: Will Pfleger <pfleger.will@gmail.com>
@wpfleger96
wpfleger96 force-pushed the duncan/relay-access-logging branch from f5643c2 to ec8eaa6 Compare October 28, 2026 15:15
@wpfleger96
wpfleger96 deployed to codex-review October 28, 2026 15:15 — with GitHub Actions Active
@github-actions github-actions Bot added codex-security-review-current The posted Codex security review matches its recorded range. and removed codex-security-review-current The posted Codex security review matches its recorded range. labels Oct 28, 2026

This branch was successfully deployed

1 active deployment
codex-review — ec8eaa62 Deployed Oct 28, 2026 by wpfleger96 via Run Codex Security Review #10221
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

codex-security-review-current The posted Codex security review matches its recorded range.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants