feat(hooks): reduce log verbosity and improve error reporting in UI (#15297)

This commit is contained in:
Abhi
2025-12-18 19:30:45 -05:00
committed by GitHub
parent 70696e364b
commit 402148dbc4
7 changed files with 84 additions and 17 deletions

View File

@@ -53,7 +53,7 @@ export async function fireBeforeAgentHook(
? createHookOutput('BeforeAgent', response.output) ? createHookOutput('BeforeAgent', response.output)
: undefined; : undefined;
} catch (error) { } catch (error) {
debugLogger.warn(`BeforeAgent hook failed: ${error}`); debugLogger.debug(`BeforeAgent hook failed: ${error}`);
return undefined; return undefined;
} }
} }
@@ -99,7 +99,7 @@ export async function fireAfterAgentHook(
? createHookOutput('AfterAgent', response.output) ? createHookOutput('AfterAgent', response.output)
: undefined; : undefined;
} catch (error) { } catch (error) {
debugLogger.warn(`AfterAgent hook failed: ${error}`); debugLogger.debug(`AfterAgent hook failed: ${error}`);
return undefined; return undefined;
} }
} }

View File

@@ -145,7 +145,7 @@ export async function fireToolNotificationHook(
MessageBusType.HOOK_EXECUTION_RESPONSE, MessageBusType.HOOK_EXECUTION_RESPONSE,
); );
} catch (error) { } catch (error) {
debugLogger.warn( debugLogger.debug(
`Notification hook failed for ${confirmationDetails.title}:`, `Notification hook failed for ${confirmationDetails.title}:`,
error, error,
); );
@@ -185,7 +185,7 @@ export async function fireBeforeToolHook(
? createHookOutput('BeforeTool', response.output) ? createHookOutput('BeforeTool', response.output)
: undefined; : undefined;
} catch (error) { } catch (error) {
debugLogger.warn(`BeforeTool hook failed for ${toolName}:`, error); debugLogger.debug(`BeforeTool hook failed for ${toolName}:`, error);
return undefined; return undefined;
} }
} }
@@ -230,7 +230,7 @@ export async function fireAfterToolHook(
? createHookOutput('AfterTool', response.output) ? createHookOutput('AfterTool', response.output)
: undefined; : undefined;
} catch (error) { } catch (error) {
debugLogger.warn(`AfterTool hook failed for ${toolName}:`, error); debugLogger.debug(`AfterTool hook failed for ${toolName}:`, error);
return undefined; return undefined;
} }
} }

View File

@@ -124,7 +124,7 @@ export async function fireBeforeModelHook(
return { blocked: false }; return { blocked: false };
} catch (error) { } catch (error) {
debugLogger.warn(`BeforeModel hook failed:`, error); debugLogger.debug(`BeforeModel hook failed:`, error);
return { blocked: false }; return { blocked: false };
} }
} }
@@ -178,7 +178,7 @@ export async function fireBeforeToolSelectionHook(
return {}; return {};
} catch (error) { } catch (error) {
debugLogger.warn(`BeforeToolSelection hook failed:`, error); debugLogger.debug(`BeforeToolSelection hook failed:`, error);
return {}; return {};
} }
} }
@@ -228,7 +228,7 @@ export async function fireAfterModelHook(
return { response: chunk }; return { response: chunk };
} catch (error) { } catch (error) {
debugLogger.warn(`AfterModel hook failed:`, error); debugLogger.debug(`AfterModel hook failed:`, error);
// On error, return original chunk to avoid interrupting the stream. // On error, return original chunk to avoid interrupting the stream.
return { response: chunk }; return { response: chunk };
} }

View File

@@ -39,7 +39,7 @@ export async function fireSessionStartHook(
MessageBusType.HOOK_EXECUTION_RESPONSE, MessageBusType.HOOK_EXECUTION_RESPONSE,
); );
} catch (error) { } catch (error) {
debugLogger.warn(`SessionStart hook failed:`, error); debugLogger.debug(`SessionStart hook failed:`, error);
} }
} }
@@ -65,7 +65,7 @@ export async function fireSessionEndHook(
MessageBusType.HOOK_EXECUTION_RESPONSE, MessageBusType.HOOK_EXECUTION_RESPONSE,
); );
} catch (error) { } catch (error) {
debugLogger.warn(`SessionEnd hook failed:`, error); debugLogger.debug(`SessionEnd hook failed:`, error);
} }
} }
@@ -91,6 +91,6 @@ export async function firePreCompressHook(
MessageBusType.HOOK_EXECUTION_RESPONSE, MessageBusType.HOOK_EXECUTION_RESPONSE,
); );
} catch (error) { } catch (error) {
debugLogger.warn(`PreCompress hook failed:`, error); debugLogger.debug(`PreCompress hook failed:`, error);
} }
} }

View File

