From 9d79bbe35168c2ab25228d72aa1631f9f6aac3fd Mon Sep 17 00:00:00 2001 From: Renato Alcara Date: Thu, 30 Apr 2026 12:40:02 -0300 Subject: [PATCH] perf(logs): silence MessageCounterError + slim stanza dump on handler errors MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Following PR #402 / fix/silence-decrypt-error-spam, prod logs still showed two heavy stdout-saturation sources that survived the previous pass: 1) auth-utils.ts:353 — `transaction failed, rolling back` fired at ERROR level for every `MessageCounterError` ("Key used already or never filled"). Only `SessionError` was downgraded. Under WhatsApp's LID/DSM rollout, own DSM messages flood with MessageCounterError when the auth state has a legacy `_1.0` session that no longer matches the LID-addressed envelope. ~30+ JSON ERROR lines per minute hit stdout. 2) messages-recv.ts:2698 — `error in handling message` logged the FULL stanza XML via `binaryNodeToString(node)`. Each stanza contains the inline encrypted ciphertext — kilobytes per log entry. Under load (e.g. downstream consumer throws on every Bad MAC), this is THE biggest single source of stdout pressure. Pedro's snapshot doesn't have these specifically — its libsignal failures fall through to upstream's leaner logging path. THIS PATCH: - auth-utils: extend the recoverable-error downgrade to MessageCounterError too (same recovery path: retry receipt → pkmsg → new session). Both now log at debug; everything else still ERRORs. - messages-recv: log a SLIM node projection (tag + id + from + type + participant) at error level. Full stanza XML moved to debug. Operators retain enough to pivot to the offending message; investigations via BAILEYS_LOG_LEVEL=debug still get the full payload. Co-Authored-By: Claude Opus 4.7 (1M context) --- src/Socket/messages-recv.ts | 15 ++++++++++++++- src/Utils/auth-utils.ts | 16 +++++++++------- 2 files changed, 23 insertions(+), 8 deletions(-) diff --git a/src/Socket/messages-recv.ts b/src/Socket/messages-recv.ts index 970f511c..029a81fb 100644 --- a/src/Socket/messages-recv.ts +++ b/src/Socket/messages-recv.ts @@ -2695,7 +2695,20 @@ export const makeMessagesRecvSocket = (config: SocketConfig) => { } }) } catch (error) { - logger.error({ error, node: binaryNodeToString(node) }, 'error in handling message') + // Slim log: identify the message that crashed without dumping the full + // stanza XML (which contains kilobytes of inline ciphertext). Under heavy + // load — e.g. a downstream consumer that throws on every Bad MAC — the + // full XML dumps overwhelm stdout and stall the event loop. Operators + // can still pivot on msgId / from / type; full payload at debug level. + const slimNode = { + tag: node.tag, + id: node.attrs?.id, + from: node.attrs?.from, + type: node.attrs?.type, + participant: node.attrs?.participant + } + logger.error({ error, node: slimNode }, 'error in handling message') + logger.debug({ node: binaryNodeToString(node) }, 'error in handling message — full stanza') } } diff --git a/src/Utils/auth-utils.ts b/src/Utils/auth-utils.ts index adabf548..203dbefc 100644 --- a/src/Utils/auth-utils.ts +++ b/src/Utils/auth-utils.ts @@ -341,14 +341,16 @@ export const addTransactionCapability = ( return result } catch (error) { - // SessionError is part of the normal Bad MAC recovery flow - // (retry receipt → sender resends as pkmsg → new session within ~1.3s). - // Logging it as ERROR creates 2 noise lines per recoverable Bad MAC cycle. - // Downgrade to debug for SessionError; keep ERROR for everything else. - // The error is still re-thrown — recovery behavior is unchanged. + // SessionError / MessageCounterError are part of the normal Bad MAC + // recovery flow (retry receipt → sender resends as pkmsg → new session + // within ~1.3s). Logging them as ERROR creates 2 noise lines per + // recoverable cycle, and under WhatsApp's LID/DSM rollout these fire + // in dense bursts that saturate stdout (synchronous pm2 writes block + // the event loop). Downgrade to debug for both; keep ERROR for + // everything else. The error is still re-thrown — recovery is unchanged. const errName = (error as { name?: string })?.name - if (errName === 'SessionError') { - logger.debug({ error }, 'transaction failed (SessionError — recoverable via retry receipt)') + if (errName === 'SessionError' || errName === 'MessageCounterError') { + logger.debug({ error }, `transaction failed (${errName} — recoverable via retry receipt)`) } else { logger.error({ error }, 'transaction failed, rolling back') }