From 846cc75f103e6f94889b7533a200b70c07197866 Mon Sep 17 00:00:00 2001 From: tanzhenxin Date: Wed, 4 Feb 2026 22:41:31 +0800 Subject: [PATCH] refactor: streamline debug logging and remove Notifications component - Remove verbose tool execution debug logs to reduce noise - Add debug logging for config initialization phases - Add comprehensive debug logging for skill loading/management - Add rate limiting for QwenLogger network error logs - Remove Notifications component from DefaultAppLayout - Update tests to reflect UI changes and logging behavior Co-authored-by: Qwen-Coder --- packages/cli/src/ui/App.test.tsx | 4 +- .../cli/src/ui/components/MainContent.tsx | 4 + .../cli/src/ui/components/Notifications.tsx | 2 - packages/cli/src/ui/hooks/useGeminiStream.ts | 2 +- .../cli/src/ui/layouts/DefaultAppLayout.tsx | 3 - packages/core/src/config/config.ts | 13 ++- packages/core/src/skills/skill-load.ts | 25 ++++- packages/core/src/skills/skill-manager.ts | 95 +++++++++++++++++-- .../telemetry/qwen-logger/qwen-logger.test.ts | 6 +- .../src/telemetry/qwen-logger/qwen-logger.ts | 44 ++++----- packages/core/src/tools/shell.ts | 1 + packages/core/src/tools/write-file.ts | 4 +- packages/core/src/utils/memoryDiscovery.ts | 6 -- 13 files changed, 154 insertions(+), 55 deletions(-) diff --git a/packages/cli/src/ui/App.test.tsx b/packages/cli/src/ui/App.test.tsx index d8883e673..be09fe52f 100644 --- a/packages/cli/src/ui/App.test.tsx +++ b/packages/cli/src/ui/App.test.tsx @@ -66,7 +66,6 @@ describe('App', () => { ); expect(lastFrame()).toContain('MainContent'); - expect(lastFrame()).toContain('Notifications'); expect(lastFrame()).toContain('Composer'); }); @@ -98,7 +97,6 @@ describe('App', () => { ); expect(lastFrame()).toContain('MainContent'); - expect(lastFrame()).toContain('Notifications'); expect(lastFrame()).toContain('DialogManager'); }); @@ -157,6 +155,6 @@ describe('App', () => { , ); - expect(lastFrame()).toContain('MainContent\nNotifications\nComposer'); + expect(lastFrame()).toContain('MainContent\nComposer'); }); }); diff --git a/packages/cli/src/ui/components/MainContent.tsx b/packages/cli/src/ui/components/MainContent.tsx index db66607dd..a89583a0d 100644 --- a/packages/cli/src/ui/components/MainContent.tsx +++ b/packages/cli/src/ui/components/MainContent.tsx @@ -7,10 +7,12 @@ import { Box, Static } from 'ink'; import { HistoryItemDisplay } from './HistoryItemDisplay.js'; import { ShowMoreLines } from './ShowMoreLines.js'; +import { Notifications } from './Notifications.js'; import { OverflowProvider } from '../contexts/OverflowContext.js'; import { useUIState } from '../contexts/UIStateContext.js'; import { useAppContext } from '../contexts/AppContext.js'; import { AppHeader } from './AppHeader.js'; +import { DebugModeNotification } from './DebugModeNotification.js'; // Limit Gemini messages to a very high number of lines to mitigate performance // issues in the worst case if we somehow get an enormous response from Gemini. @@ -35,6 +37,8 @@ export const MainContent = () => { key={uiState.historyRemountKey} items={[ , + , + , ...uiState.history.map((h) => ( { @@ -23,7 +22,6 @@ export const Notifications = () => { return ( <> {updateInfo && } - {showStartupWarnings && ( { - - {uiState.dialogsVisible ? ( { @@ -1713,7 +1722,9 @@ export class Config { } await registry.discoverAllTools(); - this.debugLogger.debug('ToolRegistry created', registry.getAllToolNames()); + this.debugLogger.debug( + `ToolRegistry created: ${JSON.stringify(registry.getAllToolNames())} (${registry.getAllToolNames().length} tools)`, + ); return registry; } } diff --git a/packages/core/src/skills/skill-load.ts b/packages/core/src/skills/skill-load.ts index 8a77758b5..dc6f2c616 100644 --- a/packages/core/src/skills/skill-load.ts +++ b/packages/core/src/skills/skill-load.ts @@ -11,12 +11,18 @@ const SKILL_MANIFEST_FILE = 'SKILL.md'; export async function loadSkillsFromDir( baseDir: string, ): Promise { + debugLogger.debug(`Loading skills from directory (skill-load): ${baseDir}`); try { const entries = await fs.readdir(baseDir, { withFileTypes: true }); const skills: SkillConfig[] = []; + debugLogger.debug(`Found ${entries.length} entries in ${baseDir}`); + for (const entry of entries) { // Only process directories (each skill is a directory) - if (!entry.isDirectory()) continue; + if (!entry.isDirectory()) { + debugLogger.warn(`Skipping non-directory entry: ${entry.name}`); + continue; + } const skillDir = path.join(baseDir, entry.name); const skillManifest = path.join(skillDir, SKILL_MANIFEST_FILE); @@ -29,15 +35,23 @@ export async function loadSkillsFromDir( const config = parseSkillContent(content, skillManifest); skills.push(config); } catch (error) { - debugLogger.warn( - `Failed to parse skill at ${skillDir}: ${error instanceof Error ? error.message : 'Unknown error'}`, + const errorMessage = + error instanceof Error ? error.message : 'Unknown error'; + debugLogger.error( + `Failed to parse skill at ${skillDir}: ${errorMessage}`, ); continue; } } + return skills; - } catch (_error) { + } catch (error) { // Directory doesn't exist or can't be read + const errorMessage = + error instanceof Error ? error.message : 'Unknown error'; + debugLogger.debug( + `Cannot read skills directory ${baseDir}: ${errorMessage}`, + ); return []; } } @@ -61,6 +75,8 @@ export function parseSkillContent( content: string, filePath: string, ): SkillConfig { + debugLogger.debug(`Parsing skill content from: ${filePath}`); + // Normalize content to handle BOM and CRLF line endings const normalizedContent = normalizeSkillFileContent(content); @@ -121,6 +137,7 @@ export function parseSkillContent( throw new Error(`Validation failed: ${validation.errors.join(', ')}`); } + debugLogger.debug(`Successfully parsed skill: ${name} from ${filePath}`); return config; } diff --git a/packages/core/src/skills/skill-manager.ts b/packages/core/src/skills/skill-manager.ts index b8c1ffd23..8ee69e9a0 100644 --- a/packages/core/src/skills/skill-manager.ts +++ b/packages/core/src/skills/skill-manager.ts @@ -80,6 +80,9 @@ export class SkillManager { * @returns Array of skill configurations */ async listSkills(options: ListSkillsOptions = {}): Promise { + debugLogger.debug( + `Listing skills${options.level ? ` at level: ${options.level}` : ''}${options.force ? ' (forced refresh)' : ''}`, + ); const skills: SkillConfig[] = []; const seenNames = new Set(); @@ -92,16 +95,25 @@ export class SkillManager { // Initialize cache if it doesn't exist or we're forcing a refresh if (!shouldUseCache) { + debugLogger.debug('Cache miss or force refresh, reloading skills'); await this.refreshCache(); + } else { + debugLogger.debug('Using cached skills'); } // Collect skills from each level (project takes precedence over user over extension) for (const level of levelsToCheck) { const levelSkills = this.skillsCache?.get(level) || []; + debugLogger.debug( + `Processing ${levelSkills.length} ${level} level skills`, + ); for (const skill of levelSkills) { // Skip if we've already seen this name (precedence: project > user > extension) if (seenNames.has(skill.name)) { + debugLogger.debug( + `Skipping duplicate skill: ${skill.name} (${level})`, + ); continue; } @@ -113,6 +125,7 @@ export class SkillManager { // Sort by name for consistent ordering skills.sort((a, b) => a.name.localeCompare(b.name)); + debugLogger.info(`Listed ${skills.length} unique skills`); return skills; } @@ -129,24 +142,42 @@ export class SkillManager { name: string, level?: SkillLevel, ): Promise { + debugLogger.debug( + `Loading skill: ${name}${level ? ` at level: ${level}` : ''}`, + ); + if (level) { - return this.findSkillByNameAtLevel(name, level); + const skill = await this.findSkillByNameAtLevel(name, level); + if (skill) { + debugLogger.debug(`Found skill ${name} at ${level} level`); + } else { + debugLogger.debug(`Skill ${name} not found at ${level} level`); + } + return skill; } // Try project level first const projectSkill = await this.findSkillByNameAtLevel(name, 'project'); if (projectSkill) { + debugLogger.debug(`Found skill ${name} at project level`); return projectSkill; } // Try user level first const userSkill = await this.findSkillByNameAtLevel(name, 'user'); if (userSkill) { + debugLogger.debug(`Found skill ${name} at user level`); return userSkill; } // Try extension level - return this.findSkillByNameAtLevel(name, 'extension'); + const extensionSkill = await this.findSkillByNameAtLevel(name, 'extension'); + if (extensionSkill) { + debugLogger.debug(`Found skill ${name} at extension level`); + } else { + debugLogger.debug(`Skill ${name} not found at any level`); + } + return extensionSkill; } /** @@ -161,11 +192,18 @@ export class SkillManager { name: string, level?: SkillLevel, ): Promise { + debugLogger.debug( + `Loading skill for runtime: ${name}${level ? ` at level: ${level}` : ''}`, + ); const skill = await this.loadSkill(name, level); if (!skill) { + debugLogger.debug(`Skill not found for runtime: ${name}`); return null; } + debugLogger.info( + `Skill loaded for runtime: ${name} from ${skill.filePath}`, + ); return skill; } @@ -183,17 +221,24 @@ export class SkillManager { * Refreshes the skills cache by loading all skills from disk. */ async refreshCache(): Promise { + debugLogger.info('Refreshing skills cache...'); const skillsCache = new Map(); this.parseErrors.clear(); const levels: SkillLevel[] = ['project', 'user', 'extension']; + let totalSkills = 0; for (const level of levels) { const levelSkills = await this.listSkillsAtLevel(level); skillsCache.set(level, levelSkills); + totalSkills += levelSkills.length; + debugLogger.debug(`Loaded ${levelSkills.length} ${level} level skills`); } this.skillsCache = skillsCache; + debugLogger.info( + `Skills cache refreshed: ${totalSkills} total skills loaded`, + ); this.notifyChangeListeners(); } @@ -202,19 +247,23 @@ export class SkillManager { */ async startWatching(): Promise { if (this.watchStarted) { + debugLogger.debug('Skill watching already started, skipping'); return; } + debugLogger.info('Starting skill directory watchers...'); this.watchStarted = true; await this.ensureUserSkillsDir(); await this.refreshCache(); this.updateWatchersFromCache(); + debugLogger.info('Skill directory watchers started'); } /** * Stops watching skill directories for changes. */ stopWatching(): void { + debugLogger.info('Stopping skill directory watchers...'); for (const watcher of this.watchers.values()) { void watcher.close().catch((error) => { debugLogger.warn('Failed to close skills watcher:', error); @@ -226,6 +275,7 @@ export class SkillManager { clearTimeout(this.refreshTimer); this.refreshTimer = null; } + debugLogger.info('Skill directory watchers stopped'); } /** @@ -252,8 +302,13 @@ export class SkillManager { try { content = await fs.readFile(filePath, 'utf8'); } catch (error) { + const errorMessage = + error instanceof Error ? error.message : 'Unknown error'; + debugLogger.error( + `Failed to read skill file ${filePath}: ${errorMessage}`, + ); const skillError = new SkillError( - `Failed to read skill file: ${error instanceof Error ? error.message : 'Unknown error'}`, + `Failed to read skill file: ${errorMessage}`, SkillErrorCode.FILE_ERROR, ); this.parseErrors.set(filePath, skillError); @@ -338,6 +393,9 @@ export class SkillManager { throw new Error(`Validation failed: ${validation.errors.join(', ')}`); } + debugLogger.debug( + `Successfully parsed skill: ${name} (${level}) from ${filePath}`, + ); return config; } catch (error) { const skillError = new SkillError( @@ -382,6 +440,9 @@ export class SkillManager { // If project level is requested but project root is same as home directory, // return empty array to avoid conflicts between project and global skills if (level === 'project' && isHomeDirectory) { + debugLogger.debug( + 'Skipping project-level skills: project root is home directory', + ); return []; } @@ -393,12 +454,16 @@ export class SkillManager { skills.push(skill); }); } - + debugLogger.debug( + `Loaded ${skills.length} extension-level skills from ${extensions.length} extensions`, + ); return skills; } const baseDir = this.getSkillsBaseDir(level); + debugLogger.debug(`Loading ${level} level skills from: ${baseDir}`); const skills = await this.loadSkillsFromDir(baseDir, level); + debugLogger.debug(`Loaded ${skills.length} ${level} level skills`); return skills; } @@ -406,15 +471,21 @@ export class SkillManager { baseDir: string, level: SkillLevel, ): Promise { + debugLogger.debug(`Loading skills from directory: ${baseDir}`); try { const entries = await fs.readdir(baseDir, { withFileTypes: true }); const skills: SkillConfig[] = []; + debugLogger.debug(`Found ${entries.length} entries in ${baseDir}`); + for (const entry of entries) { // Check if it's a directory or a symlink const isDirectory = entry.isDirectory(); const isSymlink = entry.isSymbolicLink(); - if (!isDirectory && !isSymlink) continue; + if (!isDirectory && !isSymlink) { + debugLogger.warn(`Skipping non-directory entry: ${entry.name}`); + continue; + } const skillDir = path.join(baseDir, entry.name); @@ -451,16 +522,26 @@ export class SkillManager { // Skip directories without valid SKILL.md if (error instanceof SkillError) { // Parse error was already recorded - debugLogger.warn( + debugLogger.error( `Failed to parse skill at ${skillDir}: ${error.message}`, ); + } else { + debugLogger.debug( + `No valid SKILL.md found in ${skillDir}, skipping`, + ); } continue; } } + return skills; - } catch (_error) { + } catch (error) { // Directory doesn't exist or can't be read + const errorMessage = + error instanceof Error ? error.message : 'Unknown error'; + debugLogger.debug( + `Cannot read skills directory ${baseDir}: ${errorMessage}`, + ); return []; } } diff --git a/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts b/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts index 784a9d40a..749d6eede 100644 --- a/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts +++ b/packages/core/src/telemetry/qwen-logger/qwen-logger.test.ts @@ -400,10 +400,8 @@ describe('QwenLogger', () => { // Wait for async operations await vi.runAllTimersAsync(); - expect(debugLoggerSpy.debug).toHaveBeenCalledWith( - 'Error flushing to RUM:', - expect.any(Error), - ); + // Errors are now silently ignored to reduce log spam + // Only rate-limited error logs are emitted inside flushToRum itself // Restore original method logger.flushToRum = originalFlush; diff --git a/packages/core/src/telemetry/qwen-logger/qwen-logger.ts b/packages/core/src/telemetry/qwen-logger/qwen-logger.ts index 19c94b20c..21c09cc37 100644 --- a/packages/core/src/telemetry/qwen-logger/qwen-logger.ts +++ b/packages/core/src/telemetry/qwen-logger/qwen-logger.ts @@ -74,6 +74,11 @@ const RUN_APP_ID = 'gb4w8c3ygj@851d5d500f08f92'; */ const FLUSH_INTERVAL_MS = 1000 * 60; +/** + * Minimum interval between logging network errors to avoid log spam. + */ +const ERROR_LOG_INTERVAL_MS = 5 * 60 * 1000; // 5 minutes + /** * Maximum amount of events to keep in memory. Events added after this amount * are dropped until the next flush to RUM, which happens periodically as @@ -124,6 +129,11 @@ export class QwenLogger { */ private pendingFlush: boolean = false; + /** + * Timestamp of the last network error log to prevent log spam. + */ + private lastErrorLogTime: number = 0; + private constructor(config: Config) { this.config = config; this.debugLogger = createDebugLogger('QWEN_LOGGER'); @@ -269,9 +279,7 @@ export class QwenLogger { return; } - this.flushToRum().catch((error) => { - this.debugLogger.debug('Error flushing to RUM:', error); - }); + void this.flushToRum(); } async flushToRum(): Promise { @@ -284,7 +292,6 @@ export class QwenLogger { } this.isFlushInProgress = true; - this.debugLogger.debug('Flushing log events to RUM.'); if (this.events.size === 0) { this.isFlushInProgress = false; return {}; @@ -336,7 +343,12 @@ export class QwenLogger { this.lastFlushTime = Date.now(); return {}; } catch (error) { - this.debugLogger.error('RUM flush failed.', error); + // Only log network errors if sufficient time has passed to avoid spam + const now = Date.now(); + if (now - this.lastErrorLogTime > ERROR_LOG_INTERVAL_MS) { + this.debugLogger.error('RUM flush failed.', error); + this.lastErrorLogTime = now; + } // Re-queue failed events for retry this.requeueFailedEvents(eventsToSend); @@ -348,9 +360,7 @@ export class QwenLogger { if (this.pendingFlush) { this.pendingFlush = false; // Fire and forget the pending flush - this.flushToRum().catch((error) => { - this.debugLogger.debug('Error in pending flush to RUM:', error); - }); + void this.flushToRum(); } } } @@ -359,12 +369,7 @@ export class QwenLogger { async logStartSessionEvent(event: StartSessionEvent): Promise { // Flush all pending events with the old session ID first. // If flush fails, discard the pending events to avoid mixing sessions. - await this.flushToRum().catch((error: unknown) => { - this.debugLogger.debug( - 'Error flushing pending events before session start:', - error, - ); - }); + await this.flushToRum(); // Clear any remaining events (discard if flush failed) this.events.clear(); @@ -393,9 +398,7 @@ export class QwenLogger { // Flush start event immediately this.enqueueLogEvent(applicationEvent); - this.flushToRum().catch((error: unknown) => { - this.debugLogger.debug('Error flushing to RUM:', error); - }); + void this.flushToRum(); } logEndSessionEvent(_event: EndSessionEvent): void { @@ -403,9 +406,7 @@ export class QwenLogger { // Flush immediately on session end. this.enqueueLogEvent(applicationEvent); - this.flushToRum().catch((error: unknown) => { - this.debugLogger.debug('Error flushing to RUM:', error); - }); + void this.flushToRum(); } logConversationFinishedEvent(event: ConversationFinishedEvent): void { @@ -920,9 +921,6 @@ export class QwenLogger { const numEventsToRequeue = Math.min(eventsToRetry.length, availableSpace); if (numEventsToRequeue === 0) { - this.debugLogger.debug( - `QwenLogger: No events re-queued (queue size: ${this.events.size})`, - ); return; } diff --git a/packages/core/src/tools/shell.ts b/packages/core/src/tools/shell.ts index 0d49a5e8e..affe7946b 100644 --- a/packages/core/src/tools/shell.ts +++ b/packages/core/src/tools/shell.ts @@ -375,6 +375,7 @@ export class ShellToolInvocation extends BaseToolInvocation< }, } : {}; + if (summarizeConfig && summarizeConfig[ShellTool.Name]) { const summary = await summarizeToolOutput( llmContent, diff --git a/packages/core/src/tools/write-file.ts b/packages/core/src/tools/write-file.ts index 537148467..1ccb7bf0b 100644 --- a/packages/core/src/tools/write-file.ts +++ b/packages/core/src/tools/write-file.ts @@ -200,6 +200,7 @@ class WriteFileToolInvocation extends BaseToolInvocation< async execute(_abortSignal: AbortSignal): Promise { const { file_path, content, ai_proposed_content, modified_by_user } = this.params; + const correctedContentResult = await getCorrectedFileContent( this.config, file_path, @@ -297,12 +298,13 @@ class WriteFileToolInvocation extends BaseToolInvocation< const extension = path.extname(file_path); const operation = isNewFile ? FileOperation.CREATE : FileOperation.UPDATE; + const lineCount = fileContent.split('\n').length; logFileOperation( this.config, new FileOperationEvent( WriteFileTool.Name, operation, - fileContent.split('\n').length, + lineCount, mimetype, extension, programmingLanguage, diff --git a/packages/core/src/utils/memoryDiscovery.ts b/packages/core/src/utils/memoryDiscovery.ts index f0e86d903..2a891e84a 100644 --- a/packages/core/src/utils/memoryDiscovery.ts +++ b/packages/core/src/utils/memoryDiscovery.ts @@ -350,12 +350,6 @@ export async function loadServerHierarchicalMemory( memoryFilenames.has(path.basename(item.filePath)), ).length; - logger.debug(`Combined instructions length: ${combinedInstructions.length}`); - if (combinedInstructions.length > 0) { - logger.debug( - `Combined instructions (snippet): ${combinedInstructions.substring(0, 500)}...`, - ); - } return { memoryContent: combinedInstructions, fileCount, // Only count the context files