@@ -27,10 +27,19 @@ const mockDebugLogger = vi.hoisted(() => ({
debug: vi.fn(), debug: vi.fn(),
})); }));
// Mock coreEvents
const mockCoreEvents = vi.hoisted(() => ({
emitFeedback: vi.fn(),
}));
vi.mock('../utils/debugLogger.js', () => ({ vi.mock('../utils/debugLogger.js', () => ({
debugLogger: mockDebugLogger, debugLogger: mockDebugLogger,
})); }));
vi.mock('../utils/events.js', () => ({
coreEvents: mockCoreEvents,
}));
describe('HookEventHandler', () => { describe('HookEventHandler', () => {
let hookEventHandler: HookEventHandler; let hookEventHandler: HookEventHandler;
let mockConfig: Config; let mockConfig: Config;
@@ -167,6 +176,53 @@ describe('HookEventHandler', () => {
expect(result.errors[0].message).toBe('Planning failed'); expect(result.errors[0].message).toBe('Planning failed');
expect(mockDebugLogger.error).toHaveBeenCalled(); expect(mockDebugLogger.error).toHaveBeenCalled();
}); });
it('should emit feedback when some hooks fail', async () => {
const mockPlan = [
{
type: HookType.Command,
command: './fail.sh',
} as HookConfig,
];
const mockResults: HookExecutionResult[] = [
{
success: false,
duration: 50,
hookConfig: mockPlan[0],
eventName: HookEventName.BeforeTool,
error: new Error('Failed to execute'),
},
];
const mockAggregated = {
success: false,
allOutputs: [],
errors: [new Error('Failed to execute')],
totalDuration: 50,
};
vi.mocked(mockHookPlanner.createExecutionPlan).mockReturnValue({
eventName: HookEventName.BeforeTool,
hookConfigs: mockPlan,
sequential: false,
});
vi.mocked(mockHookRunner.executeHooksParallel).mockResolvedValue(
mockResults,
);
vi.mocked(mockHookAggregator.aggregateResults).mockReturnValue(
mockAggregated,
);
await hookEventHandler.fireBeforeToolEvent('EditTool', {});
expect(mockCoreEvents.emitFeedback).toHaveBeenCalledWith(
'warning',
expect.stringContaining('./fail.sh'),
);
expect(mockCoreEvents.emitFeedback).toHaveBeenCalledWith(
'warning',
expect.stringContaining('F12'),
);
});
}); });
describe('fireAfterToolEvent', () => { describe('fireAfterToolEvent', () => {

View File

@@ -42,6 +42,7 @@ import {
type HookExecutionRequest, type HookExecutionRequest,
} from '../confirmation-bus/types.js'; } from '../confirmation-bus/types.js';
import { debugLogger } from '../utils/debugLogger.js'; import { debugLogger } from '../utils/debugLogger.js';
import { coreEvents } from '../utils/events.js';
/** /**
* Validates that a value is a non-null object * Validates that a value is a non-null object
@@ -573,14 +574,24 @@ export class HookEventHandler {
results: HookExecutionResult[], results: HookExecutionResult[],
aggregated: AggregatedHookResult, aggregated: AggregatedHookResult,
): void { ): void {
const successCount = results.filter((r) => r.success).length; const failedHooks = results.filter((r) => !r.success);
const errorCount = results.length - successCount; const successCount = results.length - failedHooks.length;
const errorCount = failedHooks.length;
if (errorCount > 0) { if (errorCount > 0) {
const failedNames = failedHooks
.map((r) => this.getHookNameFromResult(r))
.join(', ');
debugLogger.warn( debugLogger.warn(
`Hook execution for ${eventName}: ${successCount} succeeded, ${errorCount} failed, ` + `Hook execution for ${eventName}: ${successCount} succeeded, ${errorCount} failed (${failedNames}), ` +
`total duration: ${aggregated.totalDuration}ms`, `total duration: ${aggregated.totalDuration}ms`,
); );
coreEvents.emitFeedback(
'warning',
`Hook(s) [${failedNames}] failed for event ${eventName}. Press F12 to see the debug drawer for more details.\n`,
);
} else { } else {
debugLogger.debug( debugLogger.debug(
`Hook execution for ${eventName}: ${successCount} hooks executed successfully, ` + `Hook execution for ${eventName}: ${successCount} hooks executed successfully, ` +
@@ -613,7 +624,7 @@ export class HookEventHandler {
// Log individual errors // Log individual errors
for (const error of aggregated.errors) { for (const error of aggregated.errors) {
debugLogger.error(`Hook execution error: ${error.message}`); debugLogger.warn(`Hook execution error: ${error.message}`);
} }
} }

View File

@@ -235,7 +235,7 @@ export class HookRunner {
child.stdin.on('error', (err: NodeJS.ErrnoException) => { child.stdin.on('error', (err: NodeJS.ErrnoException) => {
// Ignore EPIPE errors which happen when the child process closes stdin early // Ignore EPIPE errors which happen when the child process closes stdin early
if (err.code !== 'EPIPE') { if (err.code !== 'EPIPE') {
debugLogger.warn(`Hook stdin error: ${err}`); debugLogger.debug(`Hook stdin error: ${err}`);
} }
}); });
@@ -247,7 +247,7 @@ export class HookRunner {
} catch (err) { } catch (err) {
// Ignore EPIPE errors which happen when the child process closes stdin early // Ignore EPIPE errors which happen when the child process closes stdin early
if (err instanceof Error && 'code' in err && err.code !== 'EPIPE') { if (err instanceof Error && 'code' in err && err.code !== 'EPIPE') {
debugLogger.warn(`Hook stdin write error: ${err}`); debugLogger.debug(`Hook stdin write error: ${err}`);
} }
} }
} }