From aeb6b2ffad28ff5d5ae6ac3b0d9bee70b37ce90b Mon Sep 17 00:00:00 2001 From: Peter Steinberger Date: Fri, 23 Jan 2026 23:20:07 +0000 Subject: [PATCH] refactor: standardize channel logging --- extensions/bluebubbles/src/monitor.ts | 38 +++++++++++++------ .../matrix/src/matrix/monitor/handler.ts | 25 ++++++++++-- .../mattermost/src/mattermost/monitor.ts | 18 +++++++-- .../src/monitor-handler/message-handler.ts | 8 +++- extensions/msteams/src/reply-dispatcher.ts | 10 ++++- extensions/nextcloud-talk/src/inbound.ts | 16 ++++++-- src/channels/logging.ts | 33 ++++++++++++++++ .../monitor/message-handler.preflight.ts | 8 +++- .../monitor/message-handler.process.ts | 17 +++++++-- src/imessage/monitor/monitor-provider.ts | 8 +++- src/plugin-sdk/index.ts | 1 + src/signal/monitor/event-handler.ts | 15 +++++++- src/slack/monitor/message-handler/dispatch.ts | 27 ++++++++++--- src/slack/monitor/message-handler/prepare.ts | 8 +++- src/telegram/bot-message-context.ts | 8 +++- src/telegram/bot-message-dispatch.ts | 17 +++++++-- 16 files changed, 212 insertions(+), 45 deletions(-) create mode 100644 src/channels/logging.ts diff --git a/extensions/bluebubbles/src/monitor.ts b/extensions/bluebubbles/src/monitor.ts index 86d7bf63e..7c860d761 100644 --- a/extensions/bluebubbles/src/monitor.ts +++ b/extensions/bluebubbles/src/monitor.ts @@ -1,7 +1,13 @@ import type { IncomingMessage, ServerResponse } from "node:http"; import type { ClawdbotConfig } from "clawdbot/plugin-sdk"; -import { resolveAckReaction, resolveControlCommandGate } from "clawdbot/plugin-sdk"; +import { + logAckFailure, + logInboundDrop, + logTypingFailure, + resolveAckReaction, + resolveControlCommandGate, +} from "clawdbot/plugin-sdk"; import { markBlueBubblesChatRead, sendBlueBubblesTyping } from "./chat.js"; import { resolveChatGuidForTarget, sendMessageBlueBubbles } from "./send.js"; import { downloadBlueBubblesAttachment } from "./attachments.js"; @@ -1359,11 +1365,12 @@ async function processMessage( // Block control commands from unauthorized senders in groups if (isGroup && commandGate.shouldBlock) { - logVerbose( - core, - runtime, - `bluebubbles: drop control command from unauthorized sender ${message.senderId}`, - ); + logInboundDrop({ + log: (msg) => logVerbose(core, runtime, msg), + channel: "bluebubbles", + reason: "control command (unauthorized)", + target: message.senderId, + }); return; } @@ -1765,11 +1772,12 @@ async function processMessage( opts: { cfg: config, accountId: account.accountId }, }), onError: (err) => { - logVerbose( - core, - runtime, - `ack reaction removal failed chatGuid=${chatGuidForActions} msg=${ackMessageId}: ${String(err)}`, - ); + logAckFailure({ + log: (msg) => logVerbose(core, runtime, msg), + channel: "bluebubbles", + target: `${chatGuidForActions}/${ackMessageId}`, + error: err, + }); }, }); } @@ -1779,7 +1787,13 @@ async function processMessage( cfg: config, accountId: account.accountId, }).catch((err) => { - logVerbose(core, runtime, `typing stop (no reply) failed: ${String(err)}`); + logTypingFailure({ + log: (msg) => logVerbose(core, runtime, msg), + channel: "bluebubbles", + action: "stop", + target: chatGuidForActions, + error: err, + }); }); } } diff --git a/extensions/matrix/src/matrix/monitor/handler.ts b/extensions/matrix/src/matrix/monitor/handler.ts index 8bc43879f..2ba7cbef0 100644 --- a/extensions/matrix/src/matrix/monitor/handler.ts +++ b/extensions/matrix/src/matrix/monitor/handler.ts @@ -4,6 +4,8 @@ import { createReplyPrefixContext, createTypingCallbacks, formatAllowlistMatchMeta, + logInboundDrop, + logTypingFailure, resolveControlCommandGate, type RuntimeEnv, } from "clawdbot/plugin-sdk"; @@ -392,7 +394,12 @@ export function createMatrixRoomMessageHandler(params: MatrixMonitorHandlerParam }); const commandAuthorized = commandGate.commandAuthorized; if (isRoom && commandGate.shouldBlock) { - logVerboseMessage(`matrix: drop control command from unauthorized sender ${senderId}`); + logInboundDrop({ + log: logVerboseMessage, + channel: "matrix", + reason: "control command (unauthorized)", + target: senderId, + }); return; } const shouldRequireMention = isRoom @@ -559,10 +566,22 @@ export function createMatrixRoomMessageHandler(params: MatrixMonitorHandlerParam start: () => sendTypingMatrix(roomId, true, undefined, client), stop: () => sendTypingMatrix(roomId, false, undefined, client), onStartError: (err) => { - logVerboseMessage(`matrix typing cue failed for room ${roomId}: ${String(err)}`); + logTypingFailure({ + log: logVerboseMessage, + channel: "matrix", + action: "start", + target: roomId, + error: err, + }); }, onStopError: (err) => { - logVerboseMessage(`matrix typing stop failed for room ${roomId}: ${String(err)}`); + logTypingFailure({ + log: logVerboseMessage, + channel: "matrix", + action: "stop", + target: roomId, + error: err, + }); }, }); const { dispatcher, replyOptions, markDispatchIdle } = diff --git a/extensions/mattermost/src/mattermost/monitor.ts b/extensions/mattermost/src/mattermost/monitor.ts index 8dd5c6f9b..659ca83aa 100644 --- a/extensions/mattermost/src/mattermost/monitor.ts +++ b/extensions/mattermost/src/mattermost/monitor.ts @@ -9,6 +9,8 @@ import type { import { createReplyPrefixContext, createTypingCallbacks, + logInboundDrop, + logTypingFailure, buildPendingHistoryContextFromMap, clearHistoryEntriesIfEnabled, DEFAULT_GROUP_HISTORY_LIMIT, @@ -487,9 +489,12 @@ export async function monitorMattermostProvider(opts: MonitorMattermostOpts = {} } if (kind !== "dm" && commandGate.shouldBlock) { - logVerboseMessage( - `mattermost: drop control command from unauthorized sender ${senderId}`, - ); + logInboundDrop({ + log: logVerboseMessage, + channel: "mattermost", + reason: "control command (unauthorized)", + target: senderId, + }); return; } @@ -716,7 +721,12 @@ export async function monitorMattermostProvider(opts: MonitorMattermostOpts = {} const typingCallbacks = createTypingCallbacks({ start: () => sendTypingIndicator(channelId, threadRootId), onStartError: (err) => { - logger.debug?.(`mattermost typing cue failed for channel ${channelId}: ${String(err)}`); + logTypingFailure({ + log: (message) => logger.debug?.(message), + channel: "mattermost", + target: channelId, + error: err, + }); }, }); const { dispatcher, replyOptions, markDispatchIdle } = diff --git a/extensions/msteams/src/monitor-handler/message-handler.ts b/extensions/msteams/src/monitor-handler/message-handler.ts index 9bf113584..16eb8fc0a 100644 --- a/extensions/msteams/src/monitor-handler/message-handler.ts +++ b/extensions/msteams/src/monitor-handler/message-handler.ts @@ -2,6 +2,7 @@ import { buildPendingHistoryContextFromMap, clearHistoryEntriesIfEnabled, DEFAULT_GROUP_HISTORY_LIMIT, + logInboundDrop, recordPendingHistoryEntryIfEnabled, resolveControlCommandGate, resolveMentionGating, @@ -264,7 +265,12 @@ export function createMSTeamsMessageHandler(deps: MSTeamsMessageHandlerDeps) { }); const commandAuthorized = commandGate.commandAuthorized; if (commandGate.shouldBlock) { - logVerboseMessage(`msteams: drop control command from unauthorized sender ${senderId}`); + logInboundDrop({ + log: logVerboseMessage, + channel: "msteams", + reason: "control command (unauthorized)", + target: senderId, + }); return; } diff --git a/extensions/msteams/src/reply-dispatcher.ts b/extensions/msteams/src/reply-dispatcher.ts index 31e334de2..449a14fe2 100644 --- a/extensions/msteams/src/reply-dispatcher.ts +++ b/extensions/msteams/src/reply-dispatcher.ts @@ -1,6 +1,7 @@ import { createReplyPrefixContext, createTypingCallbacks, + logTypingFailure, resolveChannelMediaMaxBytes, type ClawdbotConfig, type MSTeamsReplyStyle, @@ -45,8 +46,13 @@ export function createMSTeamsReplyDispatcher(params: { }; const typingCallbacks = createTypingCallbacks({ start: sendTypingIndicator, - onStartError: () => { - // Typing indicator is best-effort. + onStartError: (err) => { + logTypingFailure({ + log: (message) => params.log.debug(message), + channel: "msteams", + action: "start", + error: err, + }); }, }); const prefixContext = createReplyPrefixContext({ diff --git a/extensions/nextcloud-talk/src/inbound.ts b/extensions/nextcloud-talk/src/inbound.ts index ec99ba8f3..77db9f338 100644 --- a/extensions/nextcloud-talk/src/inbound.ts +++ b/extensions/nextcloud-talk/src/inbound.ts @@ -1,4 +1,9 @@ -import { resolveControlCommandGate, type ClawdbotConfig, type RuntimeEnv } from "clawdbot/plugin-sdk"; +import { + logInboundDrop, + resolveControlCommandGate, + type ClawdbotConfig, + type RuntimeEnv, +} from "clawdbot/plugin-sdk"; import type { ResolvedNextcloudTalkAccount } from "./accounts.js"; import { @@ -196,9 +201,12 @@ export async function handleNextcloudTalkInbound(params: { } if (isGroup && commandGate.shouldBlock) { - runtime.log?.( - `nextcloud-talk: drop control command from unauthorized sender ${senderId}`, - ); + logInboundDrop({ + log: (message) => runtime.log?.(message), + channel: CHANNEL_ID, + reason: "control command (unauthorized)", + target: senderId, + }); return; } diff --git a/src/channels/logging.ts b/src/channels/logging.ts new file mode 100644 index 000000000..0e124a14d --- /dev/null +++ b/src/channels/logging.ts @@ -0,0 +1,33 @@ +export type LogFn = (message: string) => void; + +export function logInboundDrop(params: { + log: LogFn; + channel: string; + reason: string; + target?: string; +}): void { + const target = params.target ? ` target=${params.target}` : ""; + params.log(`${params.channel}: drop ${params.reason}${target}`); +} + +export function logTypingFailure(params: { + log: LogFn; + channel: string; + target?: string; + action?: "start" | "stop"; + error: unknown; +}): void { + const target = params.target ? ` target=${params.target}` : ""; + const action = params.action ? ` action=${params.action}` : ""; + params.log(`${params.channel} typing${action} failed${target}: ${String(params.error)}`); +} + +export function logAckFailure(params: { + log: LogFn; + channel: string; + target?: string; + error: unknown; +}): void { + const target = params.target ? ` target=${params.target}` : ""; + params.log(`${params.channel} ack cleanup failed${target}: ${String(params.error)}`); +} diff --git a/src/discord/monitor/message-handler.preflight.ts b/src/discord/monitor/message-handler.preflight.ts index d378ad871..5245fe253 100644 --- a/src/discord/monitor/message-handler.preflight.ts +++ b/src/discord/monitor/message-handler.preflight.ts @@ -21,6 +21,7 @@ import { resolveMentionGatingWithBypass } from "../../channels/mention-gating.js import { formatAllowlistMatchMeta } from "../../channels/allowlist-match.js"; import { sendMessageDiscord } from "../send.js"; import { resolveControlCommandGate } from "../../channels/command-gating.js"; +import { logInboundDrop } from "../../channels/logging.js"; import { allowListMatches, isDiscordGroupAllowedByPolicy, @@ -385,7 +386,12 @@ export async function preflightDiscordMessage( commandAuthorized = commandGate.commandAuthorized; if (commandGate.shouldBlock) { - logVerbose(`Blocked discord control command from unauthorized sender ${author.id}`); + logInboundDrop({ + log: logVerbose, + channel: "discord", + reason: "control command (unauthorized)", + target: author.id, + }); return null; } } diff --git a/src/discord/monitor/message-handler.process.ts b/src/discord/monitor/message-handler.process.ts index 172f885ac..5297caf49 100644 --- a/src/discord/monitor/message-handler.process.ts +++ b/src/discord/monitor/message-handler.process.ts @@ -3,6 +3,7 @@ import { removeAckReactionAfterReply, shouldAckReaction as shouldAckReactionGate, } from "../../channels/ack-reactions.js"; +import { logTypingFailure, logAckFailure } from "../../channels/logging.js"; import { createReplyPrefixContext } from "../../channels/reply-prefix.js"; import { createTypingCallbacks } from "../../channels/typing.js"; import { @@ -343,7 +344,12 @@ export async function processDiscordMessage(ctx: DiscordMessagePreflightContext) onReplyStart: createTypingCallbacks({ start: () => sendTyping({ client, channelId: typingChannelId }), onStartError: (err) => { - logVerbose(`discord typing cue failed for channel ${typingChannelId}: ${String(err)}`); + logTypingFailure({ + log: logVerbose, + channel: "discord", + target: typingChannelId, + error: err, + }); }, }).onReplyStart, }); @@ -388,9 +394,12 @@ export async function processDiscordMessage(ctx: DiscordMessagePreflightContext) remove: () => removeReactionDiscord(message.channelId, message.id, ackReaction, { rest: client.rest }), onError: (err) => { - logVerbose( - `discord: failed to remove ack reaction from ${message.channelId}/${message.id}: ${String(err)}`, - ); + logAckFailure({ + log: logVerbose, + channel: "discord", + target: `${message.channelId}/${message.id}`, + error: err, + }); }, }); if (isGuildMessage) { diff --git a/src/imessage/monitor/monitor-provider.ts b/src/imessage/monitor/monitor-provider.ts index f9126346e..fa0ce2195 100644 --- a/src/imessage/monitor/monitor-provider.ts +++ b/src/imessage/monitor/monitor-provider.ts @@ -23,6 +23,7 @@ import { } from "../../auto-reply/reply/history.js"; import { buildMentionRegexes, matchesMentionPatterns } from "../../auto-reply/reply/mentions.js"; import { createReplyDispatcher } from "../../auto-reply/reply/reply-dispatcher.js"; +import { logInboundDrop } from "../../channels/logging.js"; import { createReplyPrefixContext } from "../../channels/reply-prefix.js"; import { recordInboundSession } from "../../channels/session.js"; import { loadConfig } from "../../config/config.js"; @@ -384,7 +385,12 @@ export async function monitorIMessageProvider(opts: MonitorIMessageOpts = {}): P }); const commandAuthorized = isGroup ? commandGate.commandAuthorized : dmAuthorized; if (isGroup && commandGate.shouldBlock) { - logVerbose(`imessage: drop control command from unauthorized sender ${sender}`); + logInboundDrop({ + log: logVerbose, + channel: "imessage", + reason: "control command (unauthorized)", + target: sender, + }); return; } const shouldBypassMention = diff --git a/src/plugin-sdk/index.ts b/src/plugin-sdk/index.ts index 9ee7015bf..167838b52 100644 --- a/src/plugin-sdk/index.ts +++ b/src/plugin-sdk/index.ts @@ -131,6 +131,7 @@ export { } from "../channels/ack-reactions.js"; export { createTypingCallbacks } from "../channels/typing.js"; export { createReplyPrefixContext } from "../channels/reply-prefix.js"; +export { logAckFailure, logInboundDrop, logTypingFailure } from "../channels/logging.js"; export { resolveChannelMediaMaxBytes } from "../channels/plugins/media-limits.js"; export type { NormalizedLocation } from "../channels/location.js"; export { formatLocationText, toLocationContext } from "../channels/location.js"; diff --git a/src/signal/monitor/event-handler.ts b/src/signal/monitor/event-handler.ts index 2c9105664..72195ff78 100644 --- a/src/signal/monitor/event-handler.ts +++ b/src/signal/monitor/event-handler.ts @@ -16,6 +16,7 @@ import { } from "../../auto-reply/reply/history.js"; import { finalizeInboundContext } from "../../auto-reply/reply/inbound-context.js"; import { createReplyDispatcherWithTyping } from "../../auto-reply/reply/reply-dispatcher.js"; +import { logInboundDrop, logTypingFailure } from "../../channels/logging.js"; import { createReplyPrefixContext } from "../../channels/reply-prefix.js"; import { recordInboundSession } from "../../channels/session.js"; import { createTypingCallbacks } from "../../channels/typing.js"; @@ -183,7 +184,12 @@ export function createSignalEventHandler(deps: SignalEventHandlerDeps) { }); }, onStartError: (err) => { - logVerbose(`signal typing cue failed for ${ctxPayload.To}: ${String(err)}`); + logTypingFailure({ + log: logVerbose, + channel: "signal", + target: ctxPayload.To ?? undefined, + error: err, + }); }, }); @@ -451,7 +457,12 @@ export function createSignalEventHandler(deps: SignalEventHandlerDeps) { }); const commandAuthorized = isGroup ? commandGate.commandAuthorized : dmAllowed; if (isGroup && commandGate.shouldBlock) { - logVerbose(`signal: drop control command from unauthorized sender ${senderDisplay}`); + logInboundDrop({ + log: logVerbose, + channel: "signal", + reason: "control command (unauthorized)", + target: senderDisplay, + }); return; } diff --git a/src/slack/monitor/message-handler/dispatch.ts b/src/slack/monitor/message-handler/dispatch.ts index 14f9cfb61..32968aa17 100644 --- a/src/slack/monitor/message-handler/dispatch.ts +++ b/src/slack/monitor/message-handler/dispatch.ts @@ -2,6 +2,7 @@ import { resolveHumanDelayConfig } from "../../../agents/identity.js"; import { dispatchInboundMessage } from "../../../auto-reply/dispatch.js"; import { clearHistoryEntriesIfEnabled } from "../../../auto-reply/reply/history.js"; import { removeAckReactionAfterReply } from "../../../channels/ack-reactions.js"; +import { logAckFailure, logTypingFailure } from "../../../channels/logging.js"; import { createReplyPrefixContext } from "../../../channels/reply-prefix.js"; import { createTypingCallbacks } from "../../../channels/typing.js"; import { createReplyDispatcherWithTyping } from "../../../auto-reply/reply/reply-dispatcher.js"; @@ -55,6 +56,7 @@ export async function dispatchPreparedSlackMessage(prepared: PreparedSlackMessag hasRepliedRef, }); + const typingTarget = statusThreadTs ? `${message.channel}/${statusThreadTs}` : message.channel; const typingCallbacks = createTypingCallbacks({ start: async () => { didSetStatus = true; @@ -73,10 +75,22 @@ export async function dispatchPreparedSlackMessage(prepared: PreparedSlackMessag }); }, onStartError: (err) => { - runtime.error?.(danger(`slack typing cue failed: ${String(err)}`)); + logTypingFailure({ + log: (message) => runtime.error?.(danger(message)), + channel: "slack", + action: "start", + target: typingTarget, + error: err, + }); }, onStopError: (err) => { - runtime.error?.(danger(`slack typing stop failed: ${String(err)}`)); + logTypingFailure({ + log: (message) => runtime.error?.(danger(message)), + channel: "slack", + action: "stop", + target: typingTarget, + error: err, + }); }, }); @@ -159,9 +173,12 @@ export async function dispatchPreparedSlackMessage(prepared: PreparedSlackMessag }, ), onError: (err) => { - logVerbose( - `slack: failed to remove ack reaction from ${message.channel}/${message.ts}: ${String(err)}`, - ); + logAckFailure({ + log: logVerbose, + channel: "slack", + target: `${message.channel}/${message.ts}`, + error: err, + }); }, }); diff --git a/src/slack/monitor/message-handler/prepare.ts b/src/slack/monitor/message-handler/prepare.ts index 8014a3ef7..24c251d2a 100644 --- a/src/slack/monitor/message-handler/prepare.ts +++ b/src/slack/monitor/message-handler/prepare.ts @@ -26,6 +26,7 @@ import { import { resolveMentionGatingWithBypass } from "../../../channels/mention-gating.js"; import { resolveConversationLabel } from "../../../channels/conversation-label.js"; import { resolveControlCommandGate } from "../../../channels/command-gating.js"; +import { logInboundDrop } from "../../../channels/logging.js"; import { formatAllowlistMatchMeta } from "../../../channels/allowlist-match.js"; import { recordInboundSession } from "../../../channels/session.js"; import { readSessionUpdatedAt, resolveStorePath } from "../../../config/sessions.js"; @@ -265,7 +266,12 @@ export async function prepareSlackMessage(params: { const commandAuthorized = commandGate.commandAuthorized; if (isRoomish && commandGate.shouldBlock) { - logVerbose(`Blocked slack control command from unauthorized sender ${senderId}`); + logInboundDrop({ + log: logVerbose, + channel: "slack", + reason: "control command (unauthorized)", + target: senderId, + }); return null; } diff --git a/src/telegram/bot-message-context.ts b/src/telegram/bot-message-context.ts index 597a7cc79..e4a7d6780 100644 --- a/src/telegram/bot-message-context.ts +++ b/src/telegram/bot-message-context.ts @@ -23,6 +23,7 @@ import { resolveAgentRoute } from "../routing/resolve-route.js"; import { shouldAckReaction as shouldAckReactionGate } from "../channels/ack-reactions.js"; import { resolveMentionGatingWithBypass } from "../channels/mention-gating.js"; import { resolveControlCommandGate } from "../channels/command-gating.js"; +import { logInboundDrop } from "../channels/logging.js"; import { buildGroupLabel, buildSenderLabel, @@ -306,7 +307,12 @@ export const buildTelegramMessageContext = async ({ (ent) => ent.type === "mention", ); if (isGroup && commandGate.shouldBlock) { - logVerbose(`telegram: drop control command from unauthorized sender ${senderId ?? "unknown"}`); + logInboundDrop({ + log: logVerbose, + channel: "telegram", + reason: "control command (unauthorized)", + target: senderId ?? "unknown", + }); return null; } const activationOverride = resolveGroupActivation({ diff --git a/src/telegram/bot-message-dispatch.ts b/src/telegram/bot-message-dispatch.ts index 55d1e9f87..98c5a6d40 100644 --- a/src/telegram/bot-message-dispatch.ts +++ b/src/telegram/bot-message-dispatch.ts @@ -3,6 +3,7 @@ import { EmbeddedBlockChunker } from "../agents/pi-embedded-block-chunker.js"; import { clearHistoryEntriesIfEnabled } from "../auto-reply/reply/history.js"; import { dispatchReplyWithBufferedBlockDispatcher } from "../auto-reply/reply/provider-dispatcher.js"; import { removeAckReactionAfterReply } from "../channels/ack-reactions.js"; +import { logAckFailure, logTypingFailure } from "../channels/logging.js"; import { createReplyPrefixContext } from "../channels/reply-prefix.js"; import { createTypingCallbacks } from "../channels/typing.js"; import { danger, logVerbose } from "../globals.js"; @@ -155,7 +156,12 @@ export const dispatchTelegramMessage = async ({ onReplyStart: createTypingCallbacks({ start: sendTyping, onStartError: (err) => { - logVerbose(`telegram typing cue failed for chat ${chatId}: ${String(err)}`); + logTypingFailure({ + log: logVerbose, + channel: "telegram", + target: String(chatId), + error: err, + }); }, }).onReplyStart, }, @@ -187,9 +193,12 @@ export const dispatchTelegramMessage = async ({ remove: () => reactionApi?.(chatId, msg.message_id ?? 0, []) ?? Promise.resolve(), onError: (err) => { if (!msg.message_id) return; - logVerbose( - `telegram: failed to remove ack reaction from ${chatId}/${msg.message_id}: ${String(err)}`, - ); + logAckFailure({ + log: logVerbose, + channel: "telegram", + target: `${chatId}/${msg.message_id}`, + error: err, + }); }, }); if (isGroup && historyKey) {