fix(keepalive): anchor dead-socket watchdog to first send, not last - #995
Conversation
…t the last is_dead_socket measured elapsed since last_data_sent_ms, which record_frame_sent overwrites on every outgoing frame. On a half-open socket (peer gone, writes buffer, reads hang) any app frame landing inside the 20s window kept ms_since(last_sent) < 20s, so the watchdog — the only steady-state reconnect trigger — never fired while the app kept emitting traffic (~every 10-18s). WA Web's deadSocketTimer.onOrBefore keeps the EARLIEST armed deadline: the first send after a receive arms a 20s deadline and later sends never push it back; parseAndHandleStanza cancels it. Track that anchor: a new first_send_since_recv_ms set only on the first send after a receive (CAS 0->now) and reset to 0 on any receive, and evaluate is_dead_socket against it.
|
You have reached your Codex usage limits for code reviews. You can see your limits in the Codex usage dashboard. |
|
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Repository UI (base), Organization UI (inherited) Review profile: ASSERTIVE Plan: Pro Plus Run ID: 📒 Files selected for processing (1)
📝 WalkthroughSummary by CodeRabbit
WalkthroughThe keepalive watchdog now anchors dead-socket timing on the first outbound send since the last receive. ChangesDead socket watchdog anchor rework
Estimated code review effort: 3 (Moderate) | ~20 minutes Sequence Diagram(s)sequenceDiagram
participant KeepaliveLoop
participant SessionStats
participant IsDeadSocket
KeepaliveLoop->>SessionStats: first_send_since_recv_ms()
SessionStats-->>KeepaliveLoop: armed_ms
KeepaliveLoop->>IsDeadSocket: is_dead_socket(armed_ms, last_received_ms)
IsDeadSocket-->>KeepaliveLoop: dead or alive
Possibly related PRs
Suggested labels: 🚥 Pre-merge checks | ✅ 5✅ Passed checks (5 passed)
✨ Finishing Touches🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
There was a problem hiding this comment.
Actionable comments posted: 1
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@wacore/src/stats.rs`:
- Around line 108-118: The arming path in stats.rs reads the clock twice on the
first send, once for the sent timestamp and again in the compare_exchange for
first_send_since_recv_ms. Update the send/arm logic in the relevant stats method
so it captures Self::now_ms() once, reuses that same timestamp for both
last_data_sent_ms and the first-send anchor, and keeps the existing CAS
gate/arm-once behavior intact.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Repository UI (base), Organization UI (inherited)
Review profile: ASSERTIVE
Plan: Pro Plus
Run ID: c0c2684a-5e94-4ac5-8851-915076008242
📒 Files selected for processing (3)
src/keepalive.rswacore/src/protocol/keepalive.rswacore/src/stats.rs
📦 Binary size report
.text per crate
Baseline: |
There was a problem hiding this comment.
2 issues found across 3 files
Confidence score: 4/5
- The biggest risk is test flakiness in
wacore/src/stats.rs: the regression test depends on a 2ms sleep and a strict>millisecond check, which can fail on coarse clocks or busy CI and create noisy red builds despite correct behavior — make the assertion tolerant (e.g.,>=or a larger/mocked time advance) before merging. - Also in
wacore/src/stats.rs, the arming-send path callsnow_ms()twice (forlast_data_sent_msandcompare_exchange), so a 1ms skew can record inconsistent timestamps for one logical event and slightly distort stats behavior — readnow_ms()once and reuse that value in both places before merging.
Reply with feedback, questions, or to request a fix.
Re-trigger cubic
…lake test Reuse one now_ms() for both last_data_sent_ms and the first-send CAS so they share the same instant. Shorten the field doc to why-only. Drop the test's clock-tick-dependent strict > asserts (flaky on coarse timers): the anchor-holds check stays == armed regardless of whether the clock ticked. (review feedback)
There was a problem hiding this comment.
1 issue found across 1 file (changes from recent commits).
Reply with feedback, questions, or to request a fix.
Re-trigger cubic
…ng race The arm-once CAS could stick the anchor at a pre-receive timestamp: a send that loaded anchor==0 and captured `now`, then had a concurrent receive store its timestamp and reset the anchor to 0, would still win its compare_exchange and write the pre-receive `now`. Because the anchor was then non-zero, no later send re-armed it, and is_dead_socket's `last_received >= anchor` guard stayed true forever — silently disabling dead-socket detection for the rest of the connection. Re-arm whenever the anchor is unset OR stale (`anchor <= last_received`), so a send that lost the race self-heals on the next send instead of sticking.
Dismissed because a newer commit was pushed; Greptile will re-review the current head.
There was a problem hiding this comment.
0 issues found across 1 file (changes from recent commits).
Requires human review: Bug fix in dead-socket detection: changes anchor from last send to first send since last receive, adding new atomic field and updating is_dead_socket logic. Critical reconnect logic, requires human review.
Re-trigger cubic
What
Anchor the 20s dead-socket watchdog to the first send since the last receive, not the most-recent send.
Why (bug)
is_dead_socketmeasuredms_since(last_data_sent_ms), andrecord_frame_sentoverwriteslast_data_sent_mson every outgoing frame (via the single send chokepoint innoise_socket.rs). So on a half-open socket (peer silently gone, writes buffer, reads hang), any app frame — message/receipt/presence — landing inside the 20s window keepsms_since(last_sent) < 20s, and the watchdog returns false.Since
is_dead_socketis the only steady-state reconnect trigger (a pong timeout only bumps an unreaderror_count; a silently half-open TCP socket never surfaces a transport error), detection is suppressed for as long as the app keeps emitting traffic (~every 10–18s) — a stall / silent-loss window.WA Web's
deadSocketTimer.onOrBefore(WA/Shift/Timer.js) keeps the earliest armed deadline: the firstcallStanzaafter a receive arms a 20s deadline and subsequent sends never push it back;parseAndHandleStanza→cancel()clears it. The Rust port anchored on the last send — the exact divergence.How
SessionStats::first_send_since_recv_ms: set only on the first send after a receive (compare_exchange 0 -> now, so later sends don't move it) and reset to 0 on every receive (mark_recv_activity/record_recv_batch, and on teardown).is_dead_socketnow takes that anchor (armed_ms) instead of the last-send stamp; the keepalive loop feedsfirst_send_since_recv_ms().last_data_sent_msstays for its telemetry role.Tests
dead_socket_anchor_holds_across_continued_sends— the first send arms the anchor; continued sends keep it put (whilelast_data_sent_msadvances); a stale anchor with no receive since is detected as dead; a receive cancels it; the next send re-arms with a fresh instant.is_dead_socketpure tests still pass (signature/logic unchanged, param renamed).cargo fmt/clippyclean.