perf(slack): dedupe webhook JSON.parse + LOG_LEVEL=debug perf timings

slack-mcp/server/router.ts

@@ -90,6 +90,7 @@ app.get("/temp-files/:id", async (c) => {
 // ============================================================================
 
 app.post("/slack/events/:connectionId", async (c) => {
+  const receivedAt = Date.now();
   const connectionId = c.req.param("connectionId");
   const traceId = HyperDXLogger.generateTraceId();
   const rawBody = await c.req.text();
@@ -149,7 +150,7 @@ app.post("/slack/events/:connectionId", async (c) => {
     );
   }
 
-  const { verified, payload } = await logger.measure(
+  const verified = await logger.measure(
     () =>
       verifySlackRequest(
         rawBody,
@@ -161,7 +162,7 @@ app.post("/slack/events/:connectionId", async (c) => {
     { connectionId, trace_id: traceId },
   );
 
-  if (!verified || !payload) {
+  if (!verified) {
     logger.error("Invalid signature", {
       connectionId,
       trace_id: traceId,
@@ -173,19 +174,22 @@ app.post("/slack/events/:connectionId", async (c) => {
 
   const botUserId =
     connectionConfig.botUserId ?? botUserIdCache.get(connectionId);
-  if (shouldIgnoreEvent(payload, botUserId)) {
+  if (shouldIgnoreEvent(parsedPayload, botUserId)) {
     return c.json({ ok: true });
   }
 
-  processConnectionEventAsync(payload, connectionConfig, traceId).catch(
-    (error) => {
-      logger.error("Event processing failed", {
-        connectionId,
-        trace_id: traceId,
-        error: String(error),
-      });
-    },
-  );
+  processConnectionEventAsync(
+    parsedPayload,
+    connectionConfig,
+    traceId,
+    receivedAt,
+  ).catch((error) => {
+    logger.error("Event processing failed", {
+      connectionId,
+      trace_id: traceId,
+      error: String(error),
+    });
+  });
 
   return c.json({ ok: true });
 });
@@ -258,6 +262,7 @@ async function processConnectionEventAsync(
   payload: SlackWebhookPayload,
   connectionConfig: SlackConnectionConfig,
   traceId: string,
+  receivedAt: number,
 ): Promise<void> {
   if (!payload.event) {
     return;
@@ -314,6 +319,8 @@ async function processConnectionEventAsync(
         },
         teamId: payload.team_id,
         apiAppId: payload.api_app_id,
+        traceId,
+        receivedAt,
       },
       teamConfig,
       connectionId,

slack-mcp/server/slack/handlers/eventHandler.ts

@@ -328,6 +328,37 @@ async function processAttachedFiles(
   };
 }
 
+/**
+ * Per-handler timing metadata threaded in from the webhook router.
+ *
+ * `receivedAt` is the wall-clock ms the webhook hit the pod; `traceId`
+ * matches the router-side log entries. Used only for perf-debug logs
+ * — see `logPerfStep`. Optional so unit tests don't have to fake it.
+ */
+interface HandlerMeta {
+  traceId?: string;
+  receivedAt?: number;
+}
+
+/**
+ * Emit a debug-level perf marker tagged with the cumulative pod time
+ * since the webhook was received. Only flows to HyperDX when LOG_LEVEL=debug
+ * (`logger.debug` is dropped below the configured min level — see logger.ts).
+ */
+function logPerfStep(
+  step: string,
+  meta: HandlerMeta,
+  extras: Record<string, unknown> = {},
+): void {
+  if (!meta.receivedAt) return;
+  logger.debug(`perf:${step}`, {
+    step,
+    trace_id: meta.traceId,
+    duration_ms: Date.now() - meta.receivedAt,
+    ...extras,
+  });
+}
+
 /**
  * Append transcribed audio + text-file contents to the user's original text
  * so they flow through the trigger payload's `text` field. The lazy import of
@@ -370,7 +401,8 @@ export async function handleSlackEvent(
   teamConfig: SlackTeamConfig,
   connectionId: string,
 ): Promise<void> {
-  const { type, payload } = context;
+  const { type, payload, traceId, receivedAt } = context;
+  const meta: HandlerMeta = { traceId, receivedAt };
 
   const triggerOnly = teamConfig.responseConfig?.triggerOnly ?? false;
 
@@ -383,22 +415,32 @@ export async function handleSlackEvent(
       // answered twice (once by the LLM, once by the trigger subscriber).
       if (triggerOnly) {
         await publishAppMention(connectionId, payload);
+        logPerfStep("trigger_published", meta, {
+          mode: "triggerOnly",
+          event_type: type,
+        });
       } else {
         await handleAppMention(
           payload as SlackAppMentionEvent,
           teamConfig,
           connectionId,
+          meta,
         );
       }
       break;
     case "message":
       if (triggerOnly) {
         await publishMessageReceived(connectionId, payload);
+        logPerfStep("trigger_published", meta, {
+          mode: "triggerOnly",
+          event_type: type,
+        });
       } else {
         await handleMessage(
           payload as SlackMessageEvent,
           teamConfig,
           connectionId,
+          meta,
         );
       }
       break;
@@ -429,6 +471,7 @@ async function handleAppMention(
   event: SlackAppMentionEvent,
   teamConfig: SlackTeamConfig,
   connectionId: string,
+  meta: HandlerMeta = {},
 ): Promise<void> {
   const { channel, text, ts, thread_ts, files } = event;
 
@@ -442,6 +485,11 @@ async function handleAppMention(
   const thinkingMsg = showThinking
     ? await sendThinkingMessage(channel, replyTo)
     : null;
+  logPerfStep("thinking_sent", meta, {
+    channel,
+    has_thinking: Boolean(thinkingMsg?.ts),
+    event_type: "app_mention",
+  });
 
   const { textFiles, transcriptions, audioWithoutWhisper } =
     await processAttachedFiles(files);
@@ -463,6 +511,10 @@ async function handleAppMention(
     { ...event, text: fullText },
     { thinking_message_ts: thinkingMsg?.ts },
   );
+  logPerfStep("trigger_published", meta, {
+    channel,
+    event_type: "app_mention",
+  });
 }
 
 /**
@@ -477,6 +529,7 @@ async function handleMessage(
   event: SlackMessageEvent,
   teamConfig: SlackTeamConfig,
   connectionId: string,
+  meta: HandlerMeta = {},
 ): Promise<void> {
   const { channel, text, thread_ts, channel_type } = event;
   const isDM = channel_type === "im" || channel?.startsWith("D");
@@ -504,11 +557,11 @@ async function handleMessage(
   // (see handleDirectMessage). Channel messages only reach this branch when
   // thread_ts is set AND the bot has participated in that thread.
   if (isDM && thread_ts) {
-    await handleThreadReply(event, thread_ts, teamConfig, connectionId);
+    await handleThreadReply(event, thread_ts, teamConfig, connectionId, meta);
   } else if (isDM) {
-    await handleDirectMessage(event, teamConfig, connectionId);
+    await handleDirectMessage(event, teamConfig, connectionId, meta);
   } else if (thread_ts) {
-    await handleThreadReply(event, thread_ts, teamConfig, connectionId);
+    await handleThreadReply(event, thread_ts, teamConfig, connectionId, meta);
   }
 }
 
@@ -523,6 +576,7 @@ async function handleDirectMessage(
   event: SlackMessageEvent,
   teamConfig: SlackTeamConfig,
   connectionId: string,
+  meta: HandlerMeta = {},
 ): Promise<void> {
   const { channel, text, ts, files } = event;
 
@@ -536,6 +590,11 @@ async function handleDirectMessage(
   const thinkingMsg = showThinking
     ? await sendThinkingMessage(channel, replyTo)
     : null;
+  logPerfStep("thinking_sent", meta, {
+    channel,
+    has_thinking: Boolean(thinkingMsg?.ts),
+    event_type: "direct_message",
+  });
 
   const { textFiles, transcriptions, audioWithoutWhisper } =
     await processAttachedFiles(files);
@@ -557,6 +616,10 @@ async function handleDirectMessage(
     { ...event, text: fullText },
     { thinking_message_ts: thinkingMsg?.ts },
   );
+  logPerfStep("trigger_published", meta, {
+    channel,
+    event_type: "direct_message",
+  });
 }
 
 /**
@@ -567,6 +630,7 @@ async function handleThreadReply(
   threadTs: string,
   teamConfig: SlackTeamConfig,
   connectionId: string,
+  meta: HandlerMeta = {},
 ): Promise<void> {
   const { channel, text, files } = event;
 
@@ -579,6 +643,11 @@ async function handleThreadReply(
   const thinkingMsg = showThinking
     ? await sendThinkingMessage(channel, threadTs)
     : null;
+  logPerfStep("thinking_sent", meta, {
+    channel,
+    has_thinking: Boolean(thinkingMsg?.ts),
+    event_type: "thread_reply",
+  });
 
   const { textFiles, transcriptions, audioWithoutWhisper } =
     await processAttachedFiles(files);
@@ -600,6 +669,10 @@ async function handleThreadReply(
     { ...event, text: fullText },
     { thinking_message_ts: thinkingMsg?.ts },
   );
+  logPerfStep("trigger_published", meta, {
+    channel,
+    event_type: "thread_reply",
+  });
 }
 
 // ============================================================================

slack-mcp/server/slack/handlers/types.ts

@@ -27,13 +27,20 @@ export const SLACK_EVENT_TYPES = {
 } as const;
 
 /**
- * Context for a Slack event
+ * Context for a Slack event.
+ *
+ * `traceId` and `receivedAt` are populated by the webhook router and used
+ * by handlers to emit perf-timing logs (`logger.debug("perf:…")`) so we
+ * can measure pod overhead from webhook receipt to "Pensando..." being
+ * sent and to the trigger being published.
  */
 export interface SlackEventContext {
   type: string;
   payload: SlackEvent & { original_text?: string };
   teamId?: string;
   apiAppId?: string;
+  traceId?: string;
+  receivedAt?: number;
 }
 
 /**

slack-mcp/server/webhook.ts

@@ -8,25 +8,30 @@
 import type { SlackWebhookPayload } from "./lib/types.ts";
 
 /**
- * Verify a Slack webhook request using the signing secret
+ * Verify a Slack webhook request using the signing secret.
+ *
+ * Returns only a boolean — the caller is responsible for parsing the body
+ * once (typically before calling this) and reusing that parsed payload.
+ * We deliberately do NOT JSON.parse the rawBody here: it was already
+ * parsed in the router, and parsing twice on every webhook is wasteful.
  */
 export async function verifySlackRequest(
   rawBody: string,
   signature: string | null,
   timestamp: string | null,
   signingSecret: string,
-): Promise<{ verified: boolean; payload: SlackWebhookPayload | null }> {
+): Promise<boolean> {
   if (!signature || !timestamp) {
     console.error("[Slack Webhook] Missing signature or timestamp");
-    return { verified: false, payload: null };
+    return false;
   }
 
   // Check timestamp to prevent replay attacks (5 minutes tolerance)
   const requestTimestamp = parseInt(timestamp, 10);
   const now = Math.floor(Date.now() / 1000);
   if (Math.abs(now - requestTimestamp) > 300) {
     console.error("[Slack Webhook] Request timestamp too old");
-    return { verified: false, payload: null };
+    return false;
   }
 
   // Construct the signature base string
@@ -60,7 +65,7 @@ export async function verifySlackRequest(
 
   // Constant-time comparison
   if (computedSignature.length !== signature.length) {
-    return { verified: false, payload: null };
+    return false;
   }
 
   let result = 0;
@@ -72,16 +77,9 @@ export async function verifySlackRequest(
 
   if (!verified) {
     console.error("[Slack Webhook] Signature verification failed");
-    return { verified: false, payload: null };
   }
 
-  try {
-    const payload = JSON.parse(rawBody) as SlackWebhookPayload;
-    return { verified: true, payload };
-  } catch {
-    console.error("[Slack Webhook] Failed to parse payload as JSON");
-    return { verified: false, payload: null };
-  }
+  return verified;
 }
 
 /**