From 271c792451c7622f8157a374873c2335e86231ad Mon Sep 17 00:00:00 2001 From: zaelgohary Date: Mon, 24 Nov 2025 12:53:23 +0200 Subject: [PATCH 1/6] Handle console interception overhead, add tests --- packages/playground/src/components/logger.vue | 103 +++++++++++------- .../tests/components/logger-batch-test.js | 95 ++++++++++++++++ 2 files changed, 159 insertions(+), 39 deletions(-) create mode 100644 packages/playground/tests/components/logger-batch-test.js diff --git a/packages/playground/src/components/logger.vue b/packages/playground/src/components/logger.vue index 62f143f594..10f862be5a 100644 --- a/packages/playground/src/components/logger.vue +++ b/packages/playground/src/components/logger.vue @@ -155,6 +155,7 @@ export default { _interceptorQueue.forEach(interceptMessage); _interceptorQueue = []; + if (logQueue.length > 0) flushLogQueue(); }, }); @@ -207,59 +208,79 @@ export default { interceptor.on(interceptMessage); - // This should be used if db failed to connect to be synced later let _interceptorQueue: LI[] = []; + const logQueue: LI[] = []; + let flushTimeout: ReturnType | null = null; + const BATCH_SIZE = 50; + const FLUSH_DELAY = 500; + + function scheduleFlush() { + if (flushTimeout) return; + flushTimeout = setTimeout(flushLogQueue, FLUSH_DELAY); + } + + async function flushLogQueue() { + if (logQueue.length === 0 || !connectDB?.value?.data) return; + + const batch = logQueue.splice(0, BATCH_SIZE); + const items: Indexed[] = []; + + for (const instance of batch) { + // eslint-disable-next-line @typescript-eslint/no-unused-vars + const { logger: _, date: __, ...log } = instance; + + const isViteDebug = + import.meta.env.DEV && log.type === "debug" && log.messages.map(String).join().includes("vite"); + if (isViteDebug) continue; + + try { + items.push( + await logsDBClient.write({ + type: log.type, + timestamp: log.timestamp, + message: log.messages.map(IndexedDBClient.serializer.serialize).join(" ").replace(/\n\s/g, "\n"), + }), + ); + } catch (error) { + console.error("Failed to write log to IndexedDB:", error); + } + } + + if (items.length > 0 && logs.value) { + logs.value.push(...items); + scrollToBottom(); + } + + flushTimeout = logQueue.length > 0 ? setTimeout(flushLogQueue, FLUSH_DELAY) : null; + } - async function interceptMessage(instance: LI) { + function interceptMessage(instance: LI) { if (connectDB?.value?.error) { _interceptorQueue.push(instance); return; } - // eslint-disable-next-line @typescript-eslint/no-unused-vars - const { logger: _, date: __, ...log } = instance; - - if (import.meta.env.DEV) { - if ( - log.messages - .map(v => { - try { - return String(v); - } catch { - return "{ [[null proto]] }"; - } - }) - .join() - .includes("vite") && - log.type === "debug" - ) { - return; - } - } - if (connectDB && connectDB.value.data) { - const item = await logsDBClient.write({ - type: log.type, - timestamp: log.timestamp, - message: log.messages.map(IndexedDBClient.serializer.serialize).join(" ").replace(/\n\s/g, "\n"), - }); - if (logs.value) { - logs.value.push(item); - scrollToBottom(); - } + if (!connectDB?.value?.data) return; + + logQueue.push(instance); + + if (logQueue.length >= BATCH_SIZE) { + flushTimeout && clearTimeout(flushTimeout); + flushTimeout = null; + return flushLogQueue(); } + + scheduleFlush(); } let _init_scroll = false; function scrollToBottom() { const el = scroller.value?.$el; - if (!el || el.scrollHeight === 0 || el.offsetHeight === 0) { - return; - } + if (!el || el.scrollHeight === 0 || el.offsetHeight === 0) return; + if (_init_scroll && el.scrollTop !== el.scrollHeight - el.offsetHeight) return; - if (!_init_scroll || el.scrollTop === el.scrollHeight - el.offsetHeight) { - _init_scroll = true; - scroller.value?.scrollToBottom(); - } + _init_scroll = true; + scroller.value?.scrollToBottom(); } async function downloadLogs() { @@ -281,6 +302,10 @@ export default { onBeforeUnmount(() => { document.removeEventListener("click", handleClickOutside); + if (flushTimeout) { + clearTimeout(flushTimeout); + flushLogQueue(); + } }); const handleClickOutside = (event: MouseEvent) => { diff --git a/packages/playground/tests/components/logger-batch-test.js b/packages/playground/tests/components/logger-batch-test.js new file mode 100644 index 0000000000..f45f10a479 --- /dev/null +++ b/packages/playground/tests/components/logger-batch-test.js @@ -0,0 +1,95 @@ +/** + * Logger Batching Test Script + * + * Run this in the browser console after opening the playground + * to verify the batching functionality works correctly. + * + * Usage: + * 1. Open playground in browser + * 2. Open Logger panel + * 3. Open browser console (F12) + * 4. Type "allow pasting" and press Enter (if Chrome shows warning) + * 5. Copy and paste this entire script + * 6. Watch the results + * + * Alternative: Use DevTools Snippets (no paste restriction): + * - Sources tab โ†’ Snippets โ†’ New snippet โ†’ Paste โ†’ Run + */ + +(async function testLoggerBatching() { + console.log("๐Ÿงช Starting Logger Batching Tests...\n"); + + // Test 1: Small batch (should wait 500ms) + console.log("Test 1: Small batch (10 logs) - should flush after ~500ms"); + const start1 = Date.now(); + for (let i = 0; i < 10; i++) { + console.log(`[Test 1] Log ${i + 1}`); + } + + await new Promise(resolve => setTimeout(resolve, 600)); + const elapsed1 = Date.now() - start1; + console.log(`โœ… Test 1 completed in ${elapsed1}ms (expected ~500ms delay)\n`); + + // Test 2: Batch size (50 logs - should flush immediately) + console.log("Test 2: Batch size (50 logs) - should flush immediately"); + const start2 = Date.now(); + for (let i = 0; i < 50; i++) { + console.log(`[Test 2] Log ${i + 1}`); + } + const elapsed2 = Date.now() - start2; + console.log(`โœ… Test 2 completed in ${elapsed2}ms (should be < 100ms for immediate flush)\n`); + + // Test 3: Large batch (200 logs - should batch in groups of 50) + console.log("Test 3: Large batch (200 logs) - should batch in groups"); + const start3 = Date.now(); + for (let i = 0; i < 200; i++) { + console.log(`[Test 3] Log ${i + 1}`); + } + await new Promise(resolve => setTimeout(resolve, 1000)); + const elapsed3 = Date.now() - start3; + console.log(`โœ… Test 3 completed in ${elapsed3}ms\n`); + + // Test 4: Check IndexedDB + console.log("Test 4: Verifying logs in IndexedDB..."); + try { + const request = indexedDB.open("TF_LOGGER_DB", 1); + request.onsuccess = e => { + const db = e.target.result; + const tx = db.transaction(["logs"], "readonly"); + const store = tx.objectStore("logs"); + + const countRequest = store.count(); + countRequest.onsuccess = () => { + console.log(`โœ… Found ${countRequest.result} logs in IndexedDB`); + + // Get recent logs + const index = store.index("timestamp"); + const getAllRequest = index.getAll(null, 260); // Get last 260 logs + getAllRequest.onsuccess = () => { + const testLogs = getAllRequest.result.filter( + log => + log.message.includes("[Test 1]") || log.message.includes("[Test 2]") || log.message.includes("[Test 3]"), + ); + console.log(`โœ… Found ${testLogs.length} test logs in IndexedDB`); + console.log("๐Ÿ“Š Test Summary:"); + console.log(` - Test 1 logs: ${testLogs.filter(l => l.message.includes("[Test 1]")).length}`); + console.log(` - Test 2 logs: ${testLogs.filter(l => l.message.includes("[Test 2]")).length}`); + console.log(` - Test 3 logs: ${testLogs.filter(l => l.message.includes("[Test 3]")).length}`); + console.log("\nโœ… All tests completed! Check the Logger panel to verify logs appear correctly."); + }; + }; + }; + } catch (error) { + console.error("โŒ Error checking IndexedDB:", error); + } + + // Performance test + console.log("\n๐Ÿ“Š Performance Test: Generating 100 logs..."); + const perfStart = performance.now(); + for (let i = 0; i < 100; i++) { + console.log(`[Perf] Log ${i + 1}`); + } + const perfEnd = performance.now(); + console.log(`โœ… Generated 100 logs in ${(perfEnd - perfStart).toFixed(2)}ms`); + console.log(" (This should be fast - actual writes happen asynchronously in batches)"); +})(); From 5b95f659d2774e74763a138e05786355925b5797 Mon Sep 17 00:00:00 2001 From: zaelgohary Date: Tue, 2 Dec 2025 12:23:49 +0200 Subject: [PATCH 2/6] Optimize dashboard logger batching and filtering --- packages/playground/src/components/logger.vue | 28 +++++++++++++++---- 1 file changed, 23 insertions(+), 5 deletions(-) diff --git a/packages/playground/src/components/logger.vue b/packages/playground/src/components/logger.vue index 10f862be5a..a2ab862245 100644 --- a/packages/playground/src/components/logger.vue +++ b/packages/playground/src/components/logger.vue @@ -140,6 +140,14 @@ export default { } const logs = ref[]>([]); + + /** + * Keep a reference to the original console.error so that internal + * logger failures don't recursively go through the interceptor and + * generate more log entries. + */ + const originalConsoleError = console.error.bind(console); + const interceptor = new LoggerInterceptor(console); const logsDBClient = new IndexedDBClient("TF_LOGGER_DB", VERSION, KEY); @@ -147,6 +155,8 @@ export default { init: true, async onAfterTask({ error }) { if (error) { + // Stop intercepting entirely on persistent DB failure. + interceptor.dispose(); return; } @@ -219,6 +229,8 @@ export default { flushTimeout = setTimeout(flushLogQueue, FLUSH_DELAY); } + const MAX_VISIBLE_LOGS = 2000; + async function flushLogQueue() { if (logQueue.length === 0 || !connectDB?.value?.data) return; @@ -229,10 +241,6 @@ export default { // eslint-disable-next-line @typescript-eslint/no-unused-vars const { logger: _, date: __, ...log } = instance; - const isViteDebug = - import.meta.env.DEV && log.type === "debug" && log.messages.map(String).join().includes("vite"); - if (isViteDebug) continue; - try { items.push( await logsDBClient.write({ @@ -242,12 +250,16 @@ export default { }), ); } catch (error) { - console.error("Failed to write log to IndexedDB:", error); + // Use the original console.error to avoid re-interception. + originalConsoleError("Failed to write log to IndexedDB:", error); } } if (items.length > 0 && logs.value) { logs.value.push(...items); + if (logs.value.length > MAX_VISIBLE_LOGS) { + logs.value.splice(0, logs.value.length - MAX_VISIBLE_LOGS); + } scrollToBottom(); } @@ -255,6 +267,12 @@ export default { } function interceptMessage(instance: LI) { + // Drop very noisy categories early to avoid unnecessary work. + const payload = instance.messages.map(String).join().toLowerCase(); + if (import.meta.env.DEV && (payload.includes("vite") || payload.includes("hmr") || payload.includes("webpack"))) { + return; + } + if (connectDB?.value?.error) { _interceptorQueue.push(instance); return; From f4a992c872a6821a8ba82e543a6dc70a191a544f Mon Sep 17 00:00:00 2001 From: zaelgohary Date: Tue, 2 Dec 2025 12:25:47 +0200 Subject: [PATCH 3/6] Remove test file --- .../tests/components/logger-batch-test.js | 95 ------------------- 1 file changed, 95 deletions(-) delete mode 100644 packages/playground/tests/components/logger-batch-test.js diff --git a/packages/playground/tests/components/logger-batch-test.js b/packages/playground/tests/components/logger-batch-test.js deleted file mode 100644 index f45f10a479..0000000000 --- a/packages/playground/tests/components/logger-batch-test.js +++ /dev/null @@ -1,95 +0,0 @@ -/** - * Logger Batching Test Script - * - * Run this in the browser console after opening the playground - * to verify the batching functionality works correctly. - * - * Usage: - * 1. Open playground in browser - * 2. Open Logger panel - * 3. Open browser console (F12) - * 4. Type "allow pasting" and press Enter (if Chrome shows warning) - * 5. Copy and paste this entire script - * 6. Watch the results - * - * Alternative: Use DevTools Snippets (no paste restriction): - * - Sources tab โ†’ Snippets โ†’ New snippet โ†’ Paste โ†’ Run - */ - -(async function testLoggerBatching() { - console.log("๐Ÿงช Starting Logger Batching Tests...\n"); - - // Test 1: Small batch (should wait 500ms) - console.log("Test 1: Small batch (10 logs) - should flush after ~500ms"); - const start1 = Date.now(); - for (let i = 0; i < 10; i++) { - console.log(`[Test 1] Log ${i + 1}`); - } - - await new Promise(resolve => setTimeout(resolve, 600)); - const elapsed1 = Date.now() - start1; - console.log(`โœ… Test 1 completed in ${elapsed1}ms (expected ~500ms delay)\n`); - - // Test 2: Batch size (50 logs - should flush immediately) - console.log("Test 2: Batch size (50 logs) - should flush immediately"); - const start2 = Date.now(); - for (let i = 0; i < 50; i++) { - console.log(`[Test 2] Log ${i + 1}`); - } - const elapsed2 = Date.now() - start2; - console.log(`โœ… Test 2 completed in ${elapsed2}ms (should be < 100ms for immediate flush)\n`); - - // Test 3: Large batch (200 logs - should batch in groups of 50) - console.log("Test 3: Large batch (200 logs) - should batch in groups"); - const start3 = Date.now(); - for (let i = 0; i < 200; i++) { - console.log(`[Test 3] Log ${i + 1}`); - } - await new Promise(resolve => setTimeout(resolve, 1000)); - const elapsed3 = Date.now() - start3; - console.log(`โœ… Test 3 completed in ${elapsed3}ms\n`); - - // Test 4: Check IndexedDB - console.log("Test 4: Verifying logs in IndexedDB..."); - try { - const request = indexedDB.open("TF_LOGGER_DB", 1); - request.onsuccess = e => { - const db = e.target.result; - const tx = db.transaction(["logs"], "readonly"); - const store = tx.objectStore("logs"); - - const countRequest = store.count(); - countRequest.onsuccess = () => { - console.log(`โœ… Found ${countRequest.result} logs in IndexedDB`); - - // Get recent logs - const index = store.index("timestamp"); - const getAllRequest = index.getAll(null, 260); // Get last 260 logs - getAllRequest.onsuccess = () => { - const testLogs = getAllRequest.result.filter( - log => - log.message.includes("[Test 1]") || log.message.includes("[Test 2]") || log.message.includes("[Test 3]"), - ); - console.log(`โœ… Found ${testLogs.length} test logs in IndexedDB`); - console.log("๐Ÿ“Š Test Summary:"); - console.log(` - Test 1 logs: ${testLogs.filter(l => l.message.includes("[Test 1]")).length}`); - console.log(` - Test 2 logs: ${testLogs.filter(l => l.message.includes("[Test 2]")).length}`); - console.log(` - Test 3 logs: ${testLogs.filter(l => l.message.includes("[Test 3]")).length}`); - console.log("\nโœ… All tests completed! Check the Logger panel to verify logs appear correctly."); - }; - }; - }; - } catch (error) { - console.error("โŒ Error checking IndexedDB:", error); - } - - // Performance test - console.log("\n๐Ÿ“Š Performance Test: Generating 100 logs..."); - const perfStart = performance.now(); - for (let i = 0; i < 100; i++) { - console.log(`[Perf] Log ${i + 1}`); - } - const perfEnd = performance.now(); - console.log(`โœ… Generated 100 logs in ${(perfEnd - perfStart).toFixed(2)}ms`); - console.log(" (This should be fast - actual writes happen asynchronously in batches)"); -})(); From 5f29477c69dc647015da80b0339b127b91d19380 Mon Sep 17 00:00:00 2001 From: zaelgohary Date: Tue, 2 Dec 2025 12:38:42 +0200 Subject: [PATCH 4/6] Remove webpack filter --- packages/playground/src/components/logger.vue | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/playground/src/components/logger.vue b/packages/playground/src/components/logger.vue index a2ab862245..59166aca16 100644 --- a/packages/playground/src/components/logger.vue +++ b/packages/playground/src/components/logger.vue @@ -269,7 +269,7 @@ export default { function interceptMessage(instance: LI) { // Drop very noisy categories early to avoid unnecessary work. const payload = instance.messages.map(String).join().toLowerCase(); - if (import.meta.env.DEV && (payload.includes("vite") || payload.includes("hmr") || payload.includes("webpack"))) { + if (import.meta.env.DEV && (payload.includes("vite") || payload.includes("hmr"))) { return; } From 3393bdb4cb3fe5624bacd856f177690de2c126b4 Mon Sep 17 00:00:00 2001 From: zaelgohary Date: Tue, 2 Dec 2025 14:31:15 +0200 Subject: [PATCH 5/6] Add IndexedDB log rotation and filter Vue warnings --- .../playground/src/clients/indexedDB/index.ts | 26 +++++++++++++++++++ packages/playground/src/components/logger.vue | 19 +++++++++++++- 2 files changed, 44 insertions(+), 1 deletion(-) diff --git a/packages/playground/src/clients/indexedDB/index.ts b/packages/playground/src/clients/indexedDB/index.ts index 31e9b0ba0a..08ae6ebdd6 100644 --- a/packages/playground/src/clients/indexedDB/index.ts +++ b/packages/playground/src/clients/indexedDB/index.ts @@ -140,6 +140,32 @@ export class IndexedDBClient { return res; } + public async deleteRange(startId: number, endId: number): Promise { + await this._lock.acquireAsync(); + + return new Promise((res, rej) => { + const store = this._createStore(); + const range = IDBKeyRange.bound(startId, endId); + const query = store.openCursor(range); + + query.onsuccess = () => { + const cursor = query.result; + if (cursor) { + cursor.delete(); + cursor.continue(); + } else { + this._lock.release(); + res(); + } + }; + + query.onerror = e => { + this._lock.release(); + rej(e); + }; + }); + } + public disconnect() { const db = this._assertConnection(); db.close(); diff --git a/packages/playground/src/components/logger.vue b/packages/playground/src/components/logger.vue index 59166aca16..ed138da60d 100644 --- a/packages/playground/src/components/logger.vue +++ b/packages/playground/src/components/logger.vue @@ -230,6 +230,8 @@ export default { } const MAX_VISIBLE_LOGS = 2000; + const MAX_STORED_LOGS = 10000; + const ROTATION_BUFFER = 1000; async function flushLogQueue() { if (logQueue.length === 0 || !connectDB?.value?.data) return; @@ -263,13 +265,28 @@ export default { scrollToBottom(); } + // Rotate old logs if count exceeds limit + const currentCount = await logsDBClient.count(); + if (currentCount > MAX_STORED_LOGS) { + const toDelete = currentCount - MAX_STORED_LOGS + ROTATION_BUFFER; + try { + await logsDBClient.deleteRange(1, toDelete); + count.value = await logsDBClient.count(); + } catch (error) { + originalConsoleError("Failed to rotate logs:", error); + } + } + flushTimeout = logQueue.length > 0 ? setTimeout(flushLogQueue, FLUSH_DELAY) : null; } function interceptMessage(instance: LI) { // Drop very noisy categories early to avoid unnecessary work. const payload = instance.messages.map(String).join().toLowerCase(); - if (import.meta.env.DEV && (payload.includes("vite") || payload.includes("hmr"))) { + if ( + instance.type === "warn" && + (payload.includes("vue") || payload.includes("vite") || payload.includes("hmr")) + ) { return; } From 5d9a3b3c75178e9ff8e4a440a2b00b7639f6a572 Mon Sep 17 00:00:00 2001 From: zaelgohary Date: Mon, 15 Dec 2025 01:52:24 +0200 Subject: [PATCH 6/6] Delete by count instead of range, fix concurrent rotation race condition --- .../playground/src/clients/indexedDB/index.ts | 10 ++++--- packages/playground/src/components/logger.vue | 26 ++++++++++++------- 2 files changed, 23 insertions(+), 13 deletions(-) diff --git a/packages/playground/src/clients/indexedDB/index.ts b/packages/playground/src/clients/indexedDB/index.ts index 08ae6ebdd6..27520e1ebb 100644 --- a/packages/playground/src/clients/indexedDB/index.ts +++ b/packages/playground/src/clients/indexedDB/index.ts @@ -140,18 +140,20 @@ export class IndexedDBClient { return res; } - public async deleteRange(startId: number, endId: number): Promise { + public async deleteOldestRecords(count: number): Promise { await this._lock.acquireAsync(); return new Promise((res, rej) => { const store = this._createStore(); - const range = IDBKeyRange.bound(startId, endId); - const query = store.openCursor(range); + const query = store.openCursor(); + + let deleted = 0; query.onsuccess = () => { const cursor = query.result; - if (cursor) { + if (cursor && deleted < count) { cursor.delete(); + deleted++; cursor.continue(); } else { this._lock.release(); diff --git a/packages/playground/src/components/logger.vue b/packages/playground/src/components/logger.vue index ed138da60d..7d8ae85d5b 100644 --- a/packages/playground/src/components/logger.vue +++ b/packages/playground/src/components/logger.vue @@ -221,6 +221,7 @@ export default { let _interceptorQueue: LI[] = []; const logQueue: LI[] = []; let flushTimeout: ReturnType | null = null; + let rotationPromise: Promise | null = null; // Prevent concurrent rotations const BATCH_SIZE = 50; const FLUSH_DELAY = 500; @@ -266,15 +267,22 @@ export default { } // Rotate old logs if count exceeds limit - const currentCount = await logsDBClient.count(); - if (currentCount > MAX_STORED_LOGS) { - const toDelete = currentCount - MAX_STORED_LOGS + ROTATION_BUFFER; - try { - await logsDBClient.deleteRange(1, toDelete); - count.value = await logsDBClient.count(); - } catch (error) { - originalConsoleError("Failed to rotate logs:", error); - } + if (!rotationPromise) { + rotationPromise = (async () => { + try { + const currentCount = await logsDBClient.count(); + if (currentCount > MAX_STORED_LOGS) { + const toDelete = currentCount - MAX_STORED_LOGS + ROTATION_BUFFER; + await logsDBClient.deleteOldestRecords(toDelete); + const afterCount = await logsDBClient.count(); + count.value = afterCount; + } + } catch (error) { + originalConsoleError("Failed to rotate logs:", error); + } finally { + rotationPromise = null; + } + })(); } flushTimeout = logQueue.length > 0 ? setTimeout(flushLogQueue, FLUSH_DELAY) : null;