Skip to content

fix(cubestore): Report a websocket peer that goes away as debug, not error - #11786

Open
waralexrom wants to merge 1 commit into
masterfrom
cubestore-websocket-reset-log-level
Open

fix(cubestore): Report a websocket peer that goes away as debug, not error#11786
waralexrom wants to merge 1 commit into
masterfrom
cubestore-websocket-reset-log-level

Conversation

@waralexrom

Copy link
Copy Markdown
Member

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() in http/mod.rs pick
    the 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), Io with kind ConnectionReset,
    ConnectionAborted, BrokenPipe, NotConnected or UnexpectedEof, plus
    ConnectionClosed / AlreadyClosed. The last two cannot reach this branch
    with the current tokio-tungstenite, which turns them into the end of the
    stream, 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 own
    close 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 any Io error whose kind is not a
    vanished peer. Io is split by kind rather than lowered as a group, so a
    genuine failure of the connection is still reported as one.

Testing

  • http::tests::websocket_error_levels covers one representative per class,
    including both shapes a vanished peer arrives in and an Io error that must
    stay at error. The classification is a function over tungstenite::Error
    rather than warp::Error precisely so it is constructible in a test —
    warp::Error has no public constructor.
  • cargo check -p cubestore --lib --all-targets clean, cargo fmt applied.

…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.
@waralexrom
waralexrom requested a review from a team as a code owner September 6, 2026 14:25
@github-actions github-actions Bot added cube store Issues relating to Cube Store rust Pull requests that update Rust code labels Sep 6, 2026
@claude

claude Bot commented Sep 6, 2026

Copy link
Copy Markdown
Contributor

Claude finished @waralexrom's task in 1m 55s —— View job


Review: approach is sound — 1 medium (send path still logs vanished peers at error), 1 low (comment verbosity)

Full review
  • Read the diff (git show HEAD -- rust/cubestore/cubestore/src/http/mod.rs)
  • Verify the warp::Errortungstenite::Error downcast actually resolves
  • Check the classification against tungstenite 0.20 error variants
  • Review test coverage
  • Check comment density against repo guidance
  • Post inline comments

What's correct

The downcast holds: Cargo.lock pins a single tungstenite 0.20.1 shared by warp 0.3.6 and the direct tokio-tungstenite 0.20.1 dependency, so source().downcast_ref::<tungstenite::Error>() matches the same type. The pattern is already proven in message_too_large_reason (mod.rs:122). If those ever diverge, the fallback is Level::Error — the pre-PR behavior — so the failure mode is safe.

Splitting Io by ErrorKind rather than lowering the variant as a group is the right call, and the _ => Level::Error default means a new tungstenite variant is loud rather than silently swallowed. Match-arm ordering is unambiguous (the two Protocol(..) arms don't overlap). log::log!(level, ...) is used correctly, and websocket_error_level is only reached in the None branch of message_too_large_reason, so the too-large path keeps its dedicated handling.

The test compiles against use super::* (which supplies tungstenite, ProtocolError, Level, io), covers both shapes of a vanished peer plus two must-stay-error cases, and testing over tungstenite::Error instead of warp::Error is the right factoring given warp::Error has no public constructor. ProtocolError::InvalidOpcode(u8) and ResetWithoutClosingHandshake both exist in 0.20.

No security or performance concerns — this is a pure log-level classification with no allocation on the hot path and no change to what is logged.

Findings

# 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.

· branch [`cubestore-websocket-reset-log-level`](https://github.com/cube-js/cube/tree/cubestore-websocket-reset-log-level)

}
None => error!("Websocket error: {:?}", e),
None => log::log!(
websocket_error_level(&e),

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

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 →

Comment on lines +155 to +166
/// 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.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

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

codecov Bot commented Sep 6, 2026

Copy link
Copy Markdown

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 60.11%. Comparing base (9237c26) to head (665f691).
⚠️ Report is 7 commits behind head on master.

❗ There is a different number of reports uploaded between BASE (9237c26) and HEAD (665f691). Click for more details.

HEAD has 1 upload less than BASE
Flag BASE (9237c26) HEAD (665f691)
cubesql 1 0
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     
Flag Coverage Δ
cube-backend 60.11% <ø> (?)
cubesql ?

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

cube store Issues relating to Cube Store rust Pull requests that update Rust code

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant