fix: emit diagnostics across channels

This commit is contained in:
Peter Steinberger
2026-01-21 00:29:42 +00:00
parent e447233533
commit ec01e5c7e6
8 changed files with 318 additions and 275 deletions

View File

@@ -2,14 +2,6 @@ import { beforeEach, describe, expect, it, vi } from "vitest";
const buildTelegramMessageContext = vi.hoisted(() => vi.fn());
const dispatchTelegramMessage = vi.hoisted(() => vi.fn());
const logMessageQueued = vi.hoisted(() => vi.fn());
const logMessageProcessed = vi.hoisted(() => vi.fn());
const logSessionStateChange = vi.hoisted(() => vi.fn());
const diagnosticLogger = vi.hoisted(() => ({
info: vi.fn(),
debug: vi.fn(),
error: vi.fn(),
}));
vi.mock("./bot-message-context.js", () => ({
buildTelegramMessageContext,
@@ -19,25 +11,12 @@ vi.mock("./bot-message-dispatch.js", () => ({
dispatchTelegramMessage,
}));
vi.mock("../logging/diagnostic.js", () => ({
diagnosticLogger,
logMessageQueued,
logMessageProcessed,
logSessionStateChange,
}));
import { createTelegramMessageProcessor } from "./bot-message.js";
describe("telegram bot message diagnostics", () => {
describe("telegram bot message processor", () => {
beforeEach(() => {
buildTelegramMessageContext.mockReset();
dispatchTelegramMessage.mockReset();
logMessageQueued.mockReset();
logMessageProcessed.mockReset();
logSessionStateChange.mockReset();
diagnosticLogger.info.mockReset();
diagnosticLogger.debug.mockReset();
diagnosticLogger.error.mockReset();
});
const baseDeps = {
@@ -63,39 +42,19 @@ describe("telegram bot message diagnostics", () => {
resolveBotTopicsEnabled: () => false,
};
it("decrements queue depth after successful processing", async () => {
buildTelegramMessageContext.mockResolvedValue({
route: { sessionKey: "agent:main:main" },
});
it("dispatches when context is available", async () => {
buildTelegramMessageContext.mockResolvedValue({ route: { sessionKey: "agent:main:main" } });
const processMessage = createTelegramMessageProcessor(baseDeps);
await processMessage({ message: { chat: { id: 123 }, message_id: 456 } }, [], [], {});
expect(logMessageQueued).toHaveBeenCalledTimes(1);
expect(logSessionStateChange).toHaveBeenCalledWith({
sessionKey: "agent:main:main",
state: "idle",
reason: "message_completed",
});
expect(dispatchTelegramMessage).toHaveBeenCalledTimes(1);
});
it("decrements queue depth after processing error", async () => {
buildTelegramMessageContext.mockResolvedValue({
route: { sessionKey: "agent:main:main" },
});
dispatchTelegramMessage.mockRejectedValue(new Error("boom"));
it("skips dispatch when no context is produced", async () => {
buildTelegramMessageContext.mockResolvedValue(null);
const processMessage = createTelegramMessageProcessor(baseDeps);
await expect(
processMessage({ message: { chat: { id: 123 }, message_id: 456 } }, [], [], {}),
).rejects.toThrow("boom");
expect(logMessageQueued).toHaveBeenCalledTimes(1);
expect(logSessionStateChange).toHaveBeenCalledWith({
sessionKey: "agent:main:main",
state: "idle",
reason: "message_error",
});
await processMessage({ message: { chat: { id: 123 }, message_id: 456 } }, [], [], {});
expect(dispatchTelegramMessage).not.toHaveBeenCalled();
});
});

View File

@@ -1,12 +1,6 @@
// @ts-nocheck
import { buildTelegramMessageContext } from "./bot-message-context.js";
import { dispatchTelegramMessage } from "./bot-message-dispatch.js";
import {
diagnosticLogger as diag,
logMessageProcessed,
logMessageQueued,
logSessionStateChange,
} from "../logging/diagnostic.js";
export const createTelegramMessageProcessor = (deps) => {
const {
@@ -33,122 +27,37 @@ export const createTelegramMessageProcessor = (deps) => {
} = deps;
return async (primaryCtx, allMedia, storeAllowFrom, options) => {
const chatId = primaryCtx?.message?.chat?.id ?? primaryCtx?.chat?.id ?? "unknown";
const messageId = primaryCtx?.message?.message_id ?? "unknown";
const startTime = Date.now();
diag.info(
`process message start: channel=telegram chatId=${chatId} messageId=${messageId} mediaCount=${
allMedia?.length ?? 0
}`,
);
let sessionKey: string | undefined;
try {
const context = await buildTelegramMessageContext({
primaryCtx,
allMedia,
storeAllowFrom,
options,
bot,
cfg,
account,
historyLimit,
groupHistories,
dmPolicy,
allowFrom,
groupAllowFrom,
ackReactionScope,
logger,
resolveGroupActivation,
resolveGroupRequireMention,
resolveTelegramGroupConfig,
});
if (!context) {
const durationMs = Date.now() - startTime;
diag.debug(
`process message skipped: channel=telegram chatId=${chatId} messageId=${messageId} reason=no_context`,
);
logMessageProcessed({
channel: "telegram",
chatId,
messageId,
durationMs,
outcome: "skipped",
reason: "no_context",
});
return;
}
sessionKey = context?.route?.sessionKey;
diag.info(
`process message dispatching: channel=telegram chatId=${chatId} messageId=${messageId} sessionKey=${
sessionKey ?? "unknown"
}`,
);
if (sessionKey) {
logMessageQueued({ sessionKey, channel: "telegram", source: "telegram" });
}
await dispatchTelegramMessage({
context,
bot,
cfg,
runtime,
replyToMode,
streamMode,
textLimit,
telegramCfg,
opts,
resolveBotTopicsEnabled,
});
const durationMs = Date.now() - startTime;
logMessageProcessed({
channel: "telegram",
chatId,
messageId,
sessionKey,
durationMs,
outcome: "completed",
});
if (sessionKey) {
logSessionStateChange({
sessionKey,
state: "idle",
reason: "message_completed",
});
}
diag.info(
`process message complete: channel=telegram chatId=${chatId} messageId=${messageId} sessionKey=${
sessionKey ?? "unknown"
} durationMs=${durationMs}`,
);
} catch (err) {
const durationMs = Date.now() - startTime;
logMessageProcessed({
channel: "telegram",
chatId,
messageId,
sessionKey,
durationMs,
outcome: "error",
error: String(err),
});
if (sessionKey) {
logSessionStateChange({
sessionKey,
state: "idle",
reason: "message_error",
});
}
diag.error(
`process message error: channel=telegram chatId=${chatId} messageId=${messageId} durationMs=${durationMs} error="${String(
err,
)}"`,
);
throw err;
}
const context = await buildTelegramMessageContext({
primaryCtx,
allMedia,
storeAllowFrom,
options,
bot,
cfg,
account,
historyLimit,
groupHistories,
dmPolicy,
allowFrom,
groupAllowFrom,
ackReactionScope,
logger,
resolveGroupActivation,
resolveGroupRequireMention,
resolveTelegramGroupConfig,
});
if (!context) return;
await dispatchTelegramMessage({
context,
bot,
cfg,
runtime,
replyToMode,
streamMode,
textLimit,
telegramCfg,
opts,
resolveBotTopicsEnabled,
});
};
};

View File

@@ -2,6 +2,7 @@ import { createServer } from "node:http";
import { webhookCallback } from "grammy";
import type { ClawdbotConfig } from "../config/config.js";
import { isDiagnosticsEnabled } from "../infra/diagnostic-events.js";
import { formatErrorMessage } from "../infra/errors.js";
import type { RuntimeEnv } from "../runtime.js";
import { defaultRuntime } from "../runtime.js";
@@ -34,6 +35,7 @@ export async function startTelegramWebhook(opts: {
const port = opts.port ?? 8787;
const host = opts.host ?? "0.0.0.0";
const runtime = opts.runtime ?? defaultRuntime;
const diagnosticsEnabled = isDiagnosticsEnabled(opts.config);
const bot = createTelegramBot({
token: opts.token,
runtime,
@@ -45,7 +47,9 @@ export async function startTelegramWebhook(opts: {
secretToken: opts.secret,
});
startDiagnosticHeartbeat();
if (diagnosticsEnabled) {
startDiagnosticHeartbeat();
}
const server = createServer((req, res) => {
if (req.url === healthPath) {
@@ -59,24 +63,30 @@ export async function startTelegramWebhook(opts: {
return;
}
const startTime = Date.now();
logWebhookReceived({ channel: "telegram", updateType: "telegram-post" });
if (diagnosticsEnabled) {
logWebhookReceived({ channel: "telegram", updateType: "telegram-post" });
}
const handled = handler(req, res);
if (handled && typeof (handled as Promise<void>).catch === "function") {
void (handled as Promise<void>)
.then(() => {
logWebhookProcessed({
channel: "telegram",
updateType: "telegram-post",
durationMs: Date.now() - startTime,
});
if (diagnosticsEnabled) {
logWebhookProcessed({
channel: "telegram",
updateType: "telegram-post",
durationMs: Date.now() - startTime,
});
}
})
.catch((err) => {
const errMsg = formatErrorMessage(err);
logWebhookError({
channel: "telegram",
updateType: "telegram-post",
error: errMsg,
});
if (diagnosticsEnabled) {
logWebhookError({
channel: "telegram",
updateType: "telegram-post",
error: errMsg,
});
}
runtime.log?.(`webhook handler failed: ${errMsg}`);
if (!res.headersSent) res.writeHead(500);
res.end();
@@ -98,7 +108,9 @@ export async function startTelegramWebhook(opts: {
const shutdown = () => {
server.close();
void bot.stop();
stopDiagnosticHeartbeat();
if (diagnosticsEnabled) {
stopDiagnosticHeartbeat();
}
};
if (opts.abortSignal) {
opts.abortSignal.addEventListener("abort", shutdown, { once: true });