fix(cli): prevent informational logs from polluting json output (#26264)

This commit is contained in:
Coco Sheng
2026-04-30 14:34:25 -04:00
committed by GitHub
parent 0af13141b2
commit 8c1e255ac0
4 changed files with 219 additions and 24 deletions
+42 -21
View File
@@ -13,6 +13,7 @@ import {
type OutputPayload,
type ConsoleLogPayload,
type UserFeedbackPayload,
type CoreEvents,
createSessionId,
logUserPrompt,
AuthType,
@@ -265,6 +266,7 @@ export async function startInteractiveUI(
}
export async function main() {
let config: Config | undefined;
const cliStartupHandle = startupProfiler.start('cli_startup');
// Listen for admin controls from parent process (IPC) in non-sandbox mode. In
@@ -277,7 +279,7 @@ export async function main() {
const cleanupStdio = patchStdio();
registerSyncCleanup(() => {
// This is needed to ensure we don't lose any buffered output.
initializeOutputListenersAndFlush();
initializeOutputListenersAndFlush(config);
cleanupStdio();
});
@@ -539,7 +541,7 @@ export async function main() {
// may have side effects.
{
const loadConfigHandle = startupProfiler.start('load_cli_config');
const config = await loadCliConfig(settings.merged, sessionId, argv, {
config = await loadCliConfig(settings.merged, sessionId, argv, {
projectHooks: settings.workspace.settings.hooks,
worktreeSettings: worktreeInfo,
});
@@ -785,7 +787,7 @@ export async function main() {
debugLogger.log('Session ID: %s', sessionId);
}
initializeOutputListenersAndFlush();
initializeOutputListenersAndFlush(config);
await runNonInteractive({
config,
@@ -800,7 +802,7 @@ export async function main() {
}
}
export function initializeOutputListenersAndFlush() {
export function initializeOutputListenersAndFlush(config?: Config) {
// If there are no listeners for output, make sure we flush so output is not
// lost.
if (coreEvents.listenerCount(CoreEvent.Output) === 0) {
@@ -812,24 +814,43 @@ export function initializeOutputListenersAndFlush() {
writeToStdout(payload.chunk, payload.encoding);
}
});
if (coreEvents.listenerCount(CoreEvent.ConsoleLog) === 0) {
coreEvents.on(CoreEvent.ConsoleLog, (payload: ConsoleLogPayload) => {
if (payload.type === 'error' || payload.type === 'warn') {
writeToStderr(payload.content + '\n');
} else {
writeToStderr(payload.content + '\n');
}
});
}
if (coreEvents.listenerCount(CoreEvent.UserFeedback) === 0) {
coreEvents.on(CoreEvent.UserFeedback, (payload: UserFeedbackPayload) => {
writeToStderr(payload.message + '\n');
});
}
}
coreEvents.drainBacklogs();
if (coreEvents.listenerCount(CoreEvent.ConsoleLog) === 0) {
coreEvents.on(CoreEvent.ConsoleLog, (payload: ConsoleLogPayload) => {
if (payload.type === 'error' || payload.type === 'warn') {
writeToStderr(payload.content + '\n');
} else {
writeToStderr(payload.content + '\n');
}
});
}
if (coreEvents.listenerCount(CoreEvent.UserFeedback) === 0) {
coreEvents.on(CoreEvent.UserFeedback, (payload: UserFeedbackPayload) => {
writeToStderr(payload.message + '\n');
});
}
const outputFormat = config?.getOutputFormat();
const forceToStderr = outputFormat === 'json' || config === undefined;
coreEvents.drainBacklogs(
<K extends keyof CoreEvents>(event: K, args: CoreEvents[K]) => {
if (forceToStderr && event === (CoreEvent.Output as string)) {
// eslint-disable-next-line @typescript-eslint/no-unsafe-type-assertion
const payload = args[0] as OutputPayload;
if (!payload.isStderr) {
return {
event,
// eslint-disable-next-line @typescript-eslint/no-unsafe-type-assertion
args: [{ ...payload, isStderr: true }] as unknown as CoreEvents[K],
};
}
}
return { event, args };
},
);
}
function setupAdminControlsListener() {
+100
View File
@@ -0,0 +1,100 @@
/**
* @license
* Copyright 2026 Google LLC
* SPDX-License-Identifier: Apache-2.0
*/
import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest';
import { initializeOutputListenersAndFlush } from './gemini.js';
import { coreEvents, CoreEvent, type Config } from '@google/gemini-cli-core';
// Mock core dependencies
vi.mock('@google/gemini-cli-core', async (importOriginal) => {
const actual =
await importOriginal<typeof import('@google/gemini-cli-core')>();
return {
...actual,
writeToStdout: vi.fn(),
writeToStderr: vi.fn(),
};
});
import { writeToStdout, writeToStderr } from '@google/gemini-cli-core';
describe('Output Redirection', () => {
beforeEach(() => {
vi.clearAllMocks();
// Clear listeners to simulate a clean state for each test
coreEvents.removeAllListeners();
});
afterEach(() => {
coreEvents.removeAllListeners();
});
it('should redirect buffered stdout to stderr when output format is json', () => {
const mockConfig = {
getOutputFormat: () => 'json',
} as unknown as Config;
// Simulate buffered output
coreEvents.emitOutput(false, 'informational message');
coreEvents.emitOutput(true, 'error message');
// Initialize listeners and flush
initializeOutputListenersAndFlush(mockConfig);
// Verify informational message was forced to stderr
expect(writeToStderr).toHaveBeenCalledWith(
'informational message',
undefined,
);
expect(writeToStderr).toHaveBeenCalledWith('error message', undefined);
expect(writeToStdout).not.toHaveBeenCalled();
});
it('should NOT redirect buffered stdout to stderr when output format is NOT json', () => {
const mockConfig = {
getOutputFormat: () => 'text',
} as unknown as Config;
// Simulate buffered output
coreEvents.emitOutput(false, 'regular message');
// Initialize listeners and flush
initializeOutputListenersAndFlush(mockConfig);
// Verify regular message went to stdout
expect(writeToStdout).toHaveBeenCalledWith('regular message', undefined);
expect(writeToStderr).not.toHaveBeenCalled();
});
it('should force stdout to stderr when config is undefined (early failure)', () => {
// Simulate buffered output during early init
coreEvents.emitOutput(false, 'early init message');
// Initialize with undefined config
initializeOutputListenersAndFlush(undefined);
// Verify it was forced to stderr
expect(writeToStderr).toHaveBeenCalledWith('early init message', undefined);
expect(writeToStdout).not.toHaveBeenCalled();
});
it('should attach ConsoleLog and UserFeedback listeners even if Output already has one', () => {
// Manually attach an Output listener
coreEvents.on(CoreEvent.Output, vi.fn());
// Initialize - should still attach ConsoleLog and UserFeedback defaults
initializeOutputListenersAndFlush(undefined);
// Simulate events
coreEvents.emitConsoleLog('info', 'stray log');
coreEvents.emitFeedback('info', 'stray feedback');
// Draining happens inside initializeOutputListenersAndFlush for existing backlog,
// but here we check the newly attached listeners for immediate emission.
expect(writeToStderr).toHaveBeenCalledWith('stray log\n');
expect(writeToStderr).toHaveBeenCalledWith('stray feedback\n');
});
});
+56
View File
@@ -9,6 +9,7 @@ import {
CoreEventEmitter,
CoreEvent,
coreEvents,
type CoreEvents,
type UserFeedbackPayload,
type McpProgressPayload,
} from './events.js';
@@ -268,6 +269,61 @@ describe('CoreEventEmitter', () => {
});
});
describe('drainBacklogs Transformation', () => {
it('should transform events during drain', () => {
const listener = vi.fn();
events.emitOutput(false, 'stdout chunk');
events.emitFeedback('info', 'info message');
events.on(CoreEvent.Output, listener);
events.on(CoreEvent.UserFeedback, listener);
events.drainBacklogs(
<K extends keyof CoreEvents>(event: K, args: CoreEvents[K]) => {
if (event === (CoreEvent.Output as string)) {
const payload = args[0] as { isStderr: boolean; chunk: string };
return {
event,
args: [
{ ...payload, isStderr: true },
] as unknown as CoreEvents[K],
};
}
return { event, args };
},
);
expect(listener).toHaveBeenCalledTimes(2);
expect(listener).toHaveBeenCalledWith(
expect.objectContaining({ isStderr: true, chunk: 'stdout chunk' }),
);
expect(listener).toHaveBeenCalledWith(
expect.objectContaining({ message: 'info message' }),
);
});
it('should drop events when transform returns undefined', () => {
const listener = vi.fn();
events.emitOutput(false, 'drop me');
events.emitFeedback('info', 'keep me');
events.on(CoreEvent.Output, listener);
events.on(CoreEvent.UserFeedback, listener);
events.drainBacklogs((event, args) => {
if (event === CoreEvent.Output) {
return undefined;
}
return { event, args };
});
expect(listener).toHaveBeenCalledTimes(1);
expect(listener).toHaveBeenCalledWith(
expect.objectContaining({ message: 'keep me' }),
);
});
});
describe('ModelChanged Event', () => {
it('should emit ModelChanged event with correct payload', () => {
const listener = vi.fn();
+21 -3
View File
@@ -422,8 +422,15 @@ export class CoreEventEmitter extends EventEmitter<CoreEvents> {
/**
* Flushes buffered messages. Call this immediately after primary UI listener
* subscribes.
*
* @param transform - Optional function to transform events before they are emitted.
*/
drainBacklogs(): void {
drainBacklogs(
transform?: <K extends keyof CoreEvents>(
event: K,
args: CoreEvents[K],
) => { event: K; args: CoreEvents[K] } | undefined,
): void {
const backlog = this._eventBacklog;
const head = this._backlogHead;
this._eventBacklog = [];
@@ -431,10 +438,21 @@ export class CoreEventEmitter extends EventEmitter<CoreEvents> {
for (let i = head; i < backlog.length; i++) {
const item = backlog[i];
if (item === undefined) continue;
let eventToEmit = item.event;
let argsToEmit = item.args;
if (transform) {
const transformed = transform(item.event, item.args);
if (!transformed) continue;
eventToEmit = transformed.event;
argsToEmit = transformed.args;
}
// eslint-disable-next-line @typescript-eslint/no-unsafe-type-assertion
(this.emit as (event: keyof CoreEvents, ...args: unknown[]) => boolean)(
item.event,
...item.args,
eventToEmit,
...argsToEmit,
);
}
}