perf(logs): suppress libsignal console.warn — the missing piece of stdout flood

Following commits 1734d10209 + 9d79bbe351 the user reported pm2 logs were
STILL flooding and inbound latency persisted. Inspecting libsignal source
reveals 4 console.warn calls that bypass our existing log/info/error
interceptors:

  session_builder.js:74 → "Closing open session in favor of incoming prekey bundle"
  session_record.js:270 → "Session already closed", <session object>
  session_cipher.js:182 → "Decrypted message with closed session."
  queue_job.js:50      → "Unhandled bucket type (for naming):", <bucket>

Plus we were missing 2 console.info paths from session_record.js:
  - "Opening session:" (dumps the full session object)
  - "Migrating session to:" (per migration)

Under WhatsApp's LID/DSM rollout the pkmsg flow fires "Closing open session"
on EVERY incoming pkmsg (which is every recovery message from the user's own
phone after a Bad MAC). The user's log shows hundreds of these per session.
Each is a synchronous stdout.write. pm2's pipe buffer fills, write() blocks
the Node event loop, inbound delivery freezes for tens of seconds. Profile
pictures and IQ queries time out for the same reason — they need the loop
to dispatch them.

This is the same root cause as the historical Feb-27 fix (d233a7856f, "fix:
eliminate 40s message delivery delay caused by libsignal console dumps")
but the warn channel was overlooked.

THIS PATCH:
- Add console.warn interceptor with the same suppression regex.
- Extend the regex to cover the missing patterns (Opening session,
  Migrating session, Closing open session, Session already closed,
  Decrypted message with closed session, Unhandled bucket type).
- Operator-facing signal is unchanged — the console.error path still
  formats Bad MAC / Counter / Decryption Failed as the clean emoji line.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>

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')
 		}
 	}
 

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
+						// SessionError / MessageCounterError are part of the normal Bad MAC
-						// (retry receipt → sender resends as pkmsg → new session within ~1.3s).
+						// recovery flow (retry receipt → sender resends as pkmsg → new session
-						// Logging it as ERROR creates 2 noise lines per recoverable Bad MAC cycle.
+						// within ~1.3s). Logging them as ERROR creates 2 noise lines per
-						// Downgrade to debug for SessionError; keep ERROR for everything else.
+						// recoverable cycle, and under WhatsApp's LID/DSM rollout these fire
-						// The error is still re-thrown — recovery behavior is unchanged.
+						// 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') {
+						if (errName === 'SessionError' || errName === 'MessageCounterError') {
-							logger.debug({ error }, 'transaction failed (SessionError — recoverable via retry receipt)')
+							logger.debug({ error }, `transaction failed (${errName} — recoverable via retry receipt)`)
 						} else {
 							logger.error({ error }, 'transaction failed, rolling back')
 						}

src/Utils/decode-wa-message.ts

@@ -454,19 +454,40 @@ export const decryptMessageNode = (
 							...(isRetryExhausted && { retriesExhausted: true, attempts: err.attempts })
 						}
 
