diff --git a/packages/cli/src/gemini.tsx b/packages/cli/src/gemini.tsx index ea2dee43b..5e0074714 100644 --- a/packages/cli/src/gemini.tsx +++ b/packages/cli/src/gemini.tsx @@ -4,8 +4,13 @@ * SPDX-License-Identifier: Apache-2.0 */ -import type { Config } from '@qwen-code/qwen-code-core'; -import { InputFormat, logUserPrompt } from '@qwen-code/qwen-code-core'; +import { + InputFormat, + isDebugLoggingDegraded, + logUserPrompt, + Storage, + type Config, +} from '@qwen-code/qwen-code-core'; import { render } from 'ink'; import dns from 'node:dns'; import os from 'node:os'; @@ -419,6 +424,19 @@ export async function main() { return; } + // Print debug mode notice to stderr for non-interactive mode + if (config.getDebugMode()) { + console.error('Debug mode enabled'); + console.error( + `Logging to: ${Storage.getDebugLogPath(config.getSessionId())}`, + ); + if (isDebugLoggingDegraded()) { + console.error( + 'Warning: Debug logging is degraded (write failures occurred)', + ); + } + } + // For non-stream-json mode, initialize config here if (inputFormat !== InputFormat.STREAM_JSON) { await config.initialize(); diff --git a/packages/cli/src/ui/components/DebugModeNotification.tsx b/packages/cli/src/ui/components/DebugModeNotification.tsx new file mode 100644 index 000000000..316cde9df --- /dev/null +++ b/packages/cli/src/ui/components/DebugModeNotification.tsx @@ -0,0 +1,36 @@ +/** + * @license + * Copyright 2025 Google LLC + * SPDX-License-Identifier: Apache-2.0 + */ + +import { Box, Text } from 'ink'; +import { Storage, isDebugLoggingDegraded } from '@qwen-code/qwen-code-core'; +import { useConfig } from '../contexts/ConfigContext.js'; +import { theme } from '../semantic-colors.js'; + +/** + * Displays debug mode status and log file path when debug mode is enabled. + */ +export const DebugModeNotification = () => { + const config = useConfig(); + + if (!config.getDebugMode()) { + return null; + } + + const logPath = Storage.getDebugLogPath(config.getSessionId()); + const isDegraded = isDebugLoggingDegraded(); + + return ( + + Debug mode enabled + Logging to: {logPath} + {isDegraded && ( + + Warning: Debug logging is degraded (write failures occurred) + + )} + + ); +}; diff --git a/packages/cli/src/ui/components/Notifications.tsx b/packages/cli/src/ui/components/Notifications.tsx index a287b1052..74c3506ee 100644 --- a/packages/cli/src/ui/components/Notifications.tsx +++ b/packages/cli/src/ui/components/Notifications.tsx @@ -9,6 +9,7 @@ import { useAppContext } from '../contexts/AppContext.js'; import { useUIState } from '../contexts/UIStateContext.js'; import { theme } from '../semantic-colors.js'; import { StreamingState } from '../types.js'; +import { DebugModeNotification } from './DebugModeNotification.js'; import { UpdateNotification } from './UpdateNotification.js'; export const Notifications = () => { @@ -19,13 +20,10 @@ export const Notifications = () => { const showInitError = initError && streamingState !== StreamingState.Responding; - if (!showStartupWarnings && !showInitError && !updateInfo) { - return null; - } - return ( <> {updateInfo && } + {showStartupWarnings && ( { + const actual = await importOriginal(); + return { + ...actual, + promises: { + ...actual.promises, + mkdir: vi.fn().mockResolvedValue(undefined), + appendFile: vi.fn().mockResolvedValue(undefined), + }, + }; +}); + +describe('debugLogger', () => { + const mockSession: DebugLogSession = { + getSessionId: () => 'test-session-123', + }; + + beforeEach(() => { + vi.clearAllMocks(); + vi.useFakeTimers(); + vi.setSystemTime(new Date('2026-01-24T10:30:00.000Z')); + resetDebugLoggingState(); + }); + + afterEach(() => { + vi.useRealTimers(); + }); + + describe('createDebugLogger', () => { + it('returns no-op logger when session is null', () => { + const logger = createDebugLogger(null); + // Should not throw + logger.debug('test'); + logger.info('test'); + logger.warn('test'); + logger.error('test'); + expect(fs.appendFile).not.toHaveBeenCalled(); + }); + + it('returns no-op logger when session is undefined', () => { + const logger = createDebugLogger(undefined); + logger.debug('test'); + expect(fs.appendFile).not.toHaveBeenCalled(); + }); + + it('writes debug log with correct format', async () => { + const logger = createDebugLogger(mockSession); + logger.debug('Hello world'); + + await vi.runAllTimersAsync(); + + expect(fs.mkdir).toHaveBeenCalledWith(Storage.getGlobalDebugDir(), { + recursive: true, + }); + expect(fs.appendFile).toHaveBeenCalledWith( + Storage.getDebugLogPath('test-session-123'), + '2026-01-24T10:30:00.000Z [DEBUG] Hello world\n', + 'utf8', + ); + }); + + it('writes log with tag when provided', async () => { + const logger = createDebugLogger(mockSession, 'STARTUP'); + logger.info('Server started'); + + await vi.runAllTimersAsync(); + + expect(fs.appendFile).toHaveBeenCalledWith( + Storage.getDebugLogPath('test-session-123'), + '2026-01-24T10:30:00.000Z [INFO] [STARTUP] Server started\n', + 'utf8', + ); + }); + + it('writes different log levels correctly', async () => { + const logger = createDebugLogger(mockSession); + + logger.debug('debug message'); + logger.info('info message'); + logger.warn('warn message'); + logger.error('error message'); + + await vi.runAllTimersAsync(); + + const calls = vi.mocked(fs.appendFile).mock.calls; + expect(calls[0]?.[1]).toContain('[DEBUG]'); + expect(calls[1]?.[1]).toContain('[INFO]'); + expect(calls[2]?.[1]).toContain('[WARN]'); + expect(calls[3]?.[1]).toContain('[ERROR]'); + }); + + it('formats multiple arguments', async () => { + const logger = createDebugLogger(mockSession); + logger.debug('Count:', 42, 'items'); + + await vi.runAllTimersAsync(); + + expect(fs.appendFile).toHaveBeenCalledWith( + expect.any(String), + expect.stringContaining('Count: 42 items'), + 'utf8', + ); + }); + + it('formats Error objects with stack trace', async () => { + const logger = createDebugLogger(mockSession); + const error = new Error('Something went wrong'); + logger.error('Failed:', error); + + await vi.runAllTimersAsync(); + + const call = vi.mocked(fs.appendFile).mock.calls[0]; + expect(call?.[1]).toContain('Failed:'); + expect(call?.[1]).toContain('Error: Something went wrong'); + }); + + it('formats objects using util.inspect', async () => { + const logger = createDebugLogger(mockSession); + logger.debug('Data:', { foo: 'bar', count: 123 }); + + await vi.runAllTimersAsync(); + + const call = vi.mocked(fs.appendFile).mock.calls[0]; + expect(call?.[1]).toContain('foo'); + expect(call?.[1]).toContain('bar'); + }); + }); + + describe('isDebugLoggingDegraded', () => { + it('returns false when no failures have occurred', () => { + expect(isDebugLoggingDegraded()).toBe(false); + }); + + it('returns true when mkdir fails', async () => { + vi.mocked(fs.mkdir).mockRejectedValueOnce(new Error('Permission denied')); + + const logger = createDebugLogger(mockSession); + logger.debug('test'); + + await vi.runAllTimersAsync(); + + expect(isDebugLoggingDegraded()).toBe(true); + }); + + it('returns true when appendFile fails', async () => { + vi.mocked(fs.appendFile).mockRejectedValueOnce(new Error('Disk full')); + + const logger = createDebugLogger(mockSession); + logger.debug('test'); + + await vi.runAllTimersAsync(); + + expect(isDebugLoggingDegraded()).toBe(true); + }); + + it('stays true after failure even if subsequent writes succeed', async () => { + vi.mocked(fs.appendFile).mockRejectedValueOnce( + new Error('Temporary error'), + ); + + const logger = createDebugLogger(mockSession); + logger.debug('first write fails'); + await vi.runAllTimersAsync(); + + expect(isDebugLoggingDegraded()).toBe(true); + + // Reset mock to succeed + vi.mocked(fs.appendFile).mockResolvedValue(undefined); + logger.debug('second write succeeds'); + await vi.runAllTimersAsync(); + + // Should still be degraded + expect(isDebugLoggingDegraded()).toBe(true); + }); + }); + + describe('resetDebugLoggingState', () => { + it('resets the degraded state', async () => { + vi.mocked(fs.appendFile).mockRejectedValueOnce(new Error('Disk full')); + + const logger = createDebugLogger(mockSession); + logger.debug('test'); + await vi.runAllTimersAsync(); + + expect(isDebugLoggingDegraded()).toBe(true); + + resetDebugLoggingState(); + + expect(isDebugLoggingDegraded()).toBe(false); + }); + }); +}); diff --git a/packages/core/src/utils/debugLogger.ts b/packages/core/src/utils/debugLogger.ts new file mode 100644 index 000000000..fc3a31c6b --- /dev/null +++ b/packages/core/src/utils/debugLogger.ts @@ -0,0 +1,125 @@ +/** + * @license + * Copyright 2025 Google LLC + * SPDX-License-Identifier: Apache-2.0 + */ + +import { promises as fs } from 'node:fs'; +import util from 'node:util'; +import { Storage } from '../config/storage.js'; + +type LogLevel = 'DEBUG' | 'INFO' | 'WARN' | 'ERROR'; + +export interface DebugLogSession { + getSessionId: () => string; +} + +export interface DebugLogger { + debug: (...args: unknown[]) => void; + info: (...args: unknown[]) => void; + warn: (...args: unknown[]) => void; + error: (...args: unknown[]) => void; +} + +let ensureDebugDirPromise: Promise | null = null; +let hasWriteFailure = false; + +function ensureDebugDirExists(): Promise { + if (!ensureDebugDirPromise) { + ensureDebugDirPromise = fs + .mkdir(Storage.getGlobalDebugDir(), { recursive: true }) + .then(() => undefined) + .catch(() => { + hasWriteFailure = true; + ensureDebugDirPromise = null; + }); + } + return ensureDebugDirPromise ?? Promise.resolve(); +} + +function formatArgs(args: unknown[]): string { + return args + .map((arg) => { + if (arg instanceof Error) { + return arg.stack ?? `${arg.name}: ${arg.message}`; + } + return arg; + }) + .map((arg) => (typeof arg === 'string' ? arg : util.inspect(arg))) + .join(' '); +} + +/** + * Builds a log line in the format: + * `2026-01-23T06:58:02.011Z [DEBUG] [TAG] message` + * + * Tag is optional. If not provided, format is: + * `2026-01-23T06:58:02.011Z [DEBUG] message` + */ +function buildLogLine(level: LogLevel, message: string, tag?: string): string { + const timestamp = new Date().toISOString(); + const tagPart = tag ? ` [${tag}]` : ''; + return `${timestamp} [${level}]${tagPart} ${message}\n`; +} + +function writeLog( + session: DebugLogSession, + level: LogLevel, + tag: string | undefined, + args: unknown[], +): void { + const sessionId = session.getSessionId(); + const logFilePath = Storage.getDebugLogPath(sessionId); + const message = formatArgs(args); + const line = buildLogLine(level, message, tag); + + void ensureDebugDirExists() + .then(() => fs.appendFile(logFilePath, line, 'utf8')) + .catch(() => { + hasWriteFailure = true; + }); +} + +/** + * Returns true if any debug log write has failed. + * Used by the UI to show a degraded mode notice on startup. + */ +export function isDebugLoggingDegraded(): boolean { + return hasWriteFailure; +} + +/** + * Resets the write failure tracking state. + * Primarily useful for testing. + */ +export function resetDebugLoggingState(): void { + hasWriteFailure = false; + ensureDebugDirPromise = null; +} + +/** + * Creates a debug logger that writes to a session-specific log file. + * + * Log files are written to `~/.qwen/debug/.txt`. + * Write failures are silently ignored to avoid disrupting the user. + */ +export function createDebugLogger( + session: DebugLogSession | null | undefined, + tag?: string, +): DebugLogger { + if (!session) { + return { + debug: () => {}, + info: () => {}, + warn: () => {}, + error: () => {}, + }; + } + + return { + debug: (...args: unknown[]) => writeLog(session, 'DEBUG', tag, args), + info: (...args: unknown[]) => writeLog(session, 'INFO', tag, args), + warn: (...args: unknown[]) => writeLog(session, 'WARN', tag, args), + error: (...args: unknown[]) => writeLog(session, 'ERROR', tag, args), + }; +}