fix(logging): tolerate malformed subsystem labels (#70502) (#70535)

* fix(logging): tolerate malformed subsystem labels

Guard console subsystem filtering and probe suppression against malformed subsystem labels, and normalize bad subsystem names to a stable fallback during console emission.

Fixes #70502

* test(plugins): ignore extension test-support helpers in seam guardrail

Exclude extension files named *.test-support.ts from the plugin sdk seam guardrail so test-only helpers do not trip public seam enforcement on unrelated PRs.
This commit is contained in:
Deepak Jain
2026-04-23 11:51:54 -07:00
committed by GitHub
parent b201589ae1
commit a63939d295
4 changed files with 79 additions and 20 deletions

View File

@@ -130,12 +130,27 @@ export function setConsoleTimestampPrefix(enabled: boolean): void {
loggingState.consoleTimestampPrefix = enabled;
}
export function shouldLogSubsystemToConsole(subsystem: string): boolean {
function normalizeConsoleSubsystem(subsystem?: string | null): string | null {
if (typeof subsystem !== "string") {
return null;
}
const normalized = subsystem.trim();
return normalized.length > 0 ? normalized : null;
}
export function shouldLogSubsystemToConsole(subsystem?: string | null): boolean {
const filter = loggingState.consoleSubsystemFilter;
if (!filter || filter.length === 0) {
return true;
}
return filter.some((prefix) => subsystem === prefix || subsystem.startsWith(`${prefix}/`));
const normalizedSubsystem = normalizeConsoleSubsystem(subsystem);
if (!normalizedSubsystem) {
return false;
}
return filter.some(
(prefix) =>
normalizedSubsystem === prefix || normalizedSubsystem.startsWith(`${prefix}/`),
);
}
const SUPPRESSED_CONSOLE_PREFIXES = [

View File

@@ -1,5 +1,5 @@
import { afterEach, describe, expect, it, vi } from "vitest";
import { setConsoleSubsystemFilter } from "./console.js";
import { setConsoleSubsystemFilter, shouldLogSubsystemToConsole } from "./console.js";
import { resetLogger, setLoggerOverride } from "./logger.js";
import { loggingState } from "./state.js";
import { createSubsystemLogger } from "./subsystem.js";
@@ -87,6 +87,32 @@ describe("createSubsystemLogger().isEnabled", () => {
expect(log.isEnabled("info")).toBe(true);
});
it("treats missing subsystem labels as non-matches when filters are active", () => {
setConsoleSubsystemFilter(["gateway"]);
expect(() => shouldLogSubsystemToConsole(undefined as unknown as string)).not.toThrow();
expect(shouldLogSubsystemToConsole(undefined as unknown as string)).toBe(false);
});
it("does not throw when a malformed subsystem logger checks console enablement", () => {
setLoggerOverride({ level: "silent", consoleLevel: "info" });
setConsoleSubsystemFilter(["gateway"]);
const log = createSubsystemLogger(undefined as unknown as string);
expect(() => log.isEnabled("info", "console")).not.toThrow();
expect(log.isEnabled("info", "console")).toBe(false);
});
it("falls back to an unknown subsystem label when a malformed logger emits", () => {
setLoggerOverride({ level: "silent", consoleLevel: "warn" });
const warn = installConsoleMethodSpy("warn");
const log = createSubsystemLogger(undefined as unknown as string);
expect(() => log.warn("missing subsystem label")).not.toThrow();
expect(warn).toHaveBeenCalledTimes(1);
expect(String(warn.mock.calls[0]?.[0] ?? "")).toContain("[unknown]");
});
it("suppresses probe warnings for embedded subsystems based on structured run metadata", () => {
setLoggerOverride({ level: "silent", consoleLevel: "warn" });
const warn = installConsoleMethodSpy("warn");

View File

@@ -29,6 +29,14 @@ export type SubsystemLogger = {
child: (name: string) => SubsystemLogger;
};
function normalizeSubsystemLabel(subsystem?: string | null): string {
if (typeof subsystem !== "string") {
return "unknown";
}
const normalized = subsystem.trim();
return normalized.length > 0 ? normalized : "unknown";
}
function shouldLogToConsole(level: LogLevel, settings: { level: LogLevel }): boolean {
if (level === "silent") {
return false;
@@ -259,8 +267,8 @@ function writeConsoleLine(level: LogLevel, line: string) {
function shouldSuppressProbeConsoleLine(params: {
level: LogLevel;
subsystem: string;
message: string;
subsystem?: string | null;
message?: string | null;
meta?: Record<string, unknown>;
}): boolean {
if (isVerbose()) {
@@ -269,11 +277,13 @@ function shouldSuppressProbeConsoleLine(params: {
if (params.level === "error" || params.level === "fatal") {
return false;
}
const subsystem = normalizeSubsystemLabel(params.subsystem);
const message = typeof params.message === "string" ? params.message : "";
const isProbeSuppressedSubsystem =
params.subsystem === "agent/embedded" ||
params.subsystem.startsWith("agent/embedded/") ||
params.subsystem === "model-fallback" ||
params.subsystem.startsWith("model-fallback/");
subsystem === "agent/embedded" ||
subsystem.startsWith("agent/embedded/") ||
subsystem === "model-fallback" ||
subsystem.startsWith("model-fallback/");
if (!isProbeSuppressedSubsystem) {
return false;
}
@@ -286,7 +296,7 @@ function shouldSuppressProbeConsoleLine(params: {
if (runLikeId?.startsWith("probe-")) {
return true;
}
return /(sessionId|runId)=probe-/.test(params.message);
return /(sessionId|runId)=probe-/.test(message);
}
function logToFile(
@@ -313,13 +323,14 @@ function logToFile(
}
export function createSubsystemLogger(subsystem: string): SubsystemLogger {
const resolvedSubsystem = normalizeSubsystemLabel(subsystem);
let fileLogger: TsLogger<LogObj> | null = null;
const emitLog = (level: LogLevel, message: string, meta?: Record<string, unknown>) => {
const consoleSettings = getConsoleSettings();
const consoleEnabled =
shouldLogToConsole(level, { level: consoleSettings.level }) &&
shouldLogSubsystemToConsole(subsystem);
shouldLogSubsystemToConsole(resolvedSubsystem);
const fileEnabled = isFileLogLevelEnabled(level);
if (!consoleEnabled && !fileEnabled) {
return;
@@ -337,7 +348,7 @@ export function createSubsystemLogger(subsystem: string): SubsystemLogger {
}
if (fileEnabled) {
if (!fileLogger) {
fileLogger = getChildLogger({ subsystem });
fileLogger = getChildLogger({ subsystem: resolvedSubsystem });
}
logToFile(fileLogger, level, message, fileMeta);
}
@@ -348,7 +359,7 @@ export function createSubsystemLogger(subsystem: string): SubsystemLogger {
if (
shouldSuppressProbeConsoleLine({
level,
subsystem,
subsystem: resolvedSubsystem,
message: consoleMessage,
meta: fileMeta,
})
@@ -359,7 +370,7 @@ export function createSubsystemLogger(subsystem: string): SubsystemLogger {
level,
formatConsoleLine({
level,
subsystem,
subsystem: resolvedSubsystem,
message: consoleSettings.style === "json" ? message : consoleMessage,
style: consoleSettings.style,
meta: fileMeta,
@@ -368,11 +379,11 @@ export function createSubsystemLogger(subsystem: string): SubsystemLogger {
};
const logger: SubsystemLogger = {
subsystem,
subsystem: resolvedSubsystem,
isEnabled(level, target = "any") {
const isConsoleEnabled =
shouldLogToConsole(level, { level: getConsoleSettings().level }) &&
shouldLogSubsystemToConsole(subsystem);
shouldLogSubsystemToConsole(resolvedSubsystem);
const isFileEnabled = isFileLogLevelEnabled(level);
if (target === "console") {
return isConsoleEnabled;
@@ -403,22 +414,28 @@ export function createSubsystemLogger(subsystem: string): SubsystemLogger {
raw(message) {
if (isFileLogLevelEnabled("info")) {
if (!fileLogger) {
fileLogger = getChildLogger({ subsystem });
fileLogger = getChildLogger({ subsystem: resolvedSubsystem });
}
logToFile(fileLogger, "info", message, { raw: true });
}
if (
shouldLogToConsole("info", { level: getConsoleSettings().level }) &&
shouldLogSubsystemToConsole(subsystem)
shouldLogSubsystemToConsole(resolvedSubsystem)
) {
if (shouldSuppressProbeConsoleLine({ level: "info", subsystem, message })) {
if (
shouldSuppressProbeConsoleLine({
level: "info",
subsystem: resolvedSubsystem,
message,
})
) {
return;
}
writeConsoleLine("info", message);
}
},
child(name) {
return createSubsystemLogger(`${subsystem}/${name}`);
return createSubsystemLogger(`${resolvedSubsystem}/${name}`);
},
};
return logger;

View File

@@ -104,6 +104,7 @@ function collectExtensionCoreImportLeaks(): Array<{ file: string; specifier: str
if (
/(?:^|\/)(?:__tests__|tests|test-support)(?:\/|$)/.test(repoRelativePath) ||
/(?:^|\/)test-support\.[cm]?tsx?$/.test(repoRelativePath) ||
/\.test-support\.[cm]?tsx?$/.test(repoRelativePath) ||
/\.test\.[cm]?tsx?$/.test(repoRelativePath)
) {
continue;