fix(conn): log benign server recycles quietly without hiding real errors - #785
Merged
Conversation
Prod logs show the only recurring WARNs are benign connection recycles: the
WhatsApp server periodically drops the stream (clean EOF or <xmlstreamend/>)
and we reconnect, but each one logged WARN 'Message loop exited with an error'
+ 'treating as disconnect', and a keepalive firing mid-teardown logged WARN
'Keepalive ping failed: NotConnected'. These are routine, not errors, and the
noise buries genuine failures.
Classify the log level by cause, never the behavior (we still reconnect and
dispatch Event::Disconnected):
- Add DisconnectReason::is_clean_shutdown() — clean EOF / normal-or-absent close
code are quiet; a ReadError, an abnormal close code, or an unreported reason
stay loud. Deliberately conservative: anything ambiguous stays loud.
- Read loop logs a clean disconnect at info, a real one at warn (was a generic
debug + a lifecycle WARN); lifecycle's generic WARN drops to debug since the
read loop now owns the classified, reason-bearing message.
- <xmlstreamend/> (a clean server stream end) logs at info, not warn.
- Keepalive: a fatal-classified failure (connection already gone, e.g.
NotConnected) logs at debug; a transient one (timeout / bad response) stays warn.
Tests cover both paths so real errors are never hidden: is_clean_shutdown
classifies StreamEnded / ServerClose{1000,1001,None} clean and ReadError /
abnormal codes / Unknown not-clean; the existing keepalive classify tests pin
Timeout->Transient (loud) and NotConnected->Fatal (quiet).
Keep the benign transport-channel-close visible (info) rather than burying it at debug after the lifecycle WARN was dropped — it has no DisconnectReason so we can't prove it clean, but it isn't a read error either.
|
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Repository UI Review profile: ASSERTIVE Plan: Pro Plus Run ID: 📒 Files selected for processing (2)
📝 WalkthroughSummary by CodeRabbit
WalkthroughThis PR adds DisconnectReason::is_clean_shutdown() to identify benign server stream recycling and updates read loop, Client::run, and send_keepalive to lower log verbosity for clean teardowns while preserving existing reconnect/error-return behavior. ChangesClean shutdown classification and reconnect logging
Sequence DiagramsequenceDiagram
participant node_io as read_messages_loop
participant lifecycle as Client::run
participant keepalive as send_keepalive
participant net as DisconnectReason
node_io->>net: is_clean_shutdown() on TransportEvent::Disconnected
net-->>node_io: true/false classification
node_io->>node_io: Log at info (clean) or warn (abnormal)
lifecycle->>node_io: await read_messages_loop()
node_io-->>lifecycle: Err(e) result
lifecycle->>lifecycle: Log at debug with error details
keepalive->>keepalive: Ping fails with error
keepalive->>keepalive: classify_keepalive_error()
keepalive->>keepalive: Log at debug (benign teardown) or warn (real failure)
Estimated code review effort🎯 3 (Moderate) | ⏱️ ~20 minutes Possibly related PRs
Suggested labels
🚥 Pre-merge checks | ✅ 5✅ Passed checks (5 passed)
✏️ Tip: You can configure your own custom pre-merge checks in the settings. ✨ 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 |
![chatgpt-codex-connector[bot]](https://avatars.githubusercontent.com/in/1144995?s=60&v=4){kind=small}
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 1832f6e357
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| // error), so keep this at debug to avoid re-flagging a benign | ||
| // reconnect as an error. Still treated as an unexpected | ||
| // disconnect for the event dispatch + reconnect below. | ||
| debug!("Message loop exited, will reconnect if enabled: {e:#}"); |
There was a problem hiding this comment.
When the transport event channel closes without delivering a Disconnected event, read_messages_loop takes the Err(_) branch in src/client/node_io.rs and only emits a debug message before returning Err("Transport event channel closed"). This new generic debug log is therefore the only record of that unexpected disconnect, so custom/buggy transports that drop the sender without a reason will reconnect and dispatch Disconnected without any warn/error even though the cause was not classified as clean.
Useful? React with 👍 / 👎.
Comment on lines
+99
to
+100
| KeepaliveResult::FatalFailure => { | ||
| debug!(target: "Client/Keepalive", "Keepalive skipped, connection already closing: {e:?}"); |
There was a problem hiding this comment.
This debug branch now covers every FatalFailure, but classify_keepalive_error maps more than teardown cases to fatal, including IqError::Socket(_), EncryptSend(_), ClientState(_), InternalChannelClosed, and EncodeError(_). If a keepalive ping fails because the socket/send pipeline breaks while the client still thinks it is connected, this becomes the only keepalive log before the loop exits, so a real connection/send failure is hidden at debug instead of staying loud.
Useful? React with 👍 / 👎.
Benchmark Results67 unchanged benchmark(s)
|
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
There was a problem hiding this comment.
Caution
Some comments are outside the diff and can’t be posted inline due to platform limitations.
⚠️ Outside diff range comments (1)
src/keepalive.rs (1)
91-109:⚠️ Potential issue | 🟡 Minor | ⚡ Quick winRemove unreachable pattern arm.
Look, at line 102, you're matching
KeepaliveResult::Okin the error handling branch. We're insideErr(e)from line 91, andclassify_keepalive_errorcan only returnFatalFailureorTransientFailurebased on lines 31-46. TheOkvariant is impossible here—it only appears in the success path at line 89. This is dead code that could confuse engineers debugging keepalive failures.🔧 Proposed fix
- KeepaliveResult::TransientFailure | KeepaliveResult::Ok => { + KeepaliveResult::TransientFailure => { warn!(target: "Client/Keepalive", "Keepalive ping failed: {e:?}"); }🤖 Prompt for 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. In `@src/keepalive.rs` around lines 91 - 109, The match in the Err(e) branch calls classify_keepalive_error(&e) but includes a KeepaliveResult::Ok arm which is impossible there; update the match over the result from classify_keepalive_error to only handle KeepaliveResult::FatalFailure and KeepaliveResult::TransientFailure (or replace the Ok arm with a wildcard that panics/unreachable), referencing the classify_keepalive_error call and the KeepaliveResult enum so the unreachable KeepaliveResult::Ok arm is removed from the error-handling path.
🤖 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.
Outside diff comments:
In `@src/keepalive.rs`:
- Around line 91-109: The match in the Err(e) branch calls
classify_keepalive_error(&e) but includes a KeepaliveResult::Ok arm which is
impossible there; update the match over the result from classify_keepalive_error
to only handle KeepaliveResult::FatalFailure and
KeepaliveResult::TransientFailure (or replace the Ok arm with a wildcard that
panics/unreachable), referencing the classify_keepalive_error call and the
KeepaliveResult enum so the unreachable KeepaliveResult::Ok arm is removed from
the error-handling path.
ℹ️ Review info
⚙️ Run configuration
Configuration used: Repository UI
Review profile: ASSERTIVE
Plan: Pro Plus
Run ID: b29fbf97-c7c8-44b1-9d10-f10f38144052
📒 Files selected for processing (4)
src/client/lifecycle.rssrc/client/node_io.rssrc/keepalive.rswacore/src/net.rs
Address two review findings on the disconnect log-classification change so it never hides a real error behind reconnect noise. keepalive: the log level was keyed on the FatalFailure classification, which also covers Socket/EncryptSend/ClientState/EncodeError. Those are fatal for control flow but mean the socket or send pipeline broke while we still believed we were connected, so the keepalive may be the first thing to see them. Key the log level on a narrower is_benign_teardown (NotConnected/Disconnected/channel closed only) instead, so only an already-gone connection is quiet. node_io: the event-channel-closed branch carries no DisconnectReason, so we can't prove it was a clean recycle. Raise it from info to warn to match the conservative Unknown rule in is_clean_shutdown. Adds bad/happy path tests for is_benign_teardown.
3 tasks
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
The prod logs (last 3 days) show the only recurring WARN/ERROR are benign connection recycles: the WhatsApp server periodically drops the stream (a clean EOF, or a
<xmlstreamend/>) and we reconnect within ~1s and re-auth fine — but each one was logged asWARN "Message loop exited with an error"+WARN "Received <xmlstreamend/>, treating as disconnect", and a keepalive ping firing during teardown loggedWARN "Keepalive ping failed: NotConnected". ~4-5 of these a day, 0 real errors. The noise would bury a genuine failure.This changes only the log level, never the behavior — we still reconnect and still dispatch
Event::Disconnected. The guiding rule is to never hide a real error:DisconnectReason::is_clean_shutdown(): a clean EOF (StreamEnded) or a Close frame with a normal/going-away/absent code is quiet; aReadError, an abnormal close code, or an unreported (Unknown) reason stay loud. Deliberately conservative — anything ambiguous returnsfalse(loud).infoand a real one atwarn(previously a genericdebughere plus a genericwarnin the lifecycle). The lifecycle's generic "Message loop exited"warndrops todebug, since the read loop now owns the classified, reason-bearing message.<xmlstreamend/>(a clean server stream end) logs atinfo.NotConnected) logs atdebug(it's teardown collateral; the disconnect itself is logged by the read loop); a transient failure (timeout / unexpected response) stays atwarn.Not hiding real errors — tested both ways
net.rs:clean_shutdowns_are_classified_clean(StreamEnded, ServerClose{1000,1001,None} → clean/quiet) andreal_errors_are_never_classified_clean(ReadError, Unknown, and codes 1002/1006/1011/1012/1013/3000/4000 → not clean/loud).test_classify_timeout_is_transient(real keepalive failure → Transient → stayswarn) andtest_classify_not_connected_is_fatal(benign → Fatal →debug).Internal logging change only;
DisconnectReasongains a method (no field/variant change), e2e compiles unchanged.