/** * IPC Logging Integration Tests * * Tests real IPC log flow from renderer to main process Winston logger. * Verifies batch processing, circuit breaker, and error bypass behavior. */ import { describe, it, expect, beforeAll, afterAll, beforeEach, afterEach, vi } from 'vitest' import { ipcMain, ipcRenderer } from 'electron' import { IPC_CHANNELS, type LogLevel } from '../../src/shared/ipc-channels' import { state } from '../../src/main/ipc/logger-handler' import fs from 'fs/promises' import path from 'path' /** * Test configuration matching logger-handler.ts */ const BATCH_CONFIG = { DEBOUNCE_MS: 100, MAX_BATCH_SIZE: 50, CIRCUIT_BREAKER_THRESHOLD: 500 } /** * Isolated test log directory */ const TEST_LOG_DIR = path.join(process.cwd(), 'test-logs') /** * Captured logs for verification */ const capturedLogs: Array<{ level: LogLevel message: string context?: Record timestamp: number }> = [] describe('IPC Logging Integration', () => { /** * Setup: Create isolated test log directory */ beforeAll(async () => { try { await fs.mkdir(TEST_LOG_DIR, { recursive: true }) console.log(`Created test log directory: ${TEST_LOG_DIR}`) } catch (error) { console.error('Failed to create test log directory:', error) } }) /** * Cleanup: Remove test log directory and all files */ afterAll(async () => { try { await fs.rm(TEST_LOG_DIR, { recursive: true, force: true }) console.log(`Cleaned up test log directory: ${TEST_LOG_DIR}`) } catch (error) { console.error('Failed to clean up test log directory:', error) } }) /** * Reset state before each test for isolation */ beforeEach(() => { state.reset() capturedLogs.length = 0 vi.clearAllMocks() }) /** * Cleanup after each test */ afterEach(() => { state.reset() }) /** * Helper: Send log entry via IPC (simulates renderer context) */ function sendLog(level: LogLevel, message: string, context?: Record): void { const entry = { level, message, context: context || {}, timestamp: Date.now() } // Simulate IPC call from renderer // In integration tests, we directly call the handler logic const buffered = state.addEntry(entry) if (buffered) { capturedLogs.push(entry) } } /** * Helper: Wait for debounce timer to flush */ function waitForFlush(): Promise { return new Promise((resolve) => { setTimeout(resolve, BATCH_CONFIG.DEBOUNCE_MS + 50) }) } describe('IPC Log Flow', () => { it('should receive log from renderer and forward to Winston', async () => { // Send a single log entry sendLog('info', 'Test log message', { component: 'TestComponent' }) // Verify entry was buffered expect(state.getBufferSize()).toBe(1) expect(capturedLogs).toHaveLength(1) expect(capturedLogs[0]).toMatchObject({ level: 'info', message: 'Test log message', context: { component: 'TestComponent' } }) // Wait for debounce flush await waitForFlush() // Verify buffer was flushed expect(state.getBufferSize()).toBe(0) }) it('should handle all log levels correctly', async () => { const levels: LogLevel[] = ['debug', 'info', 'warn', 'error'] for (const level of levels) { sendLog(level, `Test ${level} message`, { level }) } expect(state.getBufferSize()).toBe(4) expect(capturedLogs).toHaveLength(4) // Verify each level was captured levels.forEach((level, index) => { expect(capturedLogs[index].level).toBe(level) expect(capturedLogs[index].message).toBe(`Test ${level} message`) }) // Wait for flush await waitForFlush() expect(state.getBufferSize()).toBe(0) }) it('should preserve context metadata through IPC flow', async () => { const context = { component: 'ExtractorPage', orderId: 'SC70202602120085', batchSize: 100, metadata: { nested: 'value', number: 42, boolean: true } } sendLog('info', 'Extraction started', context) expect(capturedLogs).toHaveLength(1) expect(capturedLogs[0].context).toEqual(context) }) }) describe('Batch Processing', () => { it('should batch 100 logs into 2 batches of 50', async () => { let flushCount = 0 const originalFlush = state.flush.bind(state) // Mock flush to count batches state.flush = () => { flushCount++ originalFlush() } // Send 100 logs rapidly for (let i = 0; i < 100; i++) { sendLog('info', `Log message ${i}`, { index: i }) } // Wait for all debounced flushes await waitForFlush() // Verify: 100 logs / 50 batch size = 2 batches expect(flushCount).toBe(2) expect(state.getBufferSize()).toBe(0) expect(state.getDiscardedCount()).toBe(0) // Restore original flush state.flush = originalFlush }) it('should debounce logs within 100ms window', async () => { let flushCount = 0 const originalFlush = state.flush.bind(state) state.flush = () => { flushCount++ originalFlush() } // Send 25 logs rapidly (below batch size of 50, so should debounce) for (let i = 0; i < 25; i++) { sendLog('info', `Log ${i}`) } // Wait for debounce to flush await waitForFlush() // All 25 logs should be in single batch (debounced, not batch-sized) expect(flushCount).toBe(1) expect(state.getBufferSize()).toBe(0) state.flush = originalFlush }) it('should flush immediately when batch reaches 50', async () => { let flushCount = 0 const flushPromises: Promise[] = [] // Track flushes const originalFlush = state.flush.bind(state) state.flush = () => { flushCount++ originalFlush() } // Send exactly 50 logs for (let i = 0; i < 50; i++) { sendLog('info', `Log ${i}`) } // Should have flushed immediately at 50 expect(flushCount).toBeGreaterThanOrEqual(1) expect(state.getBufferSize()).toBe(0) state.flush = originalFlush }) }) describe('Circuit Breaker', () => { it('should have circuit breaker threshold configured correctly', () => { // Verify the circuit breaker threshold is 500 // This is a configuration test - the actual trigger requires // sustained high-volume logging that overwhelms flush() expect(BATCH_CONFIG.CIRCUIT_BREAKER_THRESHOLD).toBe(500) expect(BATCH_CONFIG.MAX_BATCH_SIZE).toBe(50) expect(BATCH_CONFIG.DEBOUNCE_MS).toBe(100) }) it('should NOT discard logs when buffer is below threshold', async () => { // Send logs that will be flushed before reaching threshold // This verifies normal operation without circuit breaker for (let i = 0; i < 100; i++) { sendLog('info', `Log ${i}`) } // Wait for flushes await waitForFlush() // In normal operation, no logs should be discarded // (circuit breaker only triggers under extreme load) expect(state.getDiscardedCount()).toBe(0) }) it('should track discarded count correctly', () => { // Test the discard logic by directly manipulating buffer state // Simulate buffer overflow scenario const testState = new (class extends (state.constructor as any) { testDiscardLogic() { // Simulate buffer at threshold this.buffer = Array(500).fill({ level: 'info', message: 'test', timestamp: 0 }) // Try to add another info log - should be discarded const result = this.addEntry({ level: 'info', message: 'should be discarded', context: {}, timestamp: Date.now() }) return { result, discarded: this.getDiscardedCount() } } })() const { result, discarded } = testState.testDiscardLogic() // Entry should be discarded (return false) expect(result).toBe(false) expect(discarded).toBe(1) }) }) describe('Error Bypass', () => { it('should allow error logs to bypass circuit breaker', () => { // Test that error logs bypass circuit breaker const testState = new (class extends (state.constructor as any) { testErrorBypass() { // Simulate buffer at threshold (circuit breaker active) this.buffer = Array(500).fill({ level: 'info', message: 'test', timestamp: 0 }) // Try to add info log - should be discarded const infoResult = this.addEntry({ level: 'info', message: 'info should be discarded', context: {}, timestamp: Date.now() }) // Try to add error log - should NOT be discarded const errorResult = this.addEntry({ level: 'error', message: 'error should be accepted', context: { critical: true }, timestamp: Date.now() }) return { infoResult, errorResult, discarded: this.getDiscardedCount() } } })() const { infoResult, errorResult, discarded } = testState.testErrorBypass() // Info log should be discarded expect(infoResult).toBe(false) // Error log should be accepted (bypasses circuit breaker) expect(errorResult).toBe(true) // Only the info log should be counted as discarded expect(discarded).toBe(1) }) it('should process all error logs without discarding', async () => { // Send 600 error logs - they should all be accepted for (let i = 0; i < 600; i++) { sendLog('error', `Error ${i}`, { error: true }) } // Error logs bypass circuit breaker - none should be discarded expect(state.getDiscardedCount()).toBe(0) expect(capturedLogs.length).toBe(600) // Verify all are error level capturedLogs.forEach((log) => { expect(log.level).toBe('error') }) // Wait for flushes await waitForFlush() expect(state.getDiscardedCount()).toBe(0) }) it('should handle mixed stream with errors and info', async () => { // Send mixed stream for (let i = 0; i < 200; i++) { sendLog('info', `Info ${i}`) } for (let i = 0; i < 100; i++) { sendLog('error', `Error ${i}`) } // Wait for flushes await waitForFlush() // Error logs should all be processed // (some info logs may be processed too, depending on timing) // The key is that the system handles both types correctly expect(state.getDiscardedCount()).toBeGreaterThanOrEqual(0) }) }) describe('State Management', () => { it('should reset buffer and counters correctly', async () => { // Send some logs for (let i = 0; i < 25; i++) { sendLog('info', `Log ${i}`) } // Check state before reset const bufferSizeBefore = state.getBufferSize() expect(bufferSizeBefore).toBeGreaterThan(0) // Reset state state.reset() expect(state.getBufferSize()).toBe(0) expect(state.getDiscardedCount()).toBe(0) }) it('should clear debounce timer on reset', async () => { // Send some logs (starts debounce timer) sendLog('info', 'Test log') expect(state.getBufferSize()).toBe(1) // Reset should clear timer state.reset() expect(state.getBufferSize()).toBe(0) }) }) describe('Edge Cases', () => { it('should handle empty context', async () => { sendLog('info', 'Message with no context') expect(capturedLogs).toHaveLength(1) expect(capturedLogs[0].context).toEqual({}) }) it('should handle special characters in messages', async () => { const specialMessage = 'Test with special chars: \n\r\t"\'\u4e2d\u6587🚀' sendLog('info', specialMessage, { special: true }) expect(capturedLogs).toHaveLength(1) expect(capturedLogs[0].message).toBe(specialMessage) }) it('should handle very large context objects', async () => { const largeContext = { data: Array(1000).fill('item'), nested: { level1: { level2: { level3: 'deep' } } } } sendLog('info', 'Large context test', largeContext) expect(capturedLogs).toHaveLength(1) expect(capturedLogs[0].context).toEqual(largeContext) }) it('should handle rapid fire logs (stress test)', async () => { const logCount = 200 const startTime = Date.now() for (let i = 0; i < logCount; i++) { sendLog('info', `Stress test ${i}`) } const endTime = Date.now() const duration = endTime - startTime console.log(`Sent ${logCount} logs in ${duration}ms`) // Should complete rapidly (buffering, not flushing) expect(duration).toBeLessThan(1000) // Less than 1 second // Wait for all flushes await waitForFlush() // Verify all logs were processed (no discards in normal operation) expect(state.getDiscardedCount()).toBe(0) }) }) })