-						// Smart logging based on error type and retry status
+						// Smart logging based on error type and retry status.
+						//
+						// PERF NOTE: under WhatsApp's LID/DSM rollout, own DSM messages flood
+						// the inbound pipeline with Bad MAC / "Key used already" / "No session
+						// record" errors *every* time the auth state has a session in the
+						// legacy `_1.0` format that no longer matches the LID-addressed
+						// envelope. Logging the full errorContext (key + jid + err) per failed
+						// attempt as warn-level produces tens of JSON lines/sec, which
+						// saturates stdout in pm2 (synchronous writes to a full pipe block the
+						// event loop). The clean `🔐 Bad MAC Error | JID: …` line emitted by
+						// the console.error interceptor in src/index.ts already gives an
+						// operator-visible signal — the duplicated pino line was pure noise.
+						//
+						// We now only emit warn-level when retries are exhausted (rare,
+						// actionable). Per-attempt detail is still available at debug level
+						// (BAILEYS_LOG_LEVEL=debug) for active troubleshooting.
+						const slimErrorContext = {
+							msgId: fullMessage.key?.id,
+							jid: fullMessage.key?.remoteJid,
+							err: slimErr,
+							attempts: isRetryExhausted ? err.attempts : 1
+						}
+
 						if (isCorrupted) {
-							// Corrupted session errors are expected and auto-recovered
+							// Corrupted session errors are expected — Signal Protocol auto-recovers
-							// Only log as ERROR if retries exhausted, otherwise WARN on first attempt
+							// via retry receipt → pkmsg → new session.
 							// eslint-disable-next-line max-depth
 							if (isRetryExhausted) {
-								logger.error(
+								logger.warn(
-									errorContext,
+									slimErrorContext,
 									`⚠️ Session corrupted after ${err.attempts} attempts. Retry+pkmsg flow will recover.`
 								)
 							} else {
-								// First occurrence - log as warning since auto-recovery will attempt
+								logger.debug(errorContext, '⚠️ Corrupted session detected - attempting auto-recovery')
-								logger.warn(errorContext, '⚠️ Corrupted session detected - attempting auto-recovery')
 							}
 
 							// Session cleanup is deferred to retry exhaustion (safety net).
@@ -479,7 +500,7 @@ export const decryptMessageNode = (
 							// Session record errors are transient - retry should handle them
 							// eslint-disable-next-line max-depth
 							if (isRetryExhausted) {
-								logger.error(errorContext, `Failed to decrypt: No session record found after ${err.attempts} attempts`)
+								logger.warn(slimErrorContext, `Failed to decrypt: No session record found after ${err.attempts} attempts`)
 							} else {
 								logger.debug(errorContext, 'No session record - will retry')
 							}

src/index.ts

@@ -5,11 +5,30 @@
 const _origConsoleError = console.error
 const _origConsoleLog = console.log
 const _origConsoleInfo = console.info
+const _origConsoleWarn = console.warn
+
+// Suppress libsignal session lifecycle dumps from console.log / console.info / console.warn.
+// libsignal's session_record.js / session_builder.js / session_cipher.js use:
+//   console.info("Removing old closed session:", obj)        ← ~500ms I/O dump per call
+//   console.info("Opening session:", obj)                    ← ~500ms I/O dump per call
+//   console.info("Migrating session to:", v)                 ← per migration
+//   console.log("Closing session:", obj)                     ← ~500ms I/O dump per call
+//   console.warn("Closing open session in favor of incoming prekey bundle")  ← per pkmsg
+//   console.warn("Session already closed", obj)              ← per stale close
+//   console.warn("Decrypted message with closed session.")   ← per recovered decrypt
+//   console.warn("Unhandled bucket type (for naming):", ...) ← queue_job edge case
+//
+// Under WhatsApp's LID/DSM rollout these fire dozens of times per minute when
+// the auth state has legacy `_1.0` sessions that don't match LID-addressed
+// envelopes. Each dump is a synchronous stdout.write — pm2 buffers fill and
+// the event loop blocks. Symptom: 60s inbound delivery latency, profile
+// pictures don't load, queries time out.
+//
+// The clean operator-facing signal lives in the console.error interceptor
+// below (formats Bad MAC / Counter / Decryption Failed as one emoji line).
+const _SESSION_LIFECYCLE_RE =
+	/^(Closing session|Removing old closed session|Opening session|Migrating session|Closing open session|Session already closed|Decrypted message with closed session|Unhandled bucket type)/
 
-// Suppress libsignal session lifecycle dumps from console.log / console.info.
-// libsignal's session_record.js uses console.info("Removing old closed session:", obj)
-// and console.log("Closing session:", obj) which dump full session objects (~500ms I/O each).
-const _SESSION_LIFECYCLE_RE = /^(Closing session|Removing old closed session)/
 console.log = function (...args: unknown[]) {
 	if (args.length > 0 && typeof args[0] === 'string' && _SESSION_LIFECYCLE_RE.test(args[0])) {
 		return
@@ -26,6 +45,14 @@ console.info = function (...args: unknown[]) {
 	_origConsoleInfo.apply(console, args)
 }
 
+console.warn = function (...args: unknown[]) {
+	if (args.length > 0 && typeof args[0] === 'string' && _SESSION_LIFECYCLE_RE.test(args[0])) {
+		return
+	}
+
+	_origConsoleWarn.apply(console, args)
+}
+
 // Track errors by type + JID to avoid duplicates (using Map for better performance)
 const _errorTimestamps = new Map<string, number>()
 // Dedup window for repeated decrypt-error console lines (Bad MAC / Counter / etc).