From f49d61f14d48576ca567972a4ef5057493a13d96 Mon Sep 17 00:00:00 2001 From: rob Date: Wed, 15 Oct 2025 23:56:15 -0300 Subject: [PATCH] increased logging --- src/debug-panel.js | 10 ++++- src/detector.js | 98 ++++++++++++++++++++++++++++++++++++++-------- src/logger.js | 2 +- 3 files changed, 91 insertions(+), 19 deletions(-) diff --git a/src/debug-panel.js b/src/debug-panel.js index 8e376fa..8af73cb 100644 --- a/src/debug-panel.js +++ b/src/debug-panel.js @@ -242,8 +242,14 @@ // Log level selector const sel = root.querySelector('.rc-level'); - sel.value = String(cfg().get('debug.level')); - sel.addEventListener('change', () => log().setLevel(parseInt(sel.value, 10))); + const currentLevel = cfg().get('debug.level'); + sel.value = String(currentLevel); + log().trace(`[Debug Panel] Current log level: ${currentLevel}`); + sel.addEventListener('change', () => { + const newLevel = parseInt(sel.value, 10); + log().setLevel(newLevel); + log().info(`[Debug Panel] Log level changed to ${newLevel}`); + }); // Copy buttons root.querySelector('.rc-copy').addEventListener('click', (e) => { diff --git a/src/detector.js b/src/detector.js index 7c20e45..f243f4a 100644 --- a/src/detector.js +++ b/src/detector.js @@ -41,73 +41,139 @@ this.clusterWindowMs = 1000; } start() { + if (this.observer) { + log().warn('[Detector] Already started, skipping'); + return; + } + + log().info('[Detector] Starting advanced detector with settle/debounce'); + this.observer = new MutationObserver((mutations) => { - if (cfg().get('runtime.paused')) return; - let should = false; + if (cfg().get('runtime.paused')) { + log().trace('[Detector] Mutations ignored (paused)'); + return; + } + + let assistantMsgs = 0; for (const m of mutations) { if (m.type === 'childList') { for (const n of m.addedNodes) { - if (n.nodeType === 1 && isAssistantMsg(n)) { void this._handle(n); should = true; } + if (n.nodeType === 1 && isAssistantMsg(n)) { + assistantMsgs++; + void this._handle(n); + } } } if (m.type === 'characterData') { const el = m.target?.parentElement; - if (el && isAssistantMsg(el)) should = true; + if (el && isAssistantMsg(el)) { + log().trace('[Detector] Text changed in assistant message'); + } } } - if (should) {/* no-op: _handle already queued */} + + if (assistantMsgs > 0) { + log().verbose(`[Detector] Detected ${assistantMsgs} new assistant message(s)`); + } }); + this.observer.observe(document.body, { childList: true, subtree: true, characterData: true, attributes: true }); + log().verbose('[Detector] MutationObserver attached (childList, subtree, characterData, attributes)'); + if (cfg().get('ui.processExisting')) { - document.querySelectorAll('[data-message-author-role], .chat-message, .message-content') - .forEach(el => isAssistantMsg(el) && void this._handle(el)); + log().verbose('[Detector] Processing existing messages on page'); + const nodes = document.querySelectorAll('[data-message-author-role], .chat-message, .message-content'); + log().trace(`[Detector] Found ${nodes.length} potential message nodes`); + nodes.forEach(el => { + if (isAssistantMsg(el)) { + void this._handle(el); + } + }); } - log().info('Detector started'); + + log().info('[Detector] Detector started and monitoring'); } async _handle(el) { - if (this.processed.has(el)) return; + if (this.processed.has(el)) { + log().trace('[Detector] Message already processed by detector'); + return; + } this.processed.add(el); + log().verbose('[Detector] Processing new assistant message'); + // Debounce complete generation const debounce = cfg().get('execution.debounceDelay') || 0; - if (debounce > 0) await new Promise(r => setTimeout(r, debounce)); + if (debounce > 0) { + log().trace(`[Detector] Debouncing for ${debounce}ms`); + await new Promise(r => setTimeout(r, debounce)); + } // Settle const baseText = el.textContent || ''; + log().trace('[Detector] Starting text settle check', { textLength: baseText.length }); const stable = await settleText(el, baseText, cfg().get('execution.settleCheckMs') || 1200, cfg().get('execution.settlePollMs') || 250); + const blocks = extractAllBlocks(stable); - if (!blocks.length) { this.processed.delete(el); return; } // not a command after all + log().verbose(`[Detector] Found ${blocks.length} command block(s) after settling`); + + if (!blocks.length) { + log().trace('[Detector] No command blocks found, removing from processed set'); + this.processed.delete(el); + return; + } const maxPerMsg = cfg().get('queue.maxPerMessage') || 5; - blocks.slice(0, maxPerMsg).forEach((cmdText, idx) => this._enqueueOne(el, cmdText, idx)); + if (blocks.length > maxPerMsg) { + log().warn(`[Detector] Message has ${blocks.length} commands, limiting to ${maxPerMsg}`); + } + + blocks.slice(0, maxPerMsg).forEach((cmdText, idx) => { + log().verbose(`[Detector] Enqueueing command #${idx + 1}`); + this._enqueueOne(el, cmdText, idx); + }); // Cluster rescan: look ahead a few assistant messages for chained blocks + log().trace(`[Detector] Scheduling cluster rescan in ${this.clusterWindowMs}ms`); setTimeout(() => this._clusterRescan(el), this.clusterWindowMs); } _enqueueOne(el, commandText, idx) { const history = window.AI_REPO_HISTORY; + if (history.isProcessed(el, idx)) { + log().verbose(`[Detector] Command #${idx + 1} already processed, adding retry button`); this._addRunAgain(el, commandText, idx); return; } + + log().trace(`[Detector] Marking command #${idx + 1} as processed in history`); history.markProcessed(el, idx); + log().verbose(`[Detector] Pushing command #${idx + 1} to queue`); window.AI_REPO_QUEUE.push(async () => { try { + log().trace(`[Detector] Parsing command #${idx + 1}`); const parsed = window.AI_REPO_PARSER.parse(commandText); + log().verbose(`[Detector] Parsed: ${parsed.action}`, { repo: parsed.repo, path: parsed.path }); + const v = window.AI_REPO_PARSER.validate(parsed); if (!v.isValid) { - // Handle validation failures inline instead of throwing; avoid local throw/catch - try { log().warn?.('Validation failed', { errors: v.errors }); } catch {} + log().warn('[Detector] Validation failed', { errors: v.errors, action: parsed.action }); this._addRunAgain(el, commandText, idx); return; } - if (v.example) { log().info('Example command skipped'); return; } + + if (v.example) { + log().info('[Detector] Example command skipped', { action: parsed.action }); + return; + } + + log().verbose(`[Detector] Executing command #${idx + 1}: ${parsed.action}`); await window.AI_REPO_EXECUTOR.execute(parsed, el, `[${idx + 1}] ${parsed.action}`); } catch (e) { - log().error('Command failed', { error: e.message }); + log().error('[Detector] Command execution failed', { error: e.message, stack: e.stack?.slice(0, 150) }); this._addRunAgain(el, commandText, idx); } }); diff --git a/src/logger.js b/src/logger.js index 0b7dec5..9c8b937 100644 --- a/src/logger.js +++ b/src/logger.js @@ -121,7 +121,7 @@ } setLevel(n) { - const lv = Math.max(0, Math.min(4, n)); + const lv = Math.max(0, Math.min(5, n)); this.config.set('debug.level', lv); this.info(`Log level => ${lv}`); }