refactor: standardize channel logging

This commit is contained in:
Peter Steinberger
2026-01-23 23:20:07 +00:00
parent 07ce1d73ff
commit aeb6b2ffad
16 changed files with 212 additions and 45 deletions

View File

@@ -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,
});
});
}
}

View File

@@ -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 } =

View File

@@ -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 } =

View File

@@ -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;
}

View File

@@ -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({

View File

@@ -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;
}

33
src/channels/logging.ts Normal file
View File

@@ -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)}`);
}

View File

@@ -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;
}
}

View File

@@ -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) {

View File

@@ -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 =

View File

@@ -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";

View File

@@ -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;
}

View File

@@ -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,
});
},
});

View File

@@ -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;
}

View File

@@ -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({

View File

@@ -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) {