From 21fef1620d78f07af01a75b8bbbeeb15798e73ef Mon Sep 17 00:00:00 2001 From: Jacob Richman Date: Fri, 25 Jul 2025 17:35:26 -0700 Subject: [PATCH] Handle unhandled rejections more gracefully. (#4417) Co-authored-by: Tommaso Sciortino --- packages/cli/src/gemini.test.tsx | 66 ++++- packages/cli/src/gemini.tsx | 39 +-- packages/cli/src/ui/App.test.tsx | 42 +++- packages/cli/src/ui/App.tsx | 28 ++- .../src/ui/hooks/useConsoleMessages.test.ts | 227 +++++++----------- .../cli/src/ui/hooks/useConsoleMessages.ts | 119 +++++---- packages/cli/src/utils/events.ts | 14 ++ 7 files changed, 321 insertions(+), 214 deletions(-) create mode 100644 packages/cli/src/utils/events.ts diff --git a/packages/cli/src/gemini.test.tsx b/packages/cli/src/gemini.test.tsx index 20350815..505841c7 100644 --- a/packages/cli/src/gemini.test.tsx +++ b/packages/cli/src/gemini.test.tsx @@ -6,12 +6,13 @@ import stripAnsi from 'strip-ansi'; import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; -import { main } from './gemini.js'; +import { main, setupUnhandledRejectionHandler } from './gemini.js'; import { LoadedSettings, SettingsFile, loadSettings, } from './config/settings.js'; +import { appEvents, AppEvent } from './utils/events.js'; // Custom error to identify mock process.exit calls class MockProcessExitError extends Error { @@ -55,6 +56,16 @@ vi.mock('update-notifier', () => ({ })), })); +vi.mock('./utils/events.js', async (importOriginal) => { + const actual = await importOriginal(); + return { + ...actual, + appEvents: { + emit: vi.fn(), + }, + }; +}); + vi.mock('./utils/sandbox.js', () => ({ sandbox_command: vi.fn(() => ''), // Default to no sandbox command start_sandbox: vi.fn(() => Promise.resolve()), // Mock as an async function that resolves @@ -65,6 +76,8 @@ describe('gemini.tsx main function', () => { let loadSettingsMock: ReturnType>; let originalEnvGeminiSandbox: string | undefined; let originalEnvSandbox: string | undefined; + let initialUnhandledRejectionListeners: NodeJS.UnhandledRejectionListener[] = + []; const processExitSpy = vi .spyOn(process, 'exit') @@ -82,6 +95,8 @@ describe('gemini.tsx main function', () => { delete process.env.SANDBOX; consoleErrorSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); + initialUnhandledRejectionListeners = + process.listeners('unhandledRejection'); }); afterEach(() => { @@ -96,6 +111,15 @@ describe('gemini.tsx main function', () => { } else { delete process.env.SANDBOX; } + + const currentListeners = process.listeners('unhandledRejection'); + const addedListener = currentListeners.find( + (listener) => !initialUnhandledRejectionListeners.includes(listener), + ); + + if (addedListener) { + process.removeListener('unhandledRejection', addedListener); + } vi.restoreAllMocks(); }); @@ -145,7 +169,45 @@ describe('gemini.tsx main function', () => { 'Please fix /test/settings.json and try again.', ); - // Verify process.exit was called (indirectly, via the thrown error) + // Verify process.exit was called. expect(processExitSpy).toHaveBeenCalledWith(1); }); + + it('should log unhandled promise rejections and open debug console on first error', async () => { + const appEventsMock = vi.mocked(appEvents); + const rejectionError = new Error('Test unhandled rejection'); + + setupUnhandledRejectionHandler(); + // Simulate an unhandled rejection. + // We are not using Promise.reject here as vitest will catch it. + // Instead we will dispatch the event manually. + process.emit('unhandledRejection', rejectionError, Promise.resolve()); + + // We need to wait for the rejection handler to be called. + await new Promise(process.nextTick); + + expect(appEventsMock.emit).toHaveBeenCalledWith(AppEvent.OpenDebugConsole); + expect(appEventsMock.emit).toHaveBeenCalledWith( + AppEvent.LogError, + expect.stringContaining('Unhandled Promise Rejection'), + ); + expect(appEventsMock.emit).toHaveBeenCalledWith( + AppEvent.LogError, + expect.stringContaining('Please file a bug report using the /bug tool.'), + ); + + // Simulate a second rejection + const secondRejectionError = new Error('Second test unhandled rejection'); + process.emit('unhandledRejection', secondRejectionError, Promise.resolve()); + await new Promise(process.nextTick); + + // Ensure emit was only called once for OpenDebugConsole + const openDebugConsoleCalls = appEventsMock.emit.mock.calls.filter( + (call) => call[0] === AppEvent.OpenDebugConsole, + ); + expect(openDebugConsoleCalls.length).toBe(1); + + // Avoid the process.exit error from being thrown. + processExitSpy.mockRestore(); + }); }); diff --git a/packages/cli/src/gemini.tsx b/packages/cli/src/gemini.tsx index 2023431f..c771fb95 100644 --- a/packages/cli/src/gemini.tsx +++ b/packages/cli/src/gemini.tsx @@ -40,6 +40,7 @@ import { import { validateAuthMethod } from './config/auth.js'; import { setMaxSizedBoxDebugging } from './ui/components/shared/MaxSizedBox.js'; import { validateNonInteractiveAuth } from './validateNonInterActiveAuth.js'; +import { appEvents, AppEvent } from './utils/events.js'; function getNodeMemoryArgs(config: Config): string[] { const totalMemoryMB = os.totalmem() / (1024 * 1024); @@ -86,7 +87,30 @@ async function relaunchWithAdditionalArgs(additionalArgs: string[]) { } import { runAcpPeer } from './acp/acpPeer.js'; +export function setupUnhandledRejectionHandler() { + let unhandledRejectionOccurred = false; + process.on('unhandledRejection', (reason, _promise) => { + const errorMessage = `========================================= +This is an unexpected error. Please file a bug report using the /bug tool. +CRITICAL: Unhandled Promise Rejection! +========================================= +Reason: ${reason}${ + reason instanceof Error && reason.stack + ? ` +Stack trace: +${reason.stack}` + : '' + }`; + appEvents.emit(AppEvent.LogError, errorMessage); + if (!unhandledRejectionOccurred) { + unhandledRejectionOccurred = true; + appEvents.emit(AppEvent.OpenDebugConsole); + } + }); +} + export async function main() { + setupUnhandledRejectionHandler(); const workspaceRoot = process.cwd(); const settings = loadSettings(workspaceRoot); @@ -272,21 +296,6 @@ function setWindowTitle(title: string, settings: LoadedSettings) { } } -// --- Global Unhandled Rejection Handler --- -process.on('unhandledRejection', (reason, _promise) => { - // Log other unexpected unhandled rejections as critical errors - console.error('========================================='); - console.error('CRITICAL: Unhandled Promise Rejection!'); - console.error('========================================='); - console.error('Reason:', reason); - console.error('Stack trace may follow:'); - if (!(reason instanceof Error)) { - console.error(reason); - } - // Exit for genuinely unhandled errors - process.exit(1); -}); - async function loadNonInteractiveConfig( config: Config, extensions: Extension[], diff --git a/packages/cli/src/ui/App.test.tsx b/packages/cli/src/ui/App.test.tsx index 903f4b66..4abf2d06 100644 --- a/packages/cli/src/ui/App.test.tsx +++ b/packages/cli/src/ui/App.test.tsx @@ -20,7 +20,8 @@ import { import { LoadedSettings, SettingsFile, Settings } from '../config/settings.js'; import process from 'node:process'; import { useGeminiStream } from './hooks/useGeminiStream.js'; -import { StreamingState } from './types.js'; +import { useConsoleMessages } from './hooks/useConsoleMessages.js'; +import { StreamingState, ConsoleMessageItem } from './types.js'; import { Tips } from './components/Tips.js'; // Define a more complete mock server config based on actual Config @@ -192,6 +193,14 @@ vi.mock('./hooks/useLogger', () => ({ })), })); +vi.mock('./hooks/useConsoleMessages.js', () => ({ + useConsoleMessages: vi.fn(() => ({ + consoleMessages: [], + handleNewMessage: vi.fn(), + clearConsoleMessages: vi.fn(), + })), +})); + vi.mock('../config/config.js', async (importOriginal) => { const actual = await importOriginal(); return { @@ -692,4 +701,35 @@ describe('App UI', () => { ); }); }); + + describe('errorCount', () => { + it('should correctly sum the counts of error messages', async () => { + const mockConsoleMessages: ConsoleMessageItem[] = [ + { type: 'error', content: 'First error', count: 1 }, + { type: 'log', content: 'some log', count: 1 }, + { type: 'error', content: 'Second error', count: 3 }, + { type: 'warn', content: 'a warning', count: 1 }, + { type: 'error', content: 'Third error', count: 1 }, + ]; + + vi.mocked(useConsoleMessages).mockReturnValue({ + consoleMessages: mockConsoleMessages, + handleNewMessage: vi.fn(), + clearConsoleMessages: vi.fn(), + }); + + const { lastFrame, unmount } = render( + , + ); + currentUnmount = unmount; + await Promise.resolve(); + + // Total error count should be 1 + 3 + 1 = 5 + expect(lastFrame()).toContain('5 errors'); + }); + }); }); diff --git a/packages/cli/src/ui/App.tsx b/packages/cli/src/ui/App.tsx index da01521b..6163ac51 100644 --- a/packages/cli/src/ui/App.tsx +++ b/packages/cli/src/ui/App.tsx @@ -87,6 +87,7 @@ import ansiEscapes from 'ansi-escapes'; import { OverflowProvider } from './contexts/OverflowContext.js'; import { ShowMoreLines } from './components/ShowMoreLines.js'; import { PrivacyNotice } from './privacy/PrivacyNotice.js'; +import { appEvents, AppEvent } from '../utils/events.js'; const CTRL_EXIT_PROMPT_DURATION_MS = 1000; @@ -176,13 +177,38 @@ const App = ({ config, settings, startupWarnings = [], version }: AppProps) => { return unsubscribe; }, []); + useEffect(() => { + const openDebugConsole = () => { + setShowErrorDetails(true); + setConstrainHeight(false); // Make sure the user sees the full message. + }; + appEvents.on(AppEvent.OpenDebugConsole, openDebugConsole); + + const logErrorHandler = (errorMessage: unknown) => { + handleNewMessage({ + type: 'error', + content: String(errorMessage), + count: 1, + }); + }; + appEvents.on(AppEvent.LogError, logErrorHandler); + + return () => { + appEvents.off(AppEvent.OpenDebugConsole, openDebugConsole); + appEvents.off(AppEvent.LogError, logErrorHandler); + }; + }, [handleNewMessage]); + const openPrivacyNotice = useCallback(() => { setShowPrivacyNotice(true); }, []); const initialPromptSubmitted = useRef(false); const errorCount = useMemo( - () => consoleMessages.filter((msg) => msg.type === 'error').length, + () => + consoleMessages + .filter((msg) => msg.type === 'error') + .reduce((total, msg) => total + msg.count, 0), [consoleMessages], ); diff --git a/packages/cli/src/ui/hooks/useConsoleMessages.test.ts b/packages/cli/src/ui/hooks/useConsoleMessages.test.ts index 3b225ecf..b1d1acd6 100644 --- a/packages/cli/src/ui/hooks/useConsoleMessages.test.ts +++ b/packages/cli/src/ui/hooks/useConsoleMessages.test.ts @@ -5,127 +5,105 @@ */ import { act, renderHook } from '@testing-library/react'; -import { useConsoleMessages } from './useConsoleMessages.js'; -import { ConsoleMessageItem } from '../types.js'; - -// Mock setTimeout and clearTimeout -vi.useFakeTimers(); +import { vi } from 'vitest'; +import { useConsoleMessages } from './useConsoleMessages'; +import { useCallback } from 'react'; describe('useConsoleMessages', () => { + beforeEach(() => { + vi.useFakeTimers(); + }); + + afterEach(() => { + vi.runOnlyPendingTimers(); + vi.useRealTimers(); + }); + + const useTestableConsoleMessages = () => { + const { handleNewMessage, ...rest } = useConsoleMessages(); + const log = useCallback( + (content: string) => handleNewMessage({ type: 'log', content, count: 1 }), + [handleNewMessage], + ); + const error = useCallback( + (content: string) => + handleNewMessage({ type: 'error', content, count: 1 }), + [handleNewMessage], + ); + return { + ...rest, + log, + error, + clearConsoleMessages: rest.clearConsoleMessages, + }; + }; + it('should initialize with an empty array of console messages', () => { - const { result } = renderHook(() => useConsoleMessages()); + const { result } = renderHook(() => useTestableConsoleMessages()); expect(result.current.consoleMessages).toEqual([]); }); - it('should add a new message', () => { - const { result } = renderHook(() => useConsoleMessages()); - const message: ConsoleMessageItem = { - type: 'log', - content: 'Test message', - count: 1, - }; + it('should add a new message when log is called', async () => { + const { result } = renderHook(() => useTestableConsoleMessages()); act(() => { - result.current.handleNewMessage(message); + result.current.log('Test message'); }); - act(() => { - vi.runAllTimers(); // Process the queue - }); - - expect(result.current.consoleMessages).toEqual([{ ...message, count: 1 }]); - }); - - it('should consolidate identical consecutive messages', () => { - const { result } = renderHook(() => useConsoleMessages()); - const message: ConsoleMessageItem = { - type: 'log', - content: 'Test message', - count: 1, - }; - - act(() => { - result.current.handleNewMessage(message); - result.current.handleNewMessage(message); - }); - - act(() => { - vi.runAllTimers(); - }); - - expect(result.current.consoleMessages).toEqual([{ ...message, count: 2 }]); - }); - - it('should not consolidate different messages', () => { - const { result } = renderHook(() => useConsoleMessages()); - const message1: ConsoleMessageItem = { - type: 'log', - content: 'Test message 1', - count: 1, - }; - const message2: ConsoleMessageItem = { - type: 'error', - content: 'Test message 2', - count: 1, - }; - - act(() => { - result.current.handleNewMessage(message1); - result.current.handleNewMessage(message2); - }); - - act(() => { - vi.runAllTimers(); + await act(async () => { + await vi.advanceTimersByTimeAsync(20); }); expect(result.current.consoleMessages).toEqual([ - { ...message1, count: 1 }, - { ...message2, count: 1 }, + { type: 'log', content: 'Test message', count: 1 }, ]); }); - it('should not consolidate messages if type is different', () => { - const { result } = renderHook(() => useConsoleMessages()); - const message1: ConsoleMessageItem = { - type: 'log', - content: 'Test message', - count: 1, - }; - const message2: ConsoleMessageItem = { - type: 'error', - content: 'Test message', - count: 1, - }; + it('should batch and count identical consecutive messages', async () => { + const { result } = renderHook(() => useTestableConsoleMessages()); act(() => { - result.current.handleNewMessage(message1); - result.current.handleNewMessage(message2); + result.current.log('Test message'); + result.current.log('Test message'); + result.current.log('Test message'); }); - act(() => { - vi.runAllTimers(); + await act(async () => { + await vi.advanceTimersByTimeAsync(20); }); expect(result.current.consoleMessages).toEqual([ - { ...message1, count: 1 }, - { ...message2, count: 1 }, + { type: 'log', content: 'Test message', count: 3 }, ]); }); - it('should clear console messages', () => { - const { result } = renderHook(() => useConsoleMessages()); - const message: ConsoleMessageItem = { - type: 'log', - content: 'Test message', - count: 1, - }; + it('should not batch different messages', async () => { + const { result } = renderHook(() => useTestableConsoleMessages()); act(() => { - result.current.handleNewMessage(message); + result.current.log('First message'); + result.current.error('Second message'); }); + await act(async () => { + await vi.advanceTimersByTimeAsync(20); + }); + + expect(result.current.consoleMessages).toEqual([ + { type: 'log', content: 'First message', count: 1 }, + { type: 'error', content: 'Second message', count: 1 }, + ]); + }); + + it('should clear all messages when clearConsoleMessages is called', async () => { + const { result } = renderHook(() => useTestableConsoleMessages()); + act(() => { - vi.runAllTimers(); + result.current.log('A message'); + }); + + await act(async () => { + await vi.advanceTimersByTimeAsync(20); }); expect(result.current.consoleMessages).toHaveLength(1); @@ -134,79 +112,36 @@ describe('useConsoleMessages', () => { result.current.clearConsoleMessages(); }); - expect(result.current.consoleMessages).toEqual([]); + expect(result.current.consoleMessages).toHaveLength(0); }); - it('should clear pending timeout on clearConsoleMessages', () => { - const { result } = renderHook(() => useConsoleMessages()); - const message: ConsoleMessageItem = { - type: 'log', - content: 'Test message', - count: 1, - }; + it('should clear the pending timeout when clearConsoleMessages is called', () => { + const { result } = renderHook(() => useTestableConsoleMessages()); + const clearTimeoutSpy = vi.spyOn(global, 'clearTimeout'); act(() => { - result.current.handleNewMessage(message); // This schedules a timeout + result.current.log('A message'); }); act(() => { result.current.clearConsoleMessages(); }); - // Ensure the queue is empty and no more messages are processed - act(() => { - vi.runAllTimers(); // If timeout wasn't cleared, this would process the queue - }); - - expect(result.current.consoleMessages).toEqual([]); + expect(clearTimeoutSpy).toHaveBeenCalled(); + clearTimeoutSpy.mockRestore(); }); - it('should clear message queue on clearConsoleMessages', () => { - const { result } = renderHook(() => useConsoleMessages()); - const message: ConsoleMessageItem = { - type: 'log', - content: 'Test message', - count: 1, - }; + it('should clean up the timeout on unmount', () => { + const { result, unmount } = renderHook(() => useTestableConsoleMessages()); + const clearTimeoutSpy = vi.spyOn(global, 'clearTimeout'); act(() => { - // Add a message but don't process the queue yet - result.current.handleNewMessage(message); - }); - - act(() => { - result.current.clearConsoleMessages(); - }); - - // Process any pending timeouts (should be none related to message queue) - act(() => { - vi.runAllTimers(); - }); - - // The consoleMessages should be empty because the queue was cleared before processing - expect(result.current.consoleMessages).toEqual([]); - }); - - it('should cleanup timeout on unmount', () => { - const { result, unmount } = renderHook(() => useConsoleMessages()); - const message: ConsoleMessageItem = { - type: 'log', - content: 'Test message', - count: 1, - }; - - act(() => { - result.current.handleNewMessage(message); + result.current.log('A message'); }); unmount(); - // This is a bit indirect. We check that clearTimeout was called. - // If clearTimeout was not called, and we run timers, an error might occur - // or the state might change, which it shouldn't after unmount. - // Vitest's vi.clearAllTimers() or specific checks for clearTimeout calls - // would be more direct if available and easy to set up here. - // For now, we rely on the useEffect cleanup pattern. - expect(vi.getTimerCount()).toBe(0); // Check if all timers are cleared + expect(clearTimeoutSpy).toHaveBeenCalled(); + clearTimeoutSpy.mockRestore(); }); }); diff --git a/packages/cli/src/ui/hooks/useConsoleMessages.ts b/packages/cli/src/ui/hooks/useConsoleMessages.ts index 52ffbd39..3b71560e 100644 --- a/packages/cli/src/ui/hooks/useConsoleMessages.ts +++ b/packages/cli/src/ui/hooks/useConsoleMessages.ts @@ -4,7 +4,13 @@ * SPDX-License-Identifier: Apache-2.0 */ -import { useCallback, useEffect, useRef, useState } from 'react'; +import { + useCallback, + useEffect, + useReducer, + useRef, + useTransition, +} from 'react'; import { ConsoleMessageItem } from '../types.js'; export interface UseConsoleMessagesReturn { @@ -13,75 +19,90 @@ export interface UseConsoleMessagesReturn { clearConsoleMessages: () => void; } -export function useConsoleMessages(): UseConsoleMessagesReturn { - const [consoleMessages, setConsoleMessages] = useState( - [], - ); - const messageQueueRef = useRef([]); - const messageQueueTimeoutRef = useRef(null); +type Action = + | { type: 'ADD_MESSAGES'; payload: ConsoleMessageItem[] } + | { type: 'CLEAR' }; - const processMessageQueue = useCallback(() => { - if (messageQueueRef.current.length === 0) { - return; - } - - const newMessagesToAdd = messageQueueRef.current; - messageQueueRef.current = []; - - setConsoleMessages((prevMessages) => { - const newMessages = [...prevMessages]; - newMessagesToAdd.forEach((queuedMessage) => { +function consoleMessagesReducer( + state: ConsoleMessageItem[], + action: Action, +): ConsoleMessageItem[] { + switch (action.type) { + case 'ADD_MESSAGES': { + const newMessages = [...state]; + for (const queuedMessage of action.payload) { + const lastMessage = newMessages[newMessages.length - 1]; if ( - newMessages.length > 0 && - newMessages[newMessages.length - 1].type === queuedMessage.type && - newMessages[newMessages.length - 1].content === queuedMessage.content + lastMessage && + lastMessage.type === queuedMessage.type && + lastMessage.content === queuedMessage.content ) { - newMessages[newMessages.length - 1].count = - (newMessages[newMessages.length - 1].count || 1) + 1; + // Create a new object for the last message to ensure React detects + // the change, preventing mutation of the existing state object. + newMessages[newMessages.length - 1] = { + ...lastMessage, + count: lastMessage.count + 1, + }; } else { newMessages.push({ ...queuedMessage, count: 1 }); } - }); + } return newMessages; - }); - - messageQueueTimeoutRef.current = null; // Allow next scheduling - }, []); - - const scheduleQueueProcessing = useCallback(() => { - if (messageQueueTimeoutRef.current === null) { - messageQueueTimeoutRef.current = setTimeout( - processMessageQueue, - 0, - ) as unknown as number; } - }, [processMessageQueue]); + case 'CLEAR': + return []; + default: + return state; + } +} + +export function useConsoleMessages(): UseConsoleMessagesReturn { + const [consoleMessages, dispatch] = useReducer(consoleMessagesReducer, []); + const messageQueueRef = useRef([]); + const timeoutRef = useRef(null); + const [, startTransition] = useTransition(); + + const processQueue = useCallback(() => { + if (messageQueueRef.current.length > 0) { + const messagesToProcess = messageQueueRef.current; + messageQueueRef.current = []; + startTransition(() => { + dispatch({ type: 'ADD_MESSAGES', payload: messagesToProcess }); + }); + } + timeoutRef.current = null; + }, []); const handleNewMessage = useCallback( (message: ConsoleMessageItem) => { messageQueueRef.current.push(message); - scheduleQueueProcessing(); + if (!timeoutRef.current) { + // Batch updates using a timeout. 16ms is a reasonable delay to batch + // rapid-fire messages without noticeable lag. + timeoutRef.current = setTimeout(processQueue, 16); + } }, - [scheduleQueueProcessing], + [processQueue], ); const clearConsoleMessages = useCallback(() => { - setConsoleMessages([]); - if (messageQueueTimeoutRef.current !== null) { - clearTimeout(messageQueueTimeoutRef.current); - messageQueueTimeoutRef.current = null; + if (timeoutRef.current) { + clearTimeout(timeoutRef.current); + timeoutRef.current = null; } messageQueueRef.current = []; + startTransition(() => { + dispatch({ type: 'CLEAR' }); + }); }, []); + // Cleanup on unmount useEffect( - () => - // Cleanup on unmount - () => { - if (messageQueueTimeoutRef.current !== null) { - clearTimeout(messageQueueTimeoutRef.current); - } - }, + () => () => { + if (timeoutRef.current) { + clearTimeout(timeoutRef.current); + } + }, [], ); diff --git a/packages/cli/src/utils/events.ts b/packages/cli/src/utils/events.ts new file mode 100644 index 00000000..39364387 --- /dev/null +++ b/packages/cli/src/utils/events.ts @@ -0,0 +1,14 @@ +/** + * @license + * Copyright 2025 Google LLC + * SPDX-License-Identifier: Apache-2.0 + */ + +import { EventEmitter } from 'events'; + +export enum AppEvent { + OpenDebugConsole = 'open-debug-console', + LogError = 'log-error', +} + +export const appEvents = new EventEmitter();