fix(cubestore): Report a websocket peer that goes away as debug, not error - #11786
fix(cubestore): Report a websocket peer that goes away as debug, not error#11786waralexrom wants to merge 1 commit into
Conversation
…error A client that closes without a close handshake ends the connection the same way a graceful one does: the driver terminates connections by design on a heartbeat timeout, a write error and on dispose, and a killed process or a closed browser tab looks the same. Every one of those was logged as an error, so a rolling restart of the API produced one error line per connection and pushed the error rate of a healthy node over its alerting threshold. Classify the read-stream error instead: a vanished peer is reported at debug, a frame arriving after the peer's own close frame at warn, and everything else -- other protocol violations, TLS, capacity and IO errors that are not a vanished peer -- stays at error. IO errors are split by kind rather than lowered as a group, so a genuine failure of the connection is still an error.
|
Claude finished @waralexrom's task in 1m 55s —— View job Review: approach is sound — 1 medium (send path still logs vanished peers at
|
| # | Severity | Location | Issue |
|---|---|---|---|
| 1 | Medium | mod.rs:530, 541, 567 | Send-path errors still log at error. A peer that goes away mid-query hits Websocket message send error with ConnectionClosed/Io(BrokenPipe), so the rolling-restart scenario the PR targets can still emit one error line per connection. Routing those three sites through the same websocket_error_level would close the gap — the classifier is already direction-agnostic. |
| 2 | Low | mod.rs:155–166 | The 11-line doc block exceeds the repo's 3-line guidance for explanatory comments, repeats the source() sentence verbatim from mod.rs:115, and restates the commit message. The four inline blocks in tungstenite_error_level are similar; the _ => one mostly re-lists the arms above it. |
Notes, not blocking
ConnectionClosed/AlreadyClosed are listed defensively for a future tokio-tungstenite bump — worth keeping, and the comment says as much. After this change a connection ending abnormally is invisible at the default info level; that's the intent, but if connection-lifecycle visibility matters operationally, a single debug! on loop exit would be a cheaper place to get it than an error per disconnect.
| } | ||
| None => error!("Websocket error: {:?}", e), | ||
| None => log::log!( | ||
| websocket_error_level(&e), |
There was a problem hiding this comment.
The read path is now classified, but the send paths in the same loop are not, and a vanished peer reliably produces an error there too. In the rolling-restart scenario the PR targets, a client that goes away with a query in flight hits web_socket.send(...) at line 541 (Websocket message send error) — warp returns Error(tungstenite::Error::ConnectionClosed) or Io(BrokenPipe) — before or instead of the read stream error, so the node still emits an error line per connection and the alerting threshold is still crossed.
Same applies to the two Websocket close send error sites (lines 530 and 567): sending a close frame to a peer that already left is exactly the benign case.
Suggest routing all three through the same classifier, e.g.
log::log!(websocket_error_level(&e), "Websocket message send error: {:?}", e);The classification function itself is send/receive agnostic, so no change is needed to it. Fix this →
| /// Level at which an error from the websocket read stream is reported. | ||
| /// | ||
| /// A peer that disappears without a close handshake ends the connection the | ||
| /// same way a graceful client does: nothing on this side failed and there is | ||
| /// nothing for an operator to act on, while a fleet of clients going away at | ||
| /// once — a rolling restart of the API, say — produces one line per connection. | ||
| /// Reporting those as errors buries the transport failures that do need | ||
| /// attention, so they are separated here. | ||
| /// | ||
| /// `warp` boxes the underlying `tungstenite` error, so it has to be recovered | ||
| /// through `source()`; an error that is not one is left at `Error`, since it is | ||
| /// not known to be benign. |
There was a problem hiding this comment.
This doc block is 11 lines for a function whose body is 8. The load-bearing facts are that a vanished peer isn't actionable and that warp boxes the tungstenite error so it must come back through source() — the rolling-restart narrative is already in the commit message. The source() sentence is also a verbatim repeat of the one on message_too_large_reason (line 115).
Something like:
/// Level at which an error from the websocket read stream is reported. A peer
/// that vanishes without a close handshake is not actionable, and a fleet of
/// them going away at once would otherwise bury real transport failures.
/// `warp` boxes the `tungstenite` error, so it comes back through `source()`;
/// anything else is not known to be benign and stays at `Error`.
Same for the four inline blocks inside tungstenite_error_level — each explains a one-line arm in 3–4 lines. The ResetWithoutClosingHandshake and ReceivedAfterClosing ones earn their place (they say why the level is not the obvious one); the _ => catch-all mostly re-lists what the arms above already exclude.
Codecov Report✅ All modified and coverable lines are covered by tests.
Additional details and impacted files@@ Coverage Diff @@
## master #11786 +/- ##
===========================================
- Coverage 84.67% 60.11% -24.57%
===========================================
Files 261 239 -22
Lines 86451 19171 -67280
Branches 0 3884 +3884
===========================================
- Hits 73204 11524 -61680
+ Misses 13247 7097 -6150
- Partials 0 550 +550
Flags with carried forward coverage won't be shown. Click here to find out more. ☔ View full report in Codecov by Harness. 🚀 New features to boost your workflow:
|
Summary
A websocket client that disconnects without a close handshake was logged as an
error, even though that is how connections normally end: the Cube Store driver
terminates them by design on a heartbeat timeout, on a write error and on
dispose, and a killed process or a closed browser tab looks the same from the
server. A rolling restart of the API therefore produced one error line per
connection and pushed the error rate of a perfectly healthy node over its
alerting threshold. This classifies the read-stream error instead of reporting
every one of them at
error.Changes
websocket_error_level()/tungstenite_error_level()inhttp/mod.rspickthe level for an error from the websocket read stream; the call site logs
through
log::log!with the level they return.debug: a peer that is simply gone —Protocol(ResetWithoutClosingHandshake),Iowith kindConnectionReset,ConnectionAborted,BrokenPipe,NotConnectedorUnexpectedEof, plusConnectionClosed/AlreadyClosed. The last two cannot reach this branchwith the current
tokio-tungstenite, which turns them into the end of thestream, but they are a normal close either way and are listed so a version
bump cannot turn a graceful close into an error.
warn:Protocol(ReceivedAfterClosing)— a frame that raced the peer's ownclose frame. Harmless for the connection, worth seeing if a client does it
often.
error, unchanged: every other protocol violation (InvalidOpcode,NonZeroReservedBits,ControlFrameTooBig, ...),Tls,Capacity,Utf8,AttackAttempt,WriteBufferFull, and anyIoerror whose kind is not avanished peer.
Iois split by kind rather than lowered as a group, so agenuine failure of the connection is still reported as one.
Testing
http::tests::websocket_error_levelscovers one representative per class,including both shapes a vanished peer arrives in and an
Ioerror that muststay at
error. The classification is a function overtungstenite::Errorrather than
warp::Errorprecisely so it is constructible in a test —warp::Errorhas no public constructor.cargo check -p cubestore --lib --all-targetsclean,cargo fmtapplied.