diff --git a/src/Utils/baileys-logger.ts b/src/Utils/baileys-logger.ts index efadcbf8..c99bcb46 100644 --- a/src/Utils/baileys-logger.ts +++ b/src/Utils/baileys-logger.ts @@ -521,25 +521,97 @@ function isBaileysLogEnabled(): boolean { return process.env.BAILEYS_LOG !== 'false' } +/** + * Safely stringify a value, handling circular references, Errors, and special types + */ +function safeStringify(value: unknown, seen: WeakSet = new WeakSet()): string { + // Handle primitives + if (value === null) return 'null' + if (value === undefined) return 'undefined' + if (typeof value === 'string') return value + if (typeof value === 'number' || typeof value === 'boolean') return String(value) + if (typeof value === 'function') return '[Function]' + if (typeof value === 'symbol') return value.toString() + if (typeof value === 'bigint') return `${value}n` + + // Handle objects + if (typeof value === 'object') { + // Check for circular reference + if (seen.has(value)) return '[Circular]' + seen.add(value) + + // Handle Error objects + if (value instanceof Error) { + return `${value.name}: ${value.message}` + } + + // Handle Date objects + if (value instanceof Date) { + return value.toISOString() + } + + // Handle Arrays + if (Array.isArray(value)) { + if (value.length === 0) return '[]' + if (value.length <= 3) { + const items = value.map(v => safeStringify(v, seen)) + return `[${items.join(', ')}]` + } + return `[Array(${value.length})]` + } + + // Handle plain objects + try { + const keys = Object.keys(value as Record) + if (keys.length === 0) return '{}' + if (keys.length <= 5) { + const pairs = keys.map(k => { + const v = (value as Record)[k] + return `${k}: ${safeStringify(v, seen)}` + }) + return `{${pairs.join(', ')}}` + } + return `{Object(${keys.length} keys)}` + } catch { + return '[Object]' + } + } + + return String(value) +} + /** * Format data object for single-line or multi-line output + * Handles circular references, Error objects, arrays, and undefined values */ function formatLogData(data: Record, singleLine: boolean = true): string { - if (Object.keys(data).length === 0) return '' + if (!data || Object.keys(data).length === 0) return '' + + const seen = new WeakSet() 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 `${k}: ${safeStringify(v, seen)}` }) return `{ ${pairs.join(', ')} }` } - // Multi-line format for complex objects - return JSON.stringify(data, null, 2) + // Multi-line format - use safe replacer for JSON.stringify + try { + return JSON.stringify(data, (key, value) => { + if (value instanceof Error) { + return { name: value.name, message: value.message, stack: value.stack } + } + if (typeof value === 'bigint') { + return `${value}n` + } + return value + }, 2) + } catch { + // Fallback for circular references or other issues + return safeStringify(data, seen) + } } /** @@ -814,7 +886,8 @@ export function logInfo(message: string, data?: Record, session if (!isBaileysLogEnabled()) return const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' - const dataStr = data ? ' ' + formatLogData(data) : '' + const formatted = data ? formatLogData(data) : '' + const dataStr = formatted ? ' ' + formatted : '' console.log(`${prefix} ℹ️ ${message}${dataStr}`) } @@ -829,7 +902,8 @@ export function logWarn(message: string, data?: Record, session if (!isBaileysLogEnabled()) return const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' - const dataStr = data ? ' ' + formatLogData(data) : '' + const formatted = data ? formatLogData(data) : '' + const dataStr = formatted ? ' ' + formatted : '' console.log(`${prefix} ⚠️ ${message}${dataStr}`) } @@ -844,7 +918,8 @@ export function logError(message: string, data?: Record, sessio if (!isBaileysLogEnabled()) return const prefix = sessionName ? `[BAILEYS] [${sessionName}]` : '[BAILEYS]' - const dataStr = data ? ' ' + formatLogData(data) : '' + const formatted = data ? formatLogData(data) : '' + const dataStr = formatted ? ' ' + formatted : '' console.error(`${prefix} ❌ ${message}${dataStr}`) } diff --git a/src/Utils/event-buffer.ts b/src/Utils/event-buffer.ts index 9f6a9afe..15a0f47c 100644 --- a/src/Utils/event-buffer.ts +++ b/src/Utils/event-buffer.ts @@ -15,7 +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' +import { logEventBuffer } from './baileys-logger' // ============================================================================ // BUFFER CONFIGURATION - Environment Variable Support @@ -316,6 +316,19 @@ class AdaptiveTimeoutCalculator { this.eventTimestamps = [] this.currentTimeout = (this.minTimeout + this.maxTimeout) / 2 } + + /** + * Get current adaptive mode based on timeout + * Returns 'aggressive', 'balanced', or 'conservative' + */ + getMode(): 'aggressive' | 'balanced' | 'conservative' { + if (this.currentTimeout <= this.minTimeout * 1.5) { + return 'aggressive' + } else if (this.currentTimeout >= this.maxTimeout * 0.8) { + return 'conservative' + } + return 'balanced' + } } // ============================================================================ @@ -542,21 +555,12 @@ 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 + // Log with [BAILEYS] prefix - use getMode() to avoid duplicating mode calculation logic const flushDuration = Date.now() - flushStartTime logEventBuffer('buffer_flush', { flushCount: stats.totalFlushes, historyCacheSize: stats.historyCacheSize, - mode: adaptiveMode, + mode: config.enableAdaptiveTimeout ? adaptiveTimeout.getMode() : 'fixed', ...(flushDuration > 5 ? { duration: `${flushDuration}ms` } : {}) }) diff --git a/src/__tests__/Utils/baileys-logger-console.test.ts b/src/__tests__/Utils/baileys-logger-console.test.ts new file mode 100644 index 00000000..91ecfa91 --- /dev/null +++ b/src/__tests__/Utils/baileys-logger-console.test.ts @@ -0,0 +1,297 @@ +/** + * Unit tests for baileys-logger.ts console-friendly logging functions + */ + +import { describe, it, expect, beforeEach, afterEach, jest } from '@jest/globals' +import { + logEventBuffer, + logBufferMetrics, + logMessageSent, + logMessageReceived, + logConnection, + logAuth, + logCircuitBreaker, + logRetry, + logInfo, + logWarn, + logError, + logLidMapping, +} from '../../Utils/baileys-logger.js' + +describe('Baileys Console Logging Functions', () => { + let consoleSpy: jest.SpiedFunction + let consoleErrorSpy: jest.SpiedFunction + const originalEnv = process.env.BAILEYS_LOG + + beforeEach(() => { + consoleSpy = jest.spyOn(console, 'log').mockImplementation(() => {}) + consoleErrorSpy = jest.spyOn(console, 'error').mockImplementation(() => {}) + // Reset env var + delete process.env.BAILEYS_LOG + }) + + afterEach(() => { + jest.restoreAllMocks() + if (originalEnv !== undefined) { + process.env.BAILEYS_LOG = originalEnv + } else { + delete process.env.BAILEYS_LOG + } + }) + + describe('environment variable check', () => { + it('should log when BAILEYS_LOG is not set', () => { + delete process.env.BAILEYS_LOG + logEventBuffer('buffer_start') + expect(consoleSpy).toHaveBeenCalled() + }) + + it('should log when BAILEYS_LOG=true', () => { + process.env.BAILEYS_LOG = 'true' + logEventBuffer('buffer_start') + expect(consoleSpy).toHaveBeenCalled() + }) + + it('should NOT log when BAILEYS_LOG=false', () => { + process.env.BAILEYS_LOG = 'false' + logEventBuffer('buffer_start') + expect(consoleSpy).not.toHaveBeenCalled() + }) + }) + + describe('logEventBuffer', () => { + it('should log buffer_start with 📦 emoji', () => { + logEventBuffer('buffer_start') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] 📦 Event buffering started') + }) + + it('should log buffer_flush with 🔄 emoji and data', () => { + logEventBuffer('buffer_flush', { flushCount: 10, mode: 'aggressive' }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[BAILEYS] 🔄 Event buffer flushed')) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('flushCount: 10')) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('mode: aggressive')) + }) + + it('should log buffer_overflow with ⚠️ emoji', () => { + logEventBuffer('buffer_overflow', { currentSize: 5000 }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[BAILEYS] ⚠️ Buffer overflow detected')) + }) + + it('should log buffer_timeout with ⏰ emoji', () => { + logEventBuffer('buffer_timeout', { timeout: 30000 }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[BAILEYS] ⏰ Buffer timeout reached')) + }) + + it('should log cache_cleanup with 🧹 emoji', () => { + logEventBuffer('cache_cleanup', { removed: 100 }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[BAILEYS] 🧹 History cache cleanup')) + }) + + it('should include session name when provided', () => { + logEventBuffer('buffer_start', undefined, 'session-123') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] [session-123] 📦 Event buffering started') + }) + }) + + describe('logBufferMetrics', () => { + it('should log metrics in multi-line format', () => { + logBufferMetrics({ + itemsBuffered: 50, + flushCount: 100, + historyCacheSize: 200, + buffersInProgress: 1, + }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('📊 Buffer Metrics')) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('itemsBuffered: 50')) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('flushCount: 100')) + }) + + it('should include adaptive info when provided', () => { + logBufferMetrics({ + itemsBuffered: 0, + flushCount: 120, + historyCacheSize: 0, + buffersInProgress: 0, + adaptive: { + mode: 'aggressive', + timeout: 1000, + eventRate: 1.34, + isHealthy: true, + }, + }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining("mode: 'aggressive'")) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('timeout: 1000')) + }) + }) + + describe('logMessageSent and logMessageReceived', () => { + it('should log message sent with 📤 emoji and arrow', () => { + logMessageSent('MSG123', '5511999999999@s.whatsapp.net') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] 📤 Message sent: MSG123 → 5511999999999@s.whatsapp.net') + }) + + it('should log message received with 📥 emoji and arrow', () => { + logMessageReceived('MSG456', '5511888888888@s.whatsapp.net') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] 📥 Message received: MSG456 ← 5511888888888@s.whatsapp.net') + }) + + it('should include session name for messages', () => { + logMessageSent('MSG789', 'user@lid', 'session-abc') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] [session-abc] 📤 Message sent: MSG789 → user@lid') + }) + }) + + describe('logConnection', () => { + it('should log connecting with 🔌 emoji', () => { + logConnection('connecting') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] 🔌 Connecting to WhatsApp...') + }) + + it('should log open with ✅ emoji', () => { + logConnection('open') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] ✅ Connected to WhatsApp') + }) + + it('should log close with 🔴 emoji', () => { + logConnection('close', { reason: 'logout' }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[BAILEYS] 🔴 Disconnected from WhatsApp')) + }) + + it('should log reconnecting with 🔄 emoji', () => { + logConnection('reconnecting', { attempt: 2 }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[BAILEYS] 🔄 Reconnecting to WhatsApp')) + }) + + it('should log error with ❌ emoji', () => { + logConnection('error', { code: 'ECONNREFUSED' }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[BAILEYS] ❌ Connection error')) + }) + }) + + describe('logAuth', () => { + it('should log qr_generated with 📱 emoji', () => { + logAuth('qr_generated') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] 📱 QR Code generated - scan with WhatsApp') + }) + + it('should log authenticated with ✅ emoji', () => { + logAuth('authenticated') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] ✅ Authentication successful') + }) + + it('should log logout with 🚪 emoji', () => { + logAuth('logout') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] 🚪 Logged out') + }) + }) + + describe('logCircuitBreaker', () => { + it('should log open state with ⚡ emoji', () => { + logCircuitBreaker('open', { failures: 5 }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[BAILEYS] ⚡ Circuit breaker OPEN')) + }) + + it('should log closed state with ✅ emoji', () => { + logCircuitBreaker('closed') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] ✅ Circuit breaker CLOSED') + }) + + it('should log half_open state with 🔶 emoji', () => { + logCircuitBreaker('half_open') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] 🔶 Circuit breaker HALF-OPEN') + }) + }) + + describe('logRetry', () => { + it('should log retry attempt with 🔁 emoji', () => { + logRetry(2, 5, 5000, 'connection') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] 🔁 Retry attempt 2/5 for connection (delay: 5000ms)') + }) + }) + + describe('logInfo, logWarn, logError', () => { + it('should log info with ℹ️ emoji', () => { + logInfo('PreKey validation passed') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] ℹ️ PreKey validation passed') + }) + + it('should log warning with ⚠️ emoji', () => { + logWarn('Rate limit approaching', { remaining: 10 }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[BAILEYS] ⚠️ Rate limit approaching')) + }) + + it('should log error with ❌ emoji to console.error', () => { + logError('Failed to send', { error: 'timeout' }) + expect(consoleErrorSpy).toHaveBeenCalledWith(expect.stringContaining('[BAILEYS] ❌ Failed to send')) + }) + }) + + describe('logLidMapping', () => { + it('should log LID events with appropriate emojis', () => { + logLidMapping('initialized') + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] 🗂️ LID Mapping Store initialized') + + logLidMapping('lookup', { jid: 'user@lid' }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[BAILEYS] 🔍 LID lookup')) + + logLidMapping('store', { count: 5 }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[BAILEYS] 💾 LID stored')) + + logLidMapping('batch_resolved', { resolved: 10 }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[BAILEYS] 📦 LID batch resolved')) + }) + }) + + describe('formatLogData edge cases', () => { + it('should handle undefined values in data', () => { + logInfo('Test', { key: undefined }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('key: undefined')) + }) + + it('should handle null values in data', () => { + logInfo('Test', { key: null }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('key: null')) + }) + + it('should handle Error objects in data', () => { + const error = new Error('Test error') + logInfo('Test', { error }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('Error: Test error')) + }) + + it('should handle arrays in data', () => { + logInfo('Test', { items: [1, 2, 3] }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[1, 2, 3]')) + }) + + it('should handle large arrays with truncation', () => { + logInfo('Test', { items: [1, 2, 3, 4, 5, 6, 7, 8, 9, 10] }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('[Array(10)]')) + }) + + it('should handle circular references gracefully', () => { + const obj: Record = { name: 'test' } + obj.self = obj // Create circular reference + // Should not throw + expect(() => logInfo('Test', { obj })).not.toThrow() + expect(consoleSpy).toHaveBeenCalled() + }) + + it('should handle Date objects', () => { + const date = new Date('2026-01-20T12:00:00.000Z') + logInfo('Test', { date }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('2026-01-20T12:00:00.000Z')) + }) + + it('should handle empty data object', () => { + logInfo('Test', {}) + // Empty data object should not add trailing space + expect(consoleSpy).toHaveBeenCalledWith('[BAILEYS] ℹ️ Test') + }) + + it('should handle nested objects', () => { + logInfo('Test', { outer: { inner: { value: 42 } } }) + expect(consoleSpy).toHaveBeenCalledWith(expect.stringContaining('outer:')) + }) + }) +})