diff --git a/extensions/slack/src/monitor/events/messages.test.ts b/extensions/slack/src/monitor/events/messages.test.ts index 3ee99e654bab..0e334f06e84a 100644 --- a/extensions/slack/src/monitor/events/messages.test.ts +++ b/extensions/slack/src/monitor/events/messages.test.ts @@ -5,11 +5,32 @@ import { type SlackSystemEventTestOverrides, } from "./system-event-test-harness.js"; -const { messageQueueMock, messageAllowMock } = vi.hoisted(() => ({ +const { messageQueueMock, messageAllowMock, inboundInfoSpy } = vi.hoisted(() => ({ messageQueueMock: vi.fn(), messageAllowMock: vi.fn(), + inboundInfoSpy: vi.fn(), })); +vi.mock("openclaw/plugin-sdk/runtime-env", async (importOriginal) => { + const actual = await importOriginal(); + const makeLogger = () => { + const logger = { + subsystem: "test", + isEnabled: () => true, + trace: () => {}, + debug: () => {}, + info: inboundInfoSpy, + warn: () => {}, + error: () => {}, + fatal: () => {}, + raw: () => {}, + child: () => logger, + }; + return logger; + }; + return { ...actual, createSubsystemLogger: () => makeLogger() }; +}); + vi.mock("openclaw/plugin-sdk/system-event-runtime", () => ({ enqueueSystemEvent: (...args: unknown[]) => messageQueueMock(...args), })); @@ -21,6 +42,13 @@ vi.mock("openclaw/plugin-sdk/conversation-runtime", () => ({ })); let registerSlackMessageEvents: typeof import("./messages.js").registerSlackMessageEvents; +let formatSlackInboundLogLine: typeof import("./messages.js").formatSlackInboundLogLine; + +function inboundLogLines(): string[] { + return inboundInfoSpy.mock.calls + .map((call) => call[0]) + .filter((line): line is string => typeof line === "string" && line.startsWith("Inbound ")); +} type MessageHandler = (args: { event: Record; body: unknown }) => Promise; type RegisteredEventName = "message" | "app_mention"; @@ -57,11 +85,12 @@ function resetMessageMocks(): void { } beforeAll(async () => { - ({ registerSlackMessageEvents } = await import("./messages.js")); + ({ registerSlackMessageEvents, formatSlackInboundLogLine } = await import("./messages.js")); }); beforeEach(() => { resetMessageMocks(); + inboundInfoSpy.mockClear(); }); function makeChangedEvent(overrides?: { channel?: string; user?: string }) { @@ -387,6 +416,8 @@ describe("registerSlackMessageEvents", () => { }); expect(handleSlackMessage).not.toHaveBeenCalled(); + // Dropped DM app_mention (already handled via message.im) must not log a receipt. + expect(inboundLogLines()).toEqual([]); }); it("routes app_mention events from channels to the message handler", async () => { @@ -397,5 +428,55 @@ describe("registerSlackMessageEvents", () => { }); expect(handleSlackMessage).toHaveBeenCalledTimes(1); + expect(inboundLogLines()).toEqual([ + "Inbound app_mention slack:T_TEST:channel:C123:user:U1 -> bot:U_BOT (channel, 14 chars)", + ]); + }); + + it("logs channel app_mention receipts with zero chars when text is absent", async () => { + const { handleSlackMessage } = await invokeRegisteredHandler({ + eventName: "app_mention", + overrides: { dmPolicy: "open" }, + event: { + ...makeAppMentionEvent({ channel: "C123", channelType: "channel" }), + text: undefined, + }, + }); + + expect(handleSlackMessage).toHaveBeenCalledTimes(1); + expect(inboundLogLines()).toEqual([ + "Inbound app_mention slack:T_TEST:channel:C123:user:U1 -> bot:U_BOT (channel, 0 chars)", + ]); + }); + + it("logs channel app_mention receipts with unknown sender when user is absent", async () => { + const { handleSlackMessage } = await invokeRegisteredHandler({ + eventName: "app_mention", + overrides: { dmPolicy: "open" }, + event: { + ...makeAppMentionEvent({ channel: "C123", channelType: "channel" }), + user: undefined, + }, + }); + + expect(handleSlackMessage).toHaveBeenCalledTimes(1); + expect(inboundLogLines()).toEqual([ + "Inbound app_mention slack:T_TEST:channel:C123:user:unknown -> bot:U_BOT (channel, 14 chars)", + ]); + }); + + it("formats the inbound receipt line with channel, sender, body length, and bot identity", () => { + expect( + formatSlackInboundLogLine({ + workspaceId: "T123", + channelId: "C456", + channelType: "channel", + userId: "U789", + botUserId: "U_BOT", + bodyChars: 42, + }), + ).toBe( + "Inbound app_mention slack:T123:channel:C456:user:U789 -> bot:U_BOT (channel, 42 chars)", + ); }); }); diff --git a/extensions/slack/src/monitor/events/messages.ts b/extensions/slack/src/monitor/events/messages.ts index 2e21d1887c00..856f64797fc3 100644 --- a/extensions/slack/src/monitor/events/messages.ts +++ b/extensions/slack/src/monitor/events/messages.ts @@ -1,7 +1,12 @@ // Slack plugin module implements messages behavior. import type { SlackEventMiddlewareArgs } from "@slack/bolt"; import { formatErrorMessage } from "openclaw/plugin-sdk/error-runtime"; -import { danger, logVerbose, shouldLogVerbose } from "openclaw/plugin-sdk/runtime-env"; +import { + createSubsystemLogger, + danger, + logVerbose, + shouldLogVerbose, +} from "openclaw/plugin-sdk/runtime-env"; import { asOptionalRecord as asRecord, normalizeOptionalString as asString, @@ -15,6 +20,22 @@ import type { SlackMessageChangedEvent } from "../types.js"; import { resolveSlackMessageSubtypeHandler } from "./message-subtype-handlers.js"; import { authorizeAndResolveSlackSystemEventContext } from "./system-event-context.js"; +// Mirrors the Telegram `[telegram]` inbound logger so cross-channel journal-grep +// workflows are uniform; the `gateway/channels/slack` subsystem renders as `[slack]`. +const slackInboundLog = createSubsystemLogger("gateway/channels/slack").child("inbound"); + +export function formatSlackInboundLogLine(params: { + workspaceId: string; + channelId: string; + channelType: string; + userId: string; + botUserId: string; + bodyChars: number; +}): string { + const from = `slack:${params.workspaceId}:channel:${params.channelId}:user:${params.userId}`; + return `Inbound app_mention ${from} -> bot:${params.botUserId} (${params.channelType}, ${params.bodyChars} chars)`; +} + type SlackAssistantMessageRecord = { bot_id?: unknown; user?: unknown; @@ -217,6 +238,21 @@ export function registerSlackMessageEvents(params: { return; } + // Emit a per-inbound receipt before dispatch so a silently-dropped mention + // (e.g. router consumes it without a tool call) still leaves journal evidence, + // matching the Telegram inbound log. Runs after the DM drop above, so duplicate + // DM app_mention events (already handled via message.im) produce no line. + slackInboundLog.info( + formatSlackInboundLogLine({ + workspaceId: ctx.teamId, + channelId: mention.channel, + channelType: channelType ?? "channel", + userId: asString(mention.user) ?? "unknown", + botUserId: ctx.botUserId, + bodyChars: asString(mention.text)?.length ?? 0, + }), + ); + await handleSlackMessage(mention as unknown as SlackMessageEvent, { source: "app_mention", wasMentioned: true, diff --git a/extensions/slack/src/monitor/events/system-event-test-harness.ts b/extensions/slack/src/monitor/events/system-event-test-harness.ts index bd949bf8d98a..42a4a78a035d 100644 --- a/extensions/slack/src/monitor/events/system-event-test-harness.ts +++ b/extensions/slack/src/monitor/events/system-event-test-harness.ts @@ -29,6 +29,7 @@ export function createSlackSystemEventTestHarness(overrides?: SlackSystemEventTe runtime: { error: () => {} }, botUserId: "U_BOT", botId: "B_BOT", + teamId: "T_TEST", dmEnabled: true, dmPolicy: overrides?.dmPolicy ?? "open", defaultRequireMention: true,