Repository navigation
Record why relay connections close and quiet close warnings - #9245
Conversation
Add close_reason to the access close line, lower the auth-timeout and missed-pong warnings to debug, and count missed-pong disconnects. Co-authored-by: Will Pfleger <wpfleger@block.xyz> Signed-off-by: Will Pfleger <wpfleger@block.xyz>
🔐 Codex Security Review
Review SummaryOverall Risk: NONE
FindingsNo concrete security, correctness, or reliability findings were identified. Notes
Generated by Codex Security Review | |
A client's reply to a server Close, a policy or auth-rejection close and a dropped handler now log their real close_reason. The reader defers to a close the server already decided on; a heartbeat tick after cancellation is not counted as a miss. Co-authored-by: Duncan <dcfd242e557282d7a1e2cf2e6877522682f1e5c6156dc92ca7d90eaedd3b0f95@buzz.block.builderlab.xyz> Signed-off-by: Will Pfleger <wpfleger@block.xyz>
kalvinnchau
left a comment
There was a problem hiding this comment.
🤖 One finding inline.
| return Some(reason.as_str()); | ||
| } | ||
| conn.cancel.is_cancelled().then(|| { | ||
| if matches!(conn.auth_state_snapshot(), AuthState::Failed) { |
There was a problem hiding this comment.
🤖 [P3] AuthState::Failed does not mean "AUTH was rejected", so unrelated server closes of pending connections can be logged as auth_failed
finish_pending_auth_on_cancel (the auth_cancel_task watcher in handle_active_connection) moves every still-Pending connection to Failed as soon as cancel fires, whatever the cause. It runs concurrently with the reader, so by the time server_close_reason runs (in recv_loop's Close/Err arms, or after recv_loop returns), Failed may have been set by the cancellation itself rather than by a rejected AUTH.
Trigger: an unauthenticated client sends REQs (or malformed frames) without reading. Each gets CLOSED auth-required / NOTICE. Once the send buffer fills, handlers::close::refuse or ConnectionState::send (backpressure) cancels with no disconnect reason. The close line then reads server_closed or auth_failed, depending on whether the watcher ran first. That client never sent AUTH, and the PR description defines auth_failed as "an AUTH rejected". Both tasks wake from the same cancel, so the order is not deterministic.
server_close_reason_ranks_shutdown_policy_then_cancellation builds AuthState::Failed directly, so it does not cover a Pending connection that was flipped by the watcher.
Fix direction: record auth_failed at the rejection sites (where AuthAttempt::reject / deny_admission / the shed path decides to close) before cancelling, as the heartbeat and auth-timeout paths already do, and drop the Failed inference here. If that is too invasive, have finish_pending_auth_on_cancel leave a state distinct from a rejection.
kalvinnchau
left a comment
There was a problem hiding this comment.
🤖 Approving. The inline P3 (close_reason inferred from AuthState::Failed) is non-blocking.
…ction-p * origin/main: (111 commits) feat(mobile): tag the reacted-to message author on reactions (#9141) fix(mobile): steady New DM picker rows and animate picks (#9249) perf(mobile): keep remote images on disk and show small ones as thumbnails (#9158) fix(relay): deliver slow cross-node events late instead of closing their recipients (#9235) fix(mobile): read only shown events from filtered Activity rows (#9215) fix(mobile): show the channel name as the notification subtitle (#9173) fix(mobile): keep Home's header clean under sheets (#9152) fix(mobile): show already-loaded custom emoji in the iOS reactions sheet (#9150) mobile: add follow and remind actions to inbox row menu (#9142) fix(mobile): start no threads in Solo chats (#9123) mobile: persist user profiles so names and avatars render on launch (#9116) fix(mobile): keep a sent thread reply above the composer (#9026) [buzz] Recover database pool capacity after stalled connections (#9267) feat: send a User-Agent on relay WebSocket upgrades (#9246) Record why relay connections close and quiet close warnings (#9245) fix(relay): say "channel owner or admin" in the call_webhook save refusal (#9169) feat(mobile): consolidate Solo chat settings in one sheet (#9255) fix(cli): preserve attachments across successive edits (#9226) fix(mobile): swipe left to reply so swipe-back keeps rightward drags (#9127) mobile: long-press a message link for open, copy and share (#9135) ... Signed-off-by: Matthew Boston <mboston@squareup.com>
Since bb-public prod moved to
RUST_LOG=error,buzz_relay=info, two connection-close warnings send about 1.9M lines a day to Datadog. This moves that information to the access log and a metric.close_reasonon the accesscloseline. The first reason recorded wins. When the server has already decided to close (shutdown, a policy disconnect, or a cancellation), the reader defers to that decision, so a peer's reply to the server's Close is never logged as the cause.auth_timeout,auth_failed(an AUTH rejected and closed immediately, or a timeout after a rejected AUTH),missed_pongs,client_closed,socket_error,frame_too_large,control_channel_full,shutdown,server_closed,refusedfor connections refused before they were served, andhandler_droppedfor a handler dropped before normal cleanup.community_archived,community_deleted,auth_policy_upgraded,authorization_denied,access_revokedorremoved.debug!, with the same text and fields.buzz_ws_missed_pong_disconnects_total, next tobuzz_ws_auth_timeouts_total. A heartbeat tick that races a close already decided is not counted.Timeouts, ping cadence, the frames sent and when connections close are unchanged. The new infra-free tests are added to the
test-unitselection andscripts/run-tests.sh.