From 3f2ced450190a30abce3a576a5af2270a0713be0 Mon Sep 17 00:00:00 2001 From: Claude Date: Tue, 20 Jan 2026 20:48:26 +0000 Subject: [PATCH] feat(logger): add [BAILEYS] console-friendly logging functions MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Add formatted logging functions with [BAILEYS] prefix and emojis: - logEventBuffer: buffer events (๐Ÿ“ฆ, ๐Ÿ”„, โš ๏ธ, โฐ, ๐Ÿงน, ๐Ÿง ) - logBufferMetrics: metrics display (๐Ÿ“Š) - logMessageSent/Received: message events (๐Ÿ“ค, ๐Ÿ“ฅ) - logConnection: connection events (๐Ÿ”Œ, โœ…, ๐Ÿ”ด, ๐Ÿ”„, โŒ) - logAuth: authentication events (๐Ÿ“ฑ, ๐Ÿ”‘, ๐Ÿšช, ๐Ÿ”) - logCircuitBreaker: circuit breaker state (โšก, โœ…, ๐Ÿ”ถ) - logRetry: retry attempts (๐Ÿ”) - logInfo/Warn/Error: generic messages (โ„น๏ธ, โš ๏ธ, โŒ) - logLidMapping: LID store events (๐Ÿ—‚๏ธ, ๐Ÿ”, ๐Ÿ’พ, ๐Ÿ“ฆ) All functions respect BAILEYS_LOG=false environment variable. Integrated into event-buffer.ts and messages-send/recv.ts. --- src/Socket/messages-recv.ts | 6 + src/Socket/messages-send.ts | 4 + src/Utils/baileys-logger.ts | 368 ++++++++++++++++++++++++++++++++++++ src/Utils/event-buffer.ts | 30 +++ 4 files changed, 408 insertions(+) diff --git a/src/Socket/messages-recv.ts b/src/Socket/messages-recv.ts index 95957134..0ed3da54 100644 --- a/src/Socket/messages-recv.ts +++ b/src/Socket/messages-recv.ts @@ -16,6 +16,7 @@ import type { WAPatchName } from '../Types' import { WAMessageStatus, WAMessageStubType } from '../Types' +import { logMessageReceived } from '../Utils/baileys-logger' import { aesDecryptCTR, aesEncryptGCM, @@ -1318,6 +1319,11 @@ export const makeMessagesRecvSocket = (config: SocketConfig) => { cleanMessage(msg, authState.creds.me!.id, authState.creds.me!.lid!) await upsertMessage(msg, node.attrs.offline ? 'append' : 'notify') + + // Log with [BAILEYS] prefix + if (msg.key.id && msg.key.remoteJid) { + logMessageReceived(msg.key.id, msg.key.remoteJid) + } }) } catch (error) { logger.error({ error, node: binaryNodeToString(node) }, 'error in handling message') diff --git a/src/Socket/messages-send.ts b/src/Socket/messages-send.ts index b6177ede..d95102c5 100644 --- a/src/Socket/messages-send.ts +++ b/src/Socket/messages-send.ts @@ -12,6 +12,7 @@ import type { WAMessage, WAMessageKey } from '../Types' +import { logMessageSent } from '../Utils/baileys-logger' import { aggregateMessageKeysNotFromMe, assertMediaContent, @@ -1034,6 +1035,9 @@ export const makeMessagesSocket = (config: SocketConfig) => { await sendNode(stanza) + // Log with [BAILEYS] prefix + logMessageSent(msgId, destinationJid) + // Add message to retry cache if enabled if (messageRetryManager && !participant) { messageRetryManager.addRecentMessage(destinationJid, msgId, message) diff --git a/src/Utils/baileys-logger.ts b/src/Utils/baileys-logger.ts index b713296c..efadcbf8 100644 --- a/src/Utils/baileys-logger.ts +++ b/src/Utils/baileys-logger.ts @@ -509,4 +509,372 @@ export function setDefaultBaileysLogger(logger: BaileysLogger): void { defaultBaileysLogger = logger } +// ============================================================================ +// CONSOLE-FRIENDLY LOGGING FUNCTIONS WITH [BAILEYS] PREFIX +// ============================================================================ + +/** + * Check if Baileys logging is enabled via environment variable + * BAILEYS_LOG=false disables all [BAILEYS] console logs + */ +function isBaileysLogEnabled(): boolean { + return process.env.BAILEYS_LOG !== 'false' +} + +/** + * Format data object for single-line or multi-line output + */ +function formatLogData(data: Record, singleLine: boolean = true): string { + if (Object.keys(data).length === 0) return '' + + if (singleLine) { + // Single line format: { key1: value1, key2: value2 } + const pairs = Object.entries(data).map(([k, v]) => { + if (typeof v === 'object' && v !== null) { + return `${k}: ${JSON.stringify(v)}` + } + return `${k}: ${v}` + }) + return `{ ${pairs.join(', ')} }` + } + + // Multi-line format for complex objects + return JSON.stringify(data, null, 2) +} + +/** + * Event buffer logging types + */ +export type EventBufferLogType = + | 'buffer_start' + | 'buffer_flush' + | 'buffer_overflow' + | 'buffer_timeout' + | 'cache_cleanup' + | 'adaptive_mode' + +/** + * Log event buffer operations with emoji and [BAILEYS] prefix + * + * @example + * logEventBuffer('buffer_start') + * // Output: [BAILEYS] ๐Ÿ“ฆ Event buffering started + * + * logEventBuffer('buffer_flush', { flushCount: 10, historyCacheSize: 5, mode: 'aggressive' }) + * // Output: [BAILEYS] ๐Ÿ”„ Event buffer flushed { flushCount: 10, historyCacheSize: 5, mode: 'aggressive' } + */ +export function logEventBuffer( + type: EventBufferLogType, + data?: Record, + sessionName?: string +): void { + if (!isBaileysLogEnabled()) return + + const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' + const dataStr = data ? ' ' + formatLogData(data) : '' + + switch (type) { + case 'buffer_start': + console.log(`${prefix} ๐Ÿ“ฆ Event buffering started${dataStr}`) + break + case 'buffer_flush': + console.log(`${prefix} ๐Ÿ”„ Event buffer flushed${dataStr}`) + break + case 'buffer_overflow': + console.log(`${prefix} โš ๏ธ Buffer overflow detected${dataStr}`) + break + case 'buffer_timeout': + console.log(`${prefix} โฐ Buffer timeout reached${dataStr}`) + break + case 'cache_cleanup': + console.log(`${prefix} ๐Ÿงน History cache cleanup${dataStr}`) + break + case 'adaptive_mode': + console.log(`${prefix} ๐Ÿง  Adaptive mode updated${dataStr}`) + break + } +} + +/** + * Log buffer metrics in a formatted way + * + * @example + * logBufferMetrics({ + * itemsBuffered: 0, + * flushCount: 120, + * historyCacheSize: 0, + * buffersInProgress: 0, + * adaptive: { mode: 'aggressive', timeout: 1000, eventRate: 1.34, isHealthy: true } + * }) + */ +export function logBufferMetrics( + metrics: { + itemsBuffered: number + flushCount: number + historyCacheSize: number + buffersInProgress: number + adaptive?: { + mode: string + timeout: number + eventRate: number + isHealthy: boolean + } + }, + sessionName?: string +): void { + if (!isBaileysLogEnabled()) return + + const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' + + console.log(`${prefix} ๐Ÿ“Š Buffer Metrics {`) + console.log(`${prefix} itemsBuffered: ${metrics.itemsBuffered},`) + console.log(`${prefix} flushCount: ${metrics.flushCount},`) + console.log(`${prefix} historyCacheSize: ${metrics.historyCacheSize},`) + console.log(`${prefix} buffersInProgress: ${metrics.buffersInProgress}${metrics.adaptive ? ',' : ''}`) + if (metrics.adaptive) { + console.log(`${prefix} adaptive: {`) + console.log(`${prefix} mode: '${metrics.adaptive.mode}',`) + console.log(`${prefix} timeout: ${metrics.adaptive.timeout},`) + console.log(`${prefix} eventRate: ${metrics.adaptive.eventRate.toFixed(2)},`) + console.log(`${prefix} isHealthy: ${metrics.adaptive.isHealthy}`) + console.log(`${prefix} }`) + } + console.log(`${prefix} }`) +} + +/** + * Log message sent event + * + * @example + * logMessageSent('3EB02FA562D6CCC0876CDE', '5511999999999@s.whatsapp.net') + * // Output: [BAILEYS] ๐Ÿ“ค Message sent: 3EB02FA562D6CCC0876CDE โ†’ 5511999999999@s.whatsapp.net + */ +export function logMessageSent( + messageId: string, + recipientJid: string, + sessionName?: string +): void { + if (!isBaileysLogEnabled()) return + + const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' + console.log(`${prefix} ๐Ÿ“ค Message sent: ${messageId} โ†’ ${recipientJid}`) +} + +/** + * Log message received event + * + * @example + * logMessageReceived('A5E0349897A3F16F3F2778EEF94A065F', '238315571802285@lid') + * // Output: [BAILEYS] ๐Ÿ“ฅ Message received: A5E0349897A3F16F3F2778EEF94A065F โ† 238315571802285@lid + */ +export function logMessageReceived( + messageId: string, + senderJid: string, + sessionName?: string +): void { + if (!isBaileysLogEnabled()) return + + const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' + console.log(`${prefix} ๐Ÿ“ฅ Message received: ${messageId} โ† ${senderJid}`) +} + +/** + * Log connection event + * + * @example + * logConnection('connecting') + * // Output: [BAILEYS] ๐Ÿ”Œ Connecting to WhatsApp... + * + * logConnection('open') + * // Output: [BAILEYS] โœ… Connected to WhatsApp + */ +export function logConnection( + event: 'connecting' | 'open' | 'close' | 'reconnecting' | 'error', + details?: Record, + sessionName?: string +): void { + if (!isBaileysLogEnabled()) return + + const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' + const dataStr = details ? ' ' + formatLogData(details) : '' + + switch (event) { + case 'connecting': + console.log(`${prefix} ๐Ÿ”Œ Connecting to WhatsApp...${dataStr}`) + break + case 'open': + console.log(`${prefix} โœ… Connected to WhatsApp${dataStr}`) + break + case 'close': + console.log(`${prefix} ๐Ÿ”ด Disconnected from WhatsApp${dataStr}`) + break + case 'reconnecting': + console.log(`${prefix} ๐Ÿ”„ Reconnecting to WhatsApp...${dataStr}`) + break + case 'error': + console.log(`${prefix} โŒ Connection error${dataStr}`) + break + } +} + +/** + * Log authentication event + * + * @example + * logAuth('qr_generated') + * // Output: [BAILEYS] ๐Ÿ“ฑ QR Code generated - scan with WhatsApp + */ +export function logAuth( + event: 'qr_generated' | 'pairing_code' | 'authenticated' | 'logout' | 'creds_updated', + details?: Record, + sessionName?: string +): void { + if (!isBaileysLogEnabled()) return + + const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' + const dataStr = details ? ' ' + formatLogData(details) : '' + + switch (event) { + case 'qr_generated': + console.log(`${prefix} ๐Ÿ“ฑ QR Code generated - scan with WhatsApp${dataStr}`) + break + case 'pairing_code': + console.log(`${prefix} ๐Ÿ”‘ Pairing code generated${dataStr}`) + break + case 'authenticated': + console.log(`${prefix} โœ… Authentication successful${dataStr}`) + break + case 'logout': + console.log(`${prefix} ๐Ÿšช Logged out${dataStr}`) + break + case 'creds_updated': + console.log(`${prefix} ๐Ÿ” Credentials updated${dataStr}`) + break + } +} + +/** + * Log circuit breaker event + * + * @example + * logCircuitBreaker('open', { failures: 5 }) + * // Output: [BAILEYS] โšก Circuit breaker OPEN { failures: 5 } + */ +export function logCircuitBreaker( + state: 'open' | 'closed' | 'half_open', + details?: Record, + sessionName?: string +): void { + if (!isBaileysLogEnabled()) return + + const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' + const dataStr = details ? ' ' + formatLogData(details) : '' + + switch (state) { + case 'open': + console.log(`${prefix} โšก Circuit breaker OPEN${dataStr}`) + break + case 'closed': + console.log(`${prefix} โœ… Circuit breaker CLOSED${dataStr}`) + break + case 'half_open': + console.log(`${prefix} ๐Ÿ”ถ Circuit breaker HALF-OPEN${dataStr}`) + break + } +} + +/** + * Log retry event + * + * @example + * logRetry(2, 3, 5000, 'connection') + * // Output: [BAILEYS] ๐Ÿ” Retry attempt 2/3 for connection (delay: 5000ms) + */ +export function logRetry( + attempt: number, + maxAttempts: number, + delayMs: number, + operation: string, + sessionName?: string +): void { + if (!isBaileysLogEnabled()) return + + const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' + console.log(`${prefix} ๐Ÿ” Retry attempt ${attempt}/${maxAttempts} for ${operation} (delay: ${delayMs}ms)`) +} + +/** + * Log generic Baileys info message + * + * @example + * logInfo('PreKey validation passed') + * // Output: [BAILEYS] โ„น๏ธ PreKey validation passed + */ +export function logInfo(message: string, data?: Record, sessionName?: string): void { + if (!isBaileysLogEnabled()) return + + const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' + const dataStr = data ? ' ' + formatLogData(data) : '' + console.log(`${prefix} โ„น๏ธ ${message}${dataStr}`) +} + +/** + * Log generic Baileys warning message + * + * @example + * logWarn('Rate limit approaching') + * // Output: [BAILEYS] โš ๏ธ Rate limit approaching + */ +export function logWarn(message: string, data?: Record, sessionName?: string): void { + if (!isBaileysLogEnabled()) return + + const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' + const dataStr = data ? ' ' + formatLogData(data) : '' + console.log(`${prefix} โš ๏ธ ${message}${dataStr}`) +} + +/** + * Log generic Baileys error message + * + * @example + * logError('Failed to send message', { error: 'timeout' }) + * // Output: [BAILEYS] โŒ Failed to send message { error: 'timeout' } + */ +export function logError(message: string, data?: Record, sessionName?: string): void { + if (!isBaileysLogEnabled()) return + + const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' + const dataStr = data ? ' ' + formatLogData(data) : '' + console.error(`${prefix} โŒ ${message}${dataStr}`) +} + +/** + * Log LID mapping store event + */ +export function logLidMapping( + event: 'initialized' | 'lookup' | 'store' | 'batch_resolved', + data?: Record, + sessionName?: string +): void { + if (!isBaileysLogEnabled()) return + + const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' + const dataStr = data ? ' ' + formatLogData(data) : '' + + switch (event) { + case 'initialized': + console.log(`${prefix} ๐Ÿ—‚๏ธ LID Mapping Store initialized${dataStr}`) + break + case 'lookup': + console.log(`${prefix} ๐Ÿ” LID lookup${dataStr}`) + break + case 'store': + console.log(`${prefix} ๐Ÿ’พ LID stored${dataStr}`) + break + case 'batch_resolved': + console.log(`${prefix} ๐Ÿ“ฆ LID batch resolved${dataStr}`) + break + } +} + export default BaileysLogger diff --git a/src/Utils/event-buffer.ts b/src/Utils/event-buffer.ts index 247f0022..9f6a9afe 100644 --- a/src/Utils/event-buffer.ts +++ b/src/Utils/event-buffer.ts @@ -15,6 +15,7 @@ import { trimUndefined } from './generics' import type { ILogger } from './logger' import { updateMessageWithReaction, updateMessageWithReceipt } from './messages' import { isRealMessage, shouldIncrementChatUnread } from './process-message' +import { logEventBuffer, logBufferMetrics } from './baileys-logger' // ============================================================================ // BUFFER CONFIGURATION - Environment Variable Support @@ -431,6 +432,10 @@ export const makeEventBuffer = ( currentSize: currentEventCount, maxSize: config.maxBufferSize }, 'Buffer overflow detected, forcing flush') + logEventBuffer('buffer_overflow', { + currentSize: currentEventCount, + maxSize: config.maxBufferSize + }) flush(true) return true } @@ -460,6 +465,10 @@ export const makeEventBuffer = ( remaining: historyCache.size, maxSize: config.maxHistoryCacheSize }, 'LRU cleanup performed on history cache') + logEventBuffer('cache_cleanup', { + removed: removed.length, + remaining: historyCache.size + }) } } @@ -471,6 +480,7 @@ export const makeEventBuffer = ( if (!isBuffering) { logger.debug('Event buffer activated') + logEventBuffer('buffer_start') isBuffering = true bufferCount = 0 currentEventCount = 0 @@ -486,6 +496,7 @@ export const makeEventBuffer = ( bufferTimeout = setTimeout(() => { if (isBuffering) { logger.warn({ timeout }, 'Buffer timeout reached, auto-flushing') + logEventBuffer('buffer_timeout', { timeout }) stats.forcedFlushes++ flush(true) } @@ -507,6 +518,7 @@ export const makeEventBuffer = ( } const eventCount = currentEventCount + const flushStartTime = Date.now() logger.debug({ bufferCount, eventCount, force }, 'Flushing event buffer') isBuffering = false @@ -530,6 +542,24 @@ export const makeEventBuffer = ( // Record metrics recordFlushMetrics(eventCount, force) + // Determine adaptive mode label + const currentTimeoutMs = config.enableAdaptiveTimeout ? adaptiveTimeout.getTimeout() : config.bufferTimeoutMs + let adaptiveMode = 'balanced' + if (currentTimeoutMs <= config.minBufferTimeoutMs * 1.5) { + adaptiveMode = 'aggressive' + } else if (currentTimeoutMs >= config.maxBufferTimeoutMs * 0.8) { + adaptiveMode = 'conservative' + } + + // Log with [BAILEYS] prefix + const flushDuration = Date.now() - flushStartTime + logEventBuffer('buffer_flush', { + flushCount: stats.totalFlushes, + historyCacheSize: stats.historyCacheSize, + mode: adaptiveMode, + ...(flushDuration > 5 ? { duration: `${flushDuration}ms` } : {}) + }) + const newData = makeBufferData() const chatUpdates = Object.values(data.chatUpdates) let conditionalChatUpdatesLeft = 0