From 2f46308d5a9f38060181eb402034392e8dc66237 Mon Sep 17 00:00:00 2001 From: Gustavo Madeira Santana Date: Sat, 21 Feb 2026 17:44:00 -0500 Subject: [PATCH] refactor(logging): migrate non-agent internal console calls to subsystem logger (#22964) Merged via /review-pr -> /prepare-pr -> /merge-pr. Prepared head SHA: b4a5b12422c7a90054dbb7473dd6c4b3e9ca8df5 Co-authored-by: gumadeiras <5599352+gumadeiras@users.noreply.github.com> Co-authored-by: gumadeiras <5599352+gumadeiras@users.noreply.github.com> Reviewed-by: @gumadeiras --- src/auto-reply/reply/session.ts | 9 +++-- src/config/sessions/store.ts | 2 +- src/discord/monitor/native-command.ts | 5 ++- .../bundled/bootstrap-extra-files/handler.ts | 4 +- src/hooks/bundled/command-logger/handler.ts | 9 +++-- src/hooks/internal-hooks.ts | 8 ++-- src/hooks/llm-slug-generator.ts | 6 ++- src/hooks/workspace.ts | 11 ++++-- src/infra/retry-policy.ts | 6 ++- src/infra/session-maintenance-warning.ts | 4 +- src/telegram/accounts.test.ts | 39 ++++++++++++++++++- src/telegram/accounts.ts | 17 +++++++- src/telegram/bot-access.ts | 6 ++- src/telegram/send.ts | 5 ++- 14 files changed, 102 insertions(+), 29 deletions(-) diff --git a/src/auto-reply/reply/session.ts b/src/auto-reply/reply/session.ts index cb4b8a194ed..e9bf4b26083 100644 --- a/src/auto-reply/reply/session.ts +++ b/src/auto-reply/reply/session.ts @@ -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 diff --git a/src/config/sessions/store.ts b/src/config/sessions/store.ts index 5807df590a9..9ad45976b1f 100644 --- a/src/config/sessions/store.ts +++ b/src/config/sessions/store.ts @@ -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}`); } } } diff --git a/src/discord/monitor/native-command.ts b/src/discord/monitor/native-command.ts index 19c0bc474dc..7391d36cba2 100644 --- a/src/discord/monitor/native-command.ts +++ b/src/discord/monitor/native-command.ts @@ -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["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: { diff --git a/src/hooks/bundled/bootstrap-extra-files/handler.ts b/src/hooks/bundled/bootstrap-extra-files/handler.ts index ada7286909d..2f015b280fc 100644 --- a/src/hooks/bundled/bootstrap-extra-files/handler.ts +++ b/src/hooks/bundled/bootstrap-extra-files/handler.ts @@ -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)}`); } }; diff --git a/src/hooks/bundled/command-logger/handler.ts b/src/hooks/bundled/command-logger/handler.ts index b86afb7fb5c..e9ee6527551 100644 --- a/src/hooks/bundled/command-logger/handler.ts +++ b/src/hooks/bundled/command-logger/handler.ts @@ -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}`); } }; diff --git a/src/hooks/internal-hooks.ts b/src/hooks/internal-hooks.ts index 1e69057e4a8..95c70597f2b 100644 --- a/src/hooks/internal-hooks.ts +++ b/src/hooks/internal-hooks.ts @@ -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 | /** Registry of hook handlers by event key */ const handlers = new Map(); +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>; +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; } diff --git a/src/infra/retry-policy.ts b/src/infra/retry-policy.ts index d0a23217925..78737241e0b 100644 --- a/src/infra/retry-policy.ts +++ b/src/infra/retry-policy.ts @@ -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)}`, ); } diff --git a/src/infra/session-maintenance-warning.ts b/src/infra/session-maintenance-warning.ts index 37ebee275ef..804b419ed3a 100644 --- a/src/infra/session-maintenance-warning.ts +++ b/src/infra/session-maintenance-warning.ts @@ -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(); +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 }); } } diff --git a/src/telegram/accounts.test.ts b/src/telegram/accounts.test.ts index e488d27c20b..c254ced27c0 100644 --- a/src/telegram/accounts.test.ts +++ b/src/telegram/accounts.test.ts @@ -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' }"); + }); }); diff --git a/src/telegram/accounts.ts b/src/telegram/accounts.ts index e0bfcf79192..c608eac1987 100644 --- a/src/telegram/accounts.ts +++ b/src/telegram/accounts.ts @@ -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()); } }; diff --git a/src/telegram/bot-access.ts b/src/telegram/bot-access.ts index 338788a2452..73f1dbec57a 100644 --- a/src/telegram/bot-access.ts +++ b/src/telegram/bot-access.ts @@ -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(); +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.', diff --git a/src/telegram/send.ts b/src/telegram/send.ts index 6959f3930ad..56f666493c3 100644 --- a/src/telegram/send.ts +++ b/src/telegram/send.ts @@ -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) { @@ -272,7 +273,7 @@ async function withTelegramHtmlParseFallback(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( throw err; } if (verbose) { - console.warn( + sendLogger.warn( `telegram ${label} failed with message_thread_id, retrying without thread: ${formatErrorMessage(err)}`, ); }