refactor(logging): migrate non-agent internal console calls to subsystem logger (#22964)

Merged via /review-pr -> /prepare-pr -> /merge-pr.

Prepared head SHA: b4a5b12422
Co-authored-by: gumadeiras <5599352+gumadeiras@users.noreply.github.com>
Co-authored-by: gumadeiras <5599352+gumadeiras@users.noreply.github.com>
Reviewed-by: @gumadeiras
This commit is contained in:
Gustavo Madeira Santana
2026-02-21 17:44:00 -05:00
committed by GitHub
parent 4ef4aa3c10
commit 2f46308d5a
14 changed files with 102 additions and 29 deletions

View File

@@ -28,6 +28,7 @@ import {
import type { TtsAutoMode } from "../../config/types.tts.js";
import { archiveSessionTranscripts } from "../../gateway/session-utils.fs.js";
import { deliverSessionMaintenanceWarning } from "../../infra/session-maintenance-warning.js";
import { createSubsystemLogger } from "../../logging/subsystem.js";
import { getGlobalHookRunner } from "../../plugins/hook-runner-global.js";
import { normalizeMainKey } from "../../routing/session-key.js";
import { normalizeSessionDeliveryFields } from "../../utils/delivery-context.js";
@@ -36,6 +37,8 @@ import type { MsgContext, TemplateContext } from "../templating.js";
import { normalizeInboundTextNewlines } from "./inbound-text.js";
import { stripMentions, stripStructuralPrefixes } from "./mentions.js";
const log = createSubsystemLogger("session-init");
export type SessionInitResult = {
sessionCtx: TemplateContext;
sessionEntry: SessionEntry;
@@ -339,8 +342,8 @@ export async function initSessionState(params: {
parentSessionKey !== sessionKey &&
sessionStore[parentSessionKey]
) {
console.warn(
`[session-init] forking from parent session: parentKey=${parentSessionKey} → sessionKey=${sessionKey} ` +
log.warn(
`forking from parent session: parentKey=${parentSessionKey} → sessionKey=${sessionKey} ` +
`parentTokens=${sessionStore[parentSessionKey].totalTokens ?? "?"}`,
);
const forked = forkSessionFromParent({
@@ -352,7 +355,7 @@ export async function initSessionState(params: {
sessionId = forked.sessionId;
sessionEntry.sessionId = forked.sessionId;
sessionEntry.sessionFile = forked.sessionFile;
console.warn(`[session-init] forked session created: file=${forked.sessionFile}`);
log.warn(`forked session created: file=${forked.sessionFile}`);
}
}
const fallbackSessionFile = !sessionEntry.sessionFile

View File

@@ -595,7 +595,7 @@ async function saveSessionStoreUnlocked(
// Final attempt failed — skip this save. The write lock ensures
// the next save will retry with fresh data. Log for diagnostics.
if (i === 4) {
console.warn(`[session-store] rename failed after 5 attempts: ${storePath}`);
log.warn(`rename failed after 5 attempts: ${storePath}`);
}
}
}

View File

@@ -41,6 +41,7 @@ import { createReplyPrefixOptions } from "../../channels/reply-prefix.js";
import type { OpenClawConfig, loadConfig } from "../../config/config.js";
import { loadSessionStore, resolveStorePath } from "../../config/sessions.js";
import { logVerbose } from "../../globals.js";
import { createSubsystemLogger } from "../../logging/subsystem.js";
import { getAgentScopedMediaLocalRoots } from "../../media/local-roots.js";
import { buildPairingReply } from "../../pairing/pairing-messages.js";
import {
@@ -85,6 +86,7 @@ import type { ThreadBindingManager } from "./thread-bindings.js";
import { resolveDiscordThreadParentInfo } from "./threading.js";
type DiscordConfig = NonNullable<OpenClawConfig["channels"]>["discord"];
const log = createSubsystemLogger("discord/native-command");
function buildDiscordCommandOptions(params: {
command: ChatCommandDefinition;
@@ -1600,7 +1602,8 @@ async function dispatchDiscordCommandInteraction(params: {
didReply = true;
},
onError: (err, info) => {
console.error(`discord slash ${info.kind} reply failed`, err);
const message = err instanceof Error ? (err.stack ?? err.message) : String(err);
log.error(`discord slash ${info.kind} reply failed: ${message}`);
},
},
replyOptions: {

View File

@@ -2,10 +2,12 @@ import {
filterBootstrapFilesForSession,
loadExtraBootstrapFiles,
} from "../../../agents/workspace.js";
import { createSubsystemLogger } from "../../../logging/subsystem.js";
import { resolveHookConfig } from "../../config.js";
import { isAgentBootstrapEvent, type HookHandler } from "../../hooks.js";
const HOOK_KEY = "bootstrap-extra-files";
const log = createSubsystemLogger("bootstrap-extra-files");
function normalizeStringArray(value: unknown): string[] {
if (!Array.isArray(value)) {
@@ -52,7 +54,7 @@ const bootstrapExtraFilesHook: HookHandler = async (event) => {
context.sessionKey,
);
} catch (err) {
console.warn(`[bootstrap-extra-files] failed: ${String(err)}`);
log.warn(`failed: ${String(err)}`);
}
};

View File

@@ -27,8 +27,11 @@ import fs from "node:fs/promises";
import os from "node:os";
import path from "node:path";
import { resolveStateDir } from "../../../config/paths.js";
import { createSubsystemLogger } from "../../../logging/subsystem.js";
import type { HookHandler } from "../../hooks.js";
const log = createSubsystemLogger("command-logger");
/**
* Log all command events to a file
*/
@@ -57,10 +60,8 @@ const logCommand: HookHandler = async (event) => {
await fs.appendFile(logFile, logLine, "utf-8");
} catch (err) {
console.error(
"[command-logger] Failed to log command:",
err instanceof Error ? err.message : String(err),
);
const message = err instanceof Error ? err.message : String(err);
log.error(`Failed to log command: ${message}`);
}
};

View File

@@ -8,6 +8,7 @@
import type { WorkspaceBootstrapFile } from "../agents/workspace.js";
import type { CliDeps } from "../cli/deps.js";
import type { OpenClawConfig } from "../config/config.js";
import { createSubsystemLogger } from "../logging/subsystem.js";
export type InternalHookEventType = "command" | "session" | "agent" | "gateway" | "message";
@@ -111,6 +112,7 @@ export type InternalHookHandler = (event: InternalHookEvent) => Promise<void> |
/** Registry of hook handlers by event key */
const handlers = new Map<string, InternalHookHandler[]>();
const log = createSubsystemLogger("internal-hooks");
/**
* Register a hook handler for a specific event type or event:action combination
@@ -201,10 +203,8 @@ export async function triggerInternalHook(event: InternalHookEvent): Promise<voi
try {
await handler(event);
} catch (err) {
console.error(
`Hook error [${event.type}:${event.action}]:`,
err instanceof Error ? err.message : String(err),
);
const message = err instanceof Error ? err.message : String(err);
log.error(`Hook error [${event.type}:${event.action}]: ${message}`);
}
}
}

View File

@@ -12,6 +12,9 @@ import {
} from "../agents/agent-scope.js";
import { runEmbeddedPiAgent } from "../agents/pi-embedded.js";
import type { OpenClawConfig } from "../config/config.js";
import { createSubsystemLogger } from "../logging/subsystem.js";
const log = createSubsystemLogger("llm-slug-generator");
/**
* Generate a short 1-2 word filename slug from session content using LLM
@@ -70,7 +73,8 @@ Reply with ONLY the slug, nothing else. Examples: "vendor-pitch", "api-design",
return null;
} catch (err) {
console.error("[llm-slug-generator] Failed to generate slug:", err);
const message = err instanceof Error ? (err.stack ?? err.message) : String(err);
log.error(`Failed to generate slug: ${message}`);
return null;
} finally {
// Clean up temporary session file

View File

@@ -2,6 +2,7 @@ import fs from "node:fs";
import path from "node:path";
import { MANIFEST_KEY } from "../compat/legacy-names.js";
import type { OpenClawConfig } from "../config/config.js";
import { createSubsystemLogger } from "../logging/subsystem.js";
import { isPathInsideWithRealpath } from "../security/scan-paths.js";
import { CONFIG_DIR, resolveUserPath } from "../utils.js";
import { resolveBundledHooksDir } from "./bundled-dir.js";
@@ -23,6 +24,7 @@ import type {
type HookPackageManifest = {
name?: string;
} & Partial<Record<typeof MANIFEST_KEY, { hooks?: string[] }>>;
const log = createSubsystemLogger("hooks/workspace");
function filterHookEntries(
entries: HookEntry[],
@@ -95,7 +97,7 @@ function loadHookFromDir(params: {
}
if (!handlerPath) {
console.warn(`[hooks] Hook "${name}" has HOOK.md but no handler file in ${params.hookDir}`);
log.warn(`Hook "${name}" has HOOK.md but no handler file in ${params.hookDir}`);
return null;
}
@@ -109,7 +111,8 @@ function loadHookFromDir(params: {
handlerPath,
};
} catch (err) {
console.warn(`[hooks] Failed to load hook from ${params.hookDir}:`, err);
const message = err instanceof Error ? (err.stack ?? err.message) : String(err);
log.warn(`Failed to load hook from ${params.hookDir}: ${message}`);
return null;
}
}
@@ -145,8 +148,8 @@ function loadHooksFromDir(params: { dir: string; source: HookSource; pluginId?:
for (const hookPath of packageHooks) {
const resolvedHookDir = resolveContainedDir(hookDir, hookPath);
if (!resolvedHookDir) {
console.warn(
`[hooks] Ignoring out-of-package hook path "${hookPath}" in ${hookDir} (must be within package directory)`,
log.warn(
`Ignoring out-of-package hook path "${hookPath}" in ${hookDir} (must be within package directory)`,
);
continue;
}

View File

@@ -1,4 +1,5 @@
import { RateLimitError } from "@buape/carbon";
import { createSubsystemLogger } from "../logging/subsystem.js";
import { formatErrorMessage } from "./errors.js";
import { type RetryConfig, resolveRetryConfig, retryAsync } from "./retry.js";
@@ -19,6 +20,7 @@ export const TELEGRAM_RETRY_DEFAULTS = {
};
const TELEGRAM_RETRY_RE = /429|timeout|connect|reset|closed|unavailable|temporarily/i;
const log = createSubsystemLogger("retry-policy");
function getTelegramRetryAfterMs(err: unknown): number | undefined {
if (!err || typeof err !== "object") {
@@ -61,7 +63,7 @@ export function createDiscordRetryRunner(params: {
? (info) => {
const labelText = info.label ?? "request";
const maxRetries = Math.max(1, info.maxAttempts - 1);
console.warn(
log.warn(
`discord ${labelText} rate limited, retry ${info.attempt}/${maxRetries} in ${info.delayMs}ms`,
);
}
@@ -92,7 +94,7 @@ export function createTelegramRetryRunner(params: {
onRetry: params.verbose
? (info) => {
const maxRetries = Math.max(1, info.maxAttempts - 1);
console.warn(
log.warn(
`telegram send retry ${info.attempt}/${maxRetries} for ${info.label ?? label ?? "request"} in ${info.delayMs}ms: ${formatErrorMessage(info.err)}`,
);
}

View File

@@ -1,6 +1,7 @@
import { resolveSessionAgentId } from "../agents/agent-scope.js";
import type { OpenClawConfig } from "../config/config.js";
import type { SessionEntry, SessionMaintenanceWarning } from "../config/sessions.js";
import { createSubsystemLogger } from "../logging/subsystem.js";
import { isDeliverableMessageChannel, normalizeMessageChannel } from "../utils/message-channel.js";
import { resolveSessionDeliveryTarget } from "./outbound/targets.js";
import { enqueueSystemEvent } from "./system-events.js";
@@ -13,6 +14,7 @@ type WarningParams = {
};
const warnedContexts = new Map<string, string>();
const log = createSubsystemLogger("session-maintenance-warning");
function shouldSendWarning(): boolean {
return !process.env.VITEST && process.env.NODE_ENV !== "test";
@@ -104,7 +106,7 @@ export async function deliverSessionMaintenanceWarning(params: WarningParams): P
agentId: resolveSessionAgentId({ sessionKey: params.sessionKey, config: params.cfg }),
});
} catch (err) {
console.warn(`Failed to deliver session maintenance warning: ${String(err)}`);
log.warn(`Failed to deliver session maintenance warning: ${String(err)}`);
enqueueSystemEvent(text, { sessionKey: params.sessionKey });
}
}

View File

@@ -1,9 +1,27 @@
import { describe, expect, it } from "vitest";
import { afterEach, describe, expect, it, vi } from "vitest";
import type { OpenClawConfig } from "../config/config.js";
import { withEnv } from "../test-utils/env.js";
import { resolveTelegramAccount } from "./accounts.js";
import { listTelegramAccountIds, resolveTelegramAccount } from "./accounts.js";
const { warnMock } = vi.hoisted(() => ({
warnMock: vi.fn(),
}));
vi.mock("../logging/subsystem.js", () => ({
createSubsystemLogger: () => {
const logger = {
warn: warnMock,
child: () => logger,
};
return logger;
},
}));
describe("resolveTelegramAccount", () => {
afterEach(() => {
warnMock.mockReset();
});
it("falls back to the first configured account when accountId is omitted", () => {
withEnv({ TELEGRAM_BOT_TOKEN: "" }, () => {
const cfg: OpenClawConfig = {
@@ -63,4 +81,21 @@ describe("resolveTelegramAccount", () => {
expect(account.token).toBe("");
});
});
it("formats debug logs with inspect-style output when debug env is enabled", () => {
withEnv({ TELEGRAM_BOT_TOKEN: "", OPENCLAW_DEBUG_TELEGRAM_ACCOUNTS: "1" }, () => {
const cfg: OpenClawConfig = {
channels: {
telegram: { accounts: { work: { botToken: "tok-work" } } },
},
};
expect(listTelegramAccountIds(cfg)).toEqual(["work"]);
resolveTelegramAccount({ cfg, accountId: "work" });
});
const lines = warnMock.mock.calls.map(([line]) => String(line));
expect(lines).toContain("listTelegramAccountIds [ 'work' ]");
expect(lines).toContain("resolve { accountId: 'work', enabled: true, tokenSource: 'config' }");
});
});

View File

@@ -1,14 +1,29 @@
import util from "node:util";
import { createAccountActionGate } from "../channels/plugins/account-action-gate.js";
import type { OpenClawConfig } from "../config/config.js";
import type { TelegramAccountConfig, TelegramActionConfig } from "../config/types.js";
import { isTruthyEnvValue } from "../infra/env.js";
import { createSubsystemLogger } from "../logging/subsystem.js";
import { listBoundAccountIds, resolveDefaultAgentBoundAccountId } from "../routing/bindings.js";
import { DEFAULT_ACCOUNT_ID, normalizeAccountId } from "../routing/session-key.js";
import { resolveTelegramToken } from "./token.js";
const log = createSubsystemLogger("telegram/accounts");
function formatDebugArg(value: unknown): string {
if (typeof value === "string") {
return value;
}
if (value instanceof Error) {
return value.stack ?? value.message;
}
return util.inspect(value, { colors: false, depth: null, compact: true, breakLength: Infinity });
}
const debugAccounts = (...args: unknown[]) => {
if (isTruthyEnvValue(process.env.OPENCLAW_DEBUG_TELEGRAM_ACCOUNTS)) {
console.warn("[telegram:accounts]", ...args);
const parts = args.map((arg) => formatDebugArg(arg));
log.warn(parts.join(" ").trim());
}
};

View File

@@ -1,5 +1,6 @@
import { firstDefined, isSenderIdAllowed, mergeAllowFromSources } from "../channels/allow-from.js";
import type { AllowlistMatch } from "../channels/allowlist-match.js";
import { createSubsystemLogger } from "../logging/subsystem.js";
export type NormalizedAllowFrom = {
entries: string[];
@@ -11,6 +12,7 @@ export type NormalizedAllowFrom = {
export type AllowFromMatch = AllowlistMatch<"wildcard" | "id">;
const warnedInvalidEntries = new Set<string>();
const log = createSubsystemLogger("telegram/bot-access");
function warnInvalidAllowFromEntries(entries: string[]) {
if (process.env.VITEST || process.env.NODE_ENV === "test") {
@@ -21,9 +23,9 @@ function warnInvalidAllowFromEntries(entries: string[]) {
continue;
}
warnedInvalidEntries.add(entry);
console.warn(
log.warn(
[
"[telegram] Invalid allowFrom entry:",
"Invalid allowFrom entry:",
JSON.stringify(entry),
"- allowFrom/groupAllowFrom authorization requires numeric Telegram sender IDs only.",
'If you had "@username" entries, re-run onboarding (it resolves @username to IDs) or replace them manually.',

View File

@@ -86,6 +86,7 @@ const THREAD_NOT_FOUND_RE = /400:\s*Bad Request:\s*message thread not found/i;
const MESSAGE_NOT_MODIFIED_RE =
/400:\s*Bad Request:\s*message is not modified|MESSAGE_NOT_MODIFIED/i;
const CHAT_NOT_FOUND_RE = /400: Bad Request: chat not found/i;
const sendLogger = createSubsystemLogger("telegram/send");
const diagLogger = createSubsystemLogger("telegram/diagnostic");
function createTelegramHttpLogger(cfg: ReturnType<typeof loadConfig>) {
@@ -272,7 +273,7 @@ async function withTelegramHtmlParseFallback<T>(params: {
throw err;
}
if (params.verbose) {
console.warn(
sendLogger.warn(
`telegram ${params.label} failed with HTML parse error, retrying as plain text: ${formatErrorMessage(
err,
)}`,
@@ -378,7 +379,7 @@ async function withTelegramThreadFallback<T>(
throw err;
}
if (verbose) {
console.warn(
sendLogger.warn(
`telegram ${label} failed with message_thread_id, retrying without thread: ${formatErrorMessage(err)}`,
);
}