diff --git a/src/client/lifecycle.rs b/src/client/lifecycle.rs index 609c67ce9..8c6fcfe02 100644 --- a/src/client/lifecycle.rs +++ b/src/client/lifecycle.rs @@ -340,38 +340,50 @@ impl Client { } else { wacore::telemetry::connect("ok"); let loop_result = self.read_messages_loop().await; - let unexpected_disconnect = if let Err(e) = loop_result { - // Check intentional_reconnect AFTER read loop exits — reconnect() - // sets this flag while the loop is running, so it must be read here. - if self.expected_disconnect.load(Ordering::Relaxed) - || self.intentional_reconnect.swap(false, Ordering::Relaxed) - { - debug!("Message loop exited during expected disconnect."); - false - } else { - // read_messages_loop already logged the cause at the right level - // (info for a clean server recycle, warn for a real transport - // 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:#}"); - true + // Consume intentional_reconnect on EVERY exit, reading it AFTER the loop + // ends (reconnect() sets it while the loop runs, then tears down via the + // shutdown signal — the Expected path). Consuming it only on some paths + // left it stale for the next connection, misclassifying the next genuine + // disconnect as intentional and swallowing its Disconnected event. + let intentional = self.intentional_reconnect.swap(false, Ordering::Relaxed); + // Some(reason) = unexpected disconnect worth a `Disconnected` event; the + // reason distinguishes a routine server recycle from a real failure so + // consumers don't have to. + let unexpected_disconnect = match loop_result { + Ok(super::node_io::ReadLoopExit::Expected) => { + debug!("Message loop exited gracefully (expected disconnect)."); + None + } + Ok(super::node_io::ReadLoopExit::ServerRecycle(reason)) => { + if self.expected_disconnect.load(Ordering::Relaxed) || intentional { + debug!("Message loop exited during expected disconnect."); + None + } else { + // read_messages_loop already logged this at info; a clean + // recycle stays quiet here too. + Some(reason) + } + } + Err(e) => { + if self.expected_disconnect.load(Ordering::Relaxed) || intentional { + debug!("Message loop exited during expected disconnect."); + None + } else { + // read_messages_loop already logged the cause at warn; keep + // this at debug to avoid double-reporting. + debug!("Message loop exited, will reconnect if enabled: {e:#}"); + Some(e.into_reason()) + } } - } else if self.expected_disconnect.load(Ordering::Relaxed) { - debug!("Message loop exited gracefully (expected disconnect)."); - false - } else { - info!("Message loop exited gracefully."); - false }; self.cleanup_connection_state().await; // Dispatch after cleanup so handlers see cleared connection state. - if unexpected_disconnect { - self.core - .event_bus - .dispatch(Event::Disconnected(crate::types::events::Disconnected)); + if let Some(reason) = unexpected_disconnect { + self.core.event_bus.dispatch(Event::Disconnected( + crate::types::events::Disconnected { reason }, + )); } } @@ -417,11 +429,25 @@ impl Client { Box::pin(self.connect_graph()) } + // err(level = "warn", ...): run()'s caller already classifies failures here itself + // (debug! for a transient HandshakeError worth a quiet retry, error! otherwise — see + // run()'s connect_err handling) — the default ERROR level on this span ignored that + // and turned every transient handshake retry into its own GlitchTip issue. A genuine + // failure still surfaces via that caller's error! call, independent of this span's level. #[cfg_attr( feature = "tracing", - tracing::instrument(name = "wa.conn.connect", level = "info", skip_all, err(Debug)) + tracing::instrument( + name = "wa.conn.connect", + level = "info", + skip_all, + fields(lid = tracing::field::Empty, pn = tracing::field::Empty), + err(level = "warn", Debug) + ) )] async fn connect_graph(self: &Arc) -> Result<(), anyhow::Error> { + #[cfg(feature = "tracing")] + self.record_identity_on_span(&tracing::Span::current()); + if self.is_connecting.swap(true, Ordering::SeqCst) { return Err(ClientError::AlreadyConnected.into()); } diff --git a/src/client/node_io.rs b/src/client/node_io.rs index 527d26025..069ed2b65 100644 --- a/src/client/node_io.rs +++ b/src/client/node_io.rs @@ -1,6 +1,40 @@ //! Inbound node I/O: read loop, frame decryption, node routing, acks and stream errors. use super::*; +use wacore::net::DisconnectReason; + +/// Non-error exits of [`Client::read_messages_loop`] — `ServerRecycle` keeps the +/// routine reconnect path out of `Err`, so severity consumers (logs, the span's +/// `err(...)` capture, error trackers) only fire for genuine failures. +pub(crate) enum ReadLoopExit { + /// Shutdown signal or an expected disconnect. + Expected, + /// Server ended the stream cleanly (the routine WhatsApp reconnect path). + ServerRecycle(DisconnectReason), +} + +/// Genuine failures of [`Client::read_messages_loop`] — everything here is worth +/// reporting loudly, unlike [`ReadLoopExit`]. +#[derive(Debug, thiserror::Error)] +pub(crate) enum ReadLoopError { + #[error("cannot start message loop: {0}")] + NotStarted(&'static str), + #[error("transport disconnected: {0}")] + Transport(DisconnectReason), + #[error("transport event channel closed")] + ChannelClosed, +} + +impl ReadLoopError { + /// The disconnect reason to surface on the `Disconnected` event; failures + /// that carry none map to `Unknown` (conservative, matches `is_clean_shutdown`). + pub(crate) fn into_reason(self) -> DisconnectReason { + match self { + Self::Transport(reason) => reason, + Self::NotStarted(_) | Self::ChannelClosed => DisconnectReason::Unknown, + } + } +} impl Client { /// Read the current semaphore generation and Arc atomically under the mutex. @@ -30,17 +64,32 @@ impl Client { .fetch_add(1, Ordering::SeqCst); } + // err(...) stays at the default ERROR on purpose: with the routine server + // recycle moved to Ok(ServerRecycle), an Err from this loop now always means + // something genuinely wrong — so the automatic capture only ever reports + // real failures, not WhatsApp's periodic stream recycling. #[cfg_attr( feature = "tracing", - tracing::instrument(name = "wa.conn.read_loop", level = "debug", skip_all, err(Debug)) + tracing::instrument( + name = "wa.conn.read_loop", + level = "debug", + skip_all, + fields(lid = tracing::field::Empty, pn = tracing::field::Empty), + err(Debug) + ) )] - pub(crate) async fn read_messages_loop(self: &Arc) -> Result<(), anyhow::Error> { + pub(crate) async fn read_messages_loop( + self: &Arc, + ) -> Result { + #[cfg(feature = "tracing")] + self.record_identity_on_span(&tracing::Span::current()); + debug!("Starting message processing loop..."); let mut rx_guard = self.transport_events.lock().await; let transport_events = rx_guard .take() - .ok_or_else(|| anyhow::anyhow!("Cannot start message loop: not connected"))?; + .ok_or(ReadLoopError::NotStarted("not connected"))?; drop(rx_guard); // The noise socket is installed before this loop starts (connect_internal) @@ -49,7 +98,7 @@ impl Client { let noise_socket = self .get_noise_socket() .await - .map_err(|_| anyhow::anyhow!("Cannot start message loop: no noise socket"))?; + .map_err(|_| ReadLoopError::NotStarted("no noise socket"))?; // Frame decoder to parse incoming data let mut frame_decoder = wacore::framing::FrameDecoder::new(); @@ -64,7 +113,7 @@ impl Client { futures::select_biased! { _ = shutdown_fut => { debug!("Shutdown signaled in message loop. Exiting message loop."); - return Ok(()); + return Ok(ReadLoopExit::Expected); }, event_result = transport_events.recv().fuse() => { match event_result { @@ -113,7 +162,7 @@ impl Client { // Check if we should exit after processing (e.g., after 515 stream error) if self.expected_disconnect.load(Ordering::Relaxed) { debug!("Expected disconnect signaled during frame processing. Exiting message loop."); - return Ok(()); + return Ok(ReadLoopExit::Expected); } // Cooperative yield — frequency and behavior are runtime-defined. @@ -138,18 +187,18 @@ impl Client { }, Ok(crate::transport::TransportEvent::Disconnected(reason)) => { if !self.expected_disconnect.load(Ordering::Relaxed) { - // Classify the level: a routine server recycle (clean EOF / - // normal close) is logged quietly, but a real transport error - // stays at WARN so it's never hidden behind reconnect noise. + // A routine server recycle (clean EOF / normal close) is not + // an error — quiet log, Ok exit. A real transport error stays + // WARN + Err so it's never hidden behind reconnect noise. if reason.is_clean_shutdown() { info!("Connection closed by server ({reason}); reconnecting."); - } else { - warn!("Transport disconnected: {reason}; reconnecting."); + return Ok(ReadLoopExit::ServerRecycle(reason)); } - return Err(anyhow::anyhow!("Transport disconnected: {reason}")); + warn!("Transport disconnected: {reason}; reconnecting."); + return Err(ReadLoopError::Transport(reason)); } else { debug!("Transport disconnected as expected: {reason}"); - return Ok(()); + return Ok(ReadLoopExit::Expected); } } // Event channel closed (no DisconnectReason available) — the @@ -159,9 +208,9 @@ impl Client { Err(_) => { if !self.expected_disconnect.load(Ordering::Relaxed) { warn!("Transport event channel closed; reconnecting."); - return Err(anyhow::anyhow!("Transport event channel closed")); + return Err(ReadLoopError::ChannelClosed); } else { - return Ok(()); + return Ok(ReadLoopExit::Expected); } } Ok(crate::transport::TransportEvent::Connected) => { diff --git a/src/transport.rs b/src/transport.rs index 4d383ee84..a21cdbf5c 100644 --- a/src/transport.rs +++ b/src/transport.rs @@ -1,5 +1,5 @@ // Re-export transport types from wacore -pub use wacore::net::{Transport, TransportEvent, TransportFactory}; +pub use wacore::net::{DisconnectReason, Transport, TransportEvent, TransportFactory}; #[cfg(feature = "tokio-transport")] pub use whatsapp_rust_tokio_transport::{ diff --git a/wacore/src/net.rs b/wacore/src/net.rs index 9cb8788b9..6d4bd09bf 100644 --- a/wacore/src/net.rs +++ b/wacore/src/net.rs @@ -10,7 +10,12 @@ pub const WHATSAPP_WEB_WS_URL: &str = "wss://web.whatsapp.com/ws/chat"; /// Why the transport connection ended. Lets a benign server-initiated stream /// recycle (a clean Close frame) be told apart from an abrupt EOF or a real /// read error when diagnosing reconnect behavior. -#[derive(Debug, Clone)] +/// +/// Serialize: carried by `events::Disconnected`, whose payload consumers forward +/// as JSON (webhooks, dashboards) — snake_case so the wire shape doesn't leak +/// Rust variant naming. +#[derive(Debug, Clone, serde::Serialize)] +#[serde(rename_all = "snake_case")] pub enum DisconnectReason { /// The peer sent a WebSocket Close frame. `code` is the RFC 6455 close /// code (1000 = normal closure); `reason` is the optional UTF-8 text. diff --git a/wacore/src/types/events.rs b/wacore/src/types/events.rs index 727e424e2..395369fac 100755 --- a/wacore/src/types/events.rs +++ b/wacore/src/types/events.rs @@ -998,7 +998,12 @@ pub struct StreamError { } #[derive(Debug, Clone, Serialize)] -pub struct Disconnected; +pub struct Disconnected { + /// Why the transport ended — lets consumers tell a routine server stream + /// recycle (`reason.is_clean_shutdown()`) from a genuine transport failure + /// without parsing logs. + pub reason: crate::net::DisconnectReason, +} #[derive(Debug, Clone, Serialize)] pub struct OfflineSyncPreview {