feat(retry): WA Web log-level parity and retry-flow observability counters - #887
Conversation
The MAX_RETRY cap refusal is a remote-driven, expected and fully-handled condition (the requester's own count attribute reached 5). WA Web emits it via WALogger.LOG (informational, level 2), not WARN (level 3) — see WAWebHandleRetryRequest. It dominated the WARN budget in production logs (23 of 25) despite being benign. debug! also matches the sibling receive-side path (message/retry.rs already logs the capped case at debug).
The base-key collision branch forced a fresh session at warn!, while the three sibling branches of update_local_signal_session (regId-mismatch delete, base-key save, base-key changed) already log at info. WA Web logs this same-base-key delete via WALogger.LOG, not WARN, so info restores both internal and oracle parity. Also thread message_id into both base-key log lines: the collision is keyed by (address, message_id), so the id makes the event correlatable to a specific message during a retry storm.
WA Web emits the MessageHighRetryCount WAM event (id 3132) from the send-receipt path when retryCount >= MAX (5). The lib had no aggregate signal for this. Add a wa_high_retry_total counter (labelled by retry reason, low-cardinality, PII-safe) emitted from the requester side (run_retry_receipt) at the same watermark. Zero-cost when the metrics feature is off (no-op sibling).
WA Web emits the MdRetryFromUnknownDevice WAM event (id 2178) when a retry receipt arrives from a device that hasDevice() reports as unknown, tagged primary vs companion. The lib's responder side had no aggregate signal. Add a wa_retry_unknown_device_total counter at the same site (the !device_known branch in handle_retry_receipt), labelled by sender type. Placed at the retry call-site, not inside schedule_unknown_device_sync, since that helper is also driven by the shared inbound path and would over-count.
The two responder-side retry health events were log-only, so measuring the refuse/total ratio or spotting a chronically thrashing peer in aggregate needed log scraping. Add wa_retry_refused_total (at the MAX_RETRY guard) and wa_base_key_collision_total (at the forced-fresh-session branch). WA Web logs both via WALogger.LOG rather than a dedicated WAM, so these are health counters consistent with that, not a direct WAM port. Zero-cost when off.
The wa.retry.handle_receipt span already carries chat and sender but not the retry count, and the cap path returns early before any other field is set, so storm depth was invisible to span aggregation. Record count right after the parse (field::Empty + Span::record, the established pattern), gated on the tracing feature. PII-safe; no behavior change.
|
@coderabbitai review |
|
✅ Action performedReview finished.
|
|
@claude review |
|
Claude finished @jlucaso1's task in 2m 37s —— View job Code ReviewI've read the three changed files, cross-checked the placement claims against the rest of the tree, and verified the cardinality of the new labels. TL;DR: ship it. This is a tight, well-scoped, behavior-neutral PR. Log levels are justified against both the WA Web oracle citations and the lib's own precedent; the four counters are correctly placed, low-cardinality, PII-safe, and zero-cost when Findings checklist
Correctness
|
✅ Action performedReview finished.
|
|
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 (1)
📝 WalkthroughSummary by CodeRabbit
WalkthroughFour new telemetry counter functions ( ChangesRetry Telemetry Instrumentation
Estimated code review effort🎯 2 (Simple) | ⏱️ ~10 minutes Possibly related PRs
🚥 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 |
📦 Binary size report
.text per crate
Top movers (cargo-bloat attribution)
Baseline: |
![coderabbitai[bot]](https://avatars.githubusercontent.com/in/347564?s=60&v=4){kind=small}
WAWebHandleMsgSendReceipt awaits sendRetryReceipt and only then calls maybePostMessageHighRetryCountMetric (a sequence expression after the yield), so WA Web commits the high-retry metric on a sent receipt, not on intent. Move wa_high_retry_total into the Ok arm of send_retry_receipt, next to the wa_retry_receipt_total sibling, so a failed send no longer counts and the two adjacent counters share the same success semantics. Surfaced by the PR review cross-checking the metric's call site against the oracle.
1 participant
What
Two threads, one commit per change.
Log levels (2 commits): two retry-flow
warn!s that fire for benign, remote-driven, fully-handled conditions move to the level WA Web uses for them.Refusing retry #N ... exceeds max attempts(the MAX_RETRY loop guard) goes todebug!, andBase key collision ... Forcing fresh sessiongoes toinfo!. The collision line and itsBase key changedsibling also start carrying themessage_id.Observability (4 commits): four low-cardinality, PII-safe, zero-cost-when-off counters on the retry flow, plus the retry count recorded on the existing receipt span.
Why
This came out of triaging ~14h of production logs from a group bot. The fleet was healthy (0 ERROR, 0 panic, 0 stanza errors), but the entire WARN budget was 25 lines of exactly two kinds, both produced by a single peer device thrashing prekeys during one group send. It was remote-driven and fully contained by the existing defenses (the MAX_RETRY cap, the per-chat resend rate limiter, the SKDM gate, base-key collision detection); the message was delivered and no ban occurred. A cross-model review (Codex/GPT-5.5) verified the oracle citations independently before this PR.
The core finding is that WA Web emits both of those conditions via
WALogger.LOG(level 2, informational), notWARN(level 3):WAWebHandleRetryRequestlogs theretryCount >= MAX_RETRY(5) refusal viaWALogger.LOG, and reservesWARNin the same module for real errors (no-requester, device-not-found).WAWebUpdateLocalSignalSessionlogs the same-base-key session delete viaWALogger.LOG.WAWebLogger:LOGis level 2,WARNis level 3.debug!(rather thaninfo!) for the cap matches the lib's own precedent for a frequent, expected, remote-driven event: the mirror receive-side capped-retry path inmessage/retry.rsalready logs atdebug!, anddecrypt_fail_log_leveldowngrades expected fan-out failures to debug to avoid WARN spam.info!for the collision matches the three sibling branches ofupdate_local_signal_session, which already log at info. Themessage_idis added because the collision is keyed by(address, message_id), so the id makes the event correlatable to a specific message during a storm.On observability: WA Web emits two dedicated WAM events on this flow that the lib had no aggregate equivalent for.
MessageHighRetryCount(id 3132, committed atretryCount >= 5from the send-receipt path) maps towa_high_retry_total, andMdRetryFromUnknownDevice(id 2178, committed when a retry arrives from a device not in our registry, tagged primary vs companion) maps towa_retry_unknown_device_total, placed at the retry call-site rather than insideschedule_unknown_device_sync(which the shared inbound path also drives, so it would over-count). Two more counters cover the responder events WA Web only logs and has no dedicated WAM for:wa_retry_refused_totalandwa_base_key_collision_total, so a chronically thrashing peer shows up in aggregate instead of via log scraping. All four are off by default and compile to no-ops without themetricsfeature. The span change records the retrycountso storm depth is aggregable per sender even when the cap returns early.What this PR deliberately leaves out
The retry logic itself is verbatim parity with the oracle and is untouched: the cap value and comparator, the base-key save/compare/delete, and the recovery path all stay as-is. Two latent parity divergences the review surfaced (peer regId-mismatch without
<keys>, and offline-gating of the destructive key-bundle path) are intentionally not addressed here: both have zero occurrences in the analyzed logs, carry moderate regression risk on session recovery, and deserve a separate decision.Tests
cargo clippy --all-targets -- -D warningsis clean both at default (no-op telemetry, tracing off) and with--features metrics,tracing(real counters plus the span field).cargo test -p wacore --lib(991) andcargo test -p whatsapp-rust --lib(827) pass.There is no behavior change: every line is a log level, an added log field, a counter increment, or a span field.