From cbba40eb665f737a239138958129e1297cb9ed6c Mon Sep 17 00:00:00 2001 From: Taylor Mullen Date: Tue, 10 Feb 2026 15:00:23 -0800 Subject: [PATCH] repro: re-enable diagnostic logging and focus failing hook tests --- integration-tests/hooks-agent-flow.test.ts | 9 +++++---- integration-tests/hooks-system.test.ts | 2 +- packages/core/src/core/coreToolScheduler.ts | 1 + packages/core/src/hooks/hookRegistry.ts | 3 +++ packages/core/src/hooks/hookRunner.ts | 8 ++++++++ packages/test-utils/src/test-rig.ts | 13 +++++++++++++ 6 files changed, 31 insertions(+), 5 deletions(-) diff --git a/integration-tests/hooks-agent-flow.test.ts b/integration-tests/hooks-agent-flow.test.ts index efe886b1a8..5d46a635a0 100644 --- a/integration-tests/hooks-agent-flow.test.ts +++ b/integration-tests/hooks-agent-flow.test.ts @@ -5,9 +5,8 @@ */ import { describe, it, expect, beforeEach, afterEach } from 'vitest'; -import { TestRig } from './test-helper.js'; +import { TestRig, normalizePath } from './test-helper.js'; import { join } from 'node:path'; -import { writeFileSync } from 'node:fs'; describe('Hooks Agent Flow', () => { let rig: TestRig; @@ -283,7 +282,7 @@ describe('Hooks Agent Flow', () => { hooks: [ { type: 'command', - command: `node "${baPath}"`, + command: normalizePath(`node "${baPath}"`)!, timeout: 5000, }, ], @@ -294,13 +293,15 @@ describe('Hooks Agent Flow', () => { hooks: [ { type: 'command', - command: `node "${aaPath}"`, + command: normalizePath(`node "${aaPath}"`)!, timeout: 5000, }, ], }, ], }, + ], + }, }, }, ); diff --git a/integration-tests/hooks-system.test.ts b/integration-tests/hooks-system.test.ts index f91aba5dfe..3911840d09 100644 --- a/integration-tests/hooks-system.test.ts +++ b/integration-tests/hooks-system.test.ts @@ -87,7 +87,7 @@ describe('Hooks System Integration', () => { expect(hookTelemetryFound).toBeTruthy(); }); - it('should block tool execution and use stderr as reason when hook exits with code 2', async () => { + it.only('should block tool execution and use stderr as reason when hook exits with code 2', async () => { rig.setup( 'should block tool execution and use stderr as reason when hook exits with code 2', { diff --git a/packages/core/src/core/coreToolScheduler.ts b/packages/core/src/core/coreToolScheduler.ts index 0bcaa5c3ed..3ea97c8adf 100644 --- a/packages/core/src/core/coreToolScheduler.ts +++ b/packages/core/src/core/coreToolScheduler.ts @@ -967,6 +967,7 @@ export class CoreToolScheduler { const completedCall = activeCall as CompletedToolCall; if (process.env['CI'] === 'true' || process.env['VERBOSE'] === 'true') { + console.log(`[CoreToolScheduler] Completed tool call: ${completedCall.request.name}, status: ${completedCall.status}`); } this.completedToolCallsForBatch.push(completedCall); diff --git a/packages/core/src/hooks/hookRegistry.ts b/packages/core/src/hooks/hookRegistry.ts index 7d3402d434..e90c60f4b5 100644 --- a/packages/core/src/hooks/hookRegistry.ts +++ b/packages/core/src/hooks/hookRegistry.ts @@ -234,9 +234,12 @@ please review the project settings (.gemini/settings.json) and remove them.`; const isDisabled = disabledHooks.includes(hookName); if (process.env['CI'] === 'true' || process.env['VERBOSE'] === 'true') { + console.log(`[HookRegistry] Processing hook: "${hookName}"`); if (isDisabled) { + console.log(`[HookRegistry] Hook is DISABLED (found in disabledHooks list)`); } if (disabledHooks.length > 0) { + console.log(`[HookRegistry] Current disabledHooks: ${JSON.stringify(disabledHooks)}`); } } diff --git a/packages/core/src/hooks/hookRunner.ts b/packages/core/src/hooks/hookRunner.ts index 7f6ef5f339..d7238d98be 100644 --- a/packages/core/src/hooks/hookRunner.ts +++ b/packages/core/src/hooks/hookRunner.ts @@ -269,6 +269,9 @@ export class HookRunner { ); if (process.env['CI'] === 'true' || process.env['VERBOSE'] === 'true') { + console.log(`[HookRunner] shellConfig: ${JSON.stringify(shellConfig)}`); + console.log(`[HookRunner] command: ${command}`); + console.log(`[HookRunner] cwd: ${input.cwd}`); } // Set up environment variables @@ -337,6 +340,7 @@ export class HookRunner { child.on('exit', (code, signal) => { if (process.env['CI'] === 'true' || process.env['VERBOSE'] === 'true') { + console.log(`[HookRunner] Hook exit. code: ${code}, signal: ${signal}`); } }); @@ -346,6 +350,9 @@ export class HookRunner { const duration = Date.now() - startTime; if (process.env['CI'] === 'true' || process.env['VERBOSE'] === 'true') { + console.log(`[HookRunner] Hook closed. exitCode: ${exitCode}, duration: ${duration}ms`); + console.log(`[HookRunner] stdout: ${stdout}`); + console.log(`[HookRunner] stderr: ${stderr}`); } if (timedOut) { @@ -440,6 +447,7 @@ export class HookRunner { exitCode: number, ): HookOutput { if (process.env['CI'] === 'true' || process.env['VERBOSE'] === 'true') { + console.log(`[HookRunner] convertPlainTextToHookOutput: exitCode=${exitCode}, text="${text}"`); } if (exitCode === EXIT_CODE_SUCCESS) { // Success - treat as system message or additional context diff --git a/packages/test-utils/src/test-rig.ts b/packages/test-utils/src/test-rig.ts index 5d041076b7..5caeccdcda 100644 --- a/packages/test-utils/src/test-rig.ts +++ b/packages/test-utils/src/test-rig.ts @@ -362,12 +362,18 @@ export class TestRig { this.homeDir = join(testFileDir, sanitizedName + '-home'); if (env['VERBOSE'] === 'true' || env['CI'] === 'true') { + console.log(`[TestRig] Setting up test: ${this.testName}`); + console.log(`[TestRig] testDir: ${this.testDir}`); + console.log(`[TestRig] homeDir: ${this.homeDir}`); } if (!this._initialized) { // Clean up existing directories from previous runs (e.g. retries) const cleanDir = (dir: string) => { if (fs.existsSync(dir)) { + if (env['VERBOSE'] === 'true' || env['CI'] === 'true') { + console.log(`[TestRig] Cleaning up existing directory: ${dir}`); + } for (let i = 0; i < 5; i++) { try { fs.rmSync(dir, { recursive: true, force: true }); @@ -765,6 +771,11 @@ export class TestRig { }); this._spawnedProcesses.push(child); + if (env['VERBOSE'] === 'true' || env['CI'] === 'true') { + console.log(`[TestRig] Running: ${command} ${commandArgs.join(' ')}`); + console.log(`[TestRig] CWD: ${this.testDir}`); + } + let stdout = ''; let stderr = ''; @@ -1250,6 +1261,7 @@ export class TestRig { for (const logData of parsedLogs) { if (env['VERBOSE'] === 'true' || env['CI'] === 'true') { if (logData.attributes?.['event.name']?.includes('tool')) { + console.log(`[TestRig] Found tool-related log: ${JSON.stringify(logData.attributes)}`); } } // Look for tool call logs @@ -1406,6 +1418,7 @@ export class TestRig { for (const logData of parsedLogs) { if (env['VERBOSE'] === 'true' || env['CI'] === 'true') { if (logData.attributes?.['event.name']?.includes('hook')) { + console.log(`[TestRig] Found hook-related log: ${JSON.stringify(logData.attributes)}`); } } // Look for tool call logs