fix(bot): do not report a busy bot as a Telegram outage

PRODUCT.md

@@ -109,6 +109,7 @@ No public inbound ports are required for normal usage.
 - Ignore messages from non-authorized users
 - Ignore updates queued while the bot was offline or unreachable, so they are not executed on startup
 - Mid-session, messages older than 60 seconds after an outage are still not executed; the chat gets one notice that messages were skipped while Telegram was unreachable
+- A message delayed by a long-running update handler (for example a session pick while the reply keeps streaming) is not treated as an outage: after 5 seconds without chat output the bot says it is busy, messages delayed up to 15 seconds are executed after the handler, and older ones are dropped with a separate "the bot was busy" notice
 - If Telegram is unreachable at startup (network error, 5xx, 429), keep retrying with a growing delay capped at 60 seconds until it answers, then start polling; a rejected or invalid token (401/404) or any other fatal startup error logs the cause and exits the process with code 1 so a supervisor can restart it
 
 ### Configuration
@@ -244,7 +245,7 @@ Agent picker behavior:
 - [x] Native Telegram rich message formatting for assistant replies (Bot API 10.1)
 - [x] Incoming Telegram rich formatted messages (Bot API 10.1): converted to Markdown, accepted anywhere text is accepted, with photos attached and unsupported message types answered explicitly
 - [x] Startup either reaches Telegram polling or the process exits: transient Telegram failures are retried in-process; a bad token or other fatal startup error exits with code 1
-- [x] After a Telegram outage the bot answers again without restart; an undelivered assistant reply is not resent, and skipped stale messages are reported once
+- [x] After a Telegram outage the bot answers again without restart; an undelivered assistant reply is not resent, and skipped stale messages are reported once per cause
 
 ## Current Task List
 

src/app/services/telegram-outage-notice-service.ts

@@ -1,17 +1,22 @@
 const CHAT_INTERVAL_MS = 1000;
 const BURST_GAP_MS = 60_000;
 
-export type TelegramOutageNoticeKind = "undelivered" | "skipped";
+export type TelegramOutageNoticeKind = "undelivered" | "skipped" | "busy";
+
+export type SkippedMessagesReason = "outage" | "busy";
 
 export interface TelegramOutageNoticesDue {
   undelivered: boolean;
   skipped: boolean;
+  busy: boolean;
 }
 
 export class TelegramOutageNoticeService {
   private undeliveredPending = false;
   private skippedPending = false;
+  private busyPending = false;
   private burstActive = false;
+  private burstReasons = new Set<SkippedMessagesReason>();
   private lastStaleAt = 0;
   private lastChatSendAt = 0;
   private flushInFlight = false;
@@ -20,25 +25,48 @@ export class TelegramOutageNoticeService {
     this.undeliveredPending = true;
   }
 
-  markMessagesSkipped(): void {
+  markMessagesSkipped(reason: SkippedMessagesReason = "outage"): void {
     const now = Date.now();
     if (this.burstActive && now - this.lastStaleAt <= BURST_GAP_MS) {
       this.lastStaleAt = now;
+      if (!this.burstReasons.has(reason)) {
+        this.burstReasons.add(reason);
+        this.markSkippedPending(reason);
+      }
       return;
     }
+
     this.burstActive = true;
-    this.skippedPending = true;
+    this.burstReasons = new Set([reason]);
+    this.markSkippedPending(reason);
     this.lastStaleAt = now;
   }
 
+  private markSkippedPending(reason: SkippedMessagesReason): void {
+    if (reason === "busy") {
+      this.busyPending = true;
+    } else {
+      this.skippedPending = true;
+    }
+  }
+
   closeBurst(): void {
     this.burstActive = false;
+    this.burstReasons = new Set();
   }
 
   noteChatSendSucceeded(): void {
     this.lastChatSendAt = Date.now();
   }
 
+  /** Milliseconds since the last chat delivery, or null when nothing was sent yet. */
+  msSinceLastChatSend(): number | null {
+    if (this.lastChatSendAt === 0) {
+      return null;
+    }
+    return Date.now() - this.lastChatSendAt;
+  }
+
   msUntilAllowedSend(): number {
     if (this.lastChatSendAt === 0) {
       return 0;
@@ -50,13 +78,14 @@ export class TelegramOutageNoticeService {
     if (this.flushInFlight) {
       return null;
     }
-    if (!this.undeliveredPending && !this.skippedPending) {
+    if (!this.undeliveredPending && !this.skippedPending && !this.busyPending) {
       return null;
     }
     this.flushInFlight = true;
     return {
       undelivered: this.undeliveredPending,
       skipped: this.skippedPending,
+      busy: this.busyPending,
     };
   }
 
@@ -66,6 +95,8 @@ export class TelegramOutageNoticeService {
     }
     if (kind === "undelivered") {
       this.undeliveredPending = false;
+    } else if (kind === "busy") {
+      this.busyPending = false;
     } else {
       this.skippedPending = false;
     }
@@ -78,7 +109,9 @@ export class TelegramOutageNoticeService {
   __resetForTests(): void {
     this.undeliveredPending = false;
     this.skippedPending = false;
+    this.busyPending = false;
     this.burstActive = false;
+    this.burstReasons = new Set();
     this.lastStaleAt = 0;
     this.lastChatSendAt = 0;
     this.flushInFlight = false;

src/app/services/update-busy-window-service.ts

@@ -0,0 +1,51 @@
+export const STALE_THRESHOLD_MS = 60_000;
+export const BUSY_CANCEL_MS = 15_000;
+// The stale check floors the age to whole seconds, so a handler just under the cancel
+// window can still leave a message looking one second older; record with that margin.
+const RECORD_THRESHOLD_MS = BUSY_CANCEL_MS - 1000;
+const WINDOW_TTL_MS = 60 * 60_000;
+
+export interface UpdateBusyWindow {
+  startedAt: number;
+  endedAt: number;
+}
+
+/**
+ * Remembers update handlers that ran longer than the busy-cancel window. A message the
+ * user sent while the bot was busy was delayed by the bot itself, not by a Telegram outage,
+ * and the stale-update middleware uses these windows to tell the two apart.
+ *
+ * The window starts at the beginning of the handler's first second: Telegram dates messages
+ * in whole seconds, so a message sent in that same second must still be covered.
+ *
+ * Only handlers that individually outlive the threshold are recorded: a backlog of shorter
+ * handlers can still delay a message past it without a window.
+ */
+export class UpdateBusyWindowService {
+  private windows: UpdateBusyWindow[] = [];
+
+  record(startedAt: number, endedAt: number): void {
+    if (endedAt - startedAt < RECORD_THRESHOLD_MS) {
+      return;
+    }
+
+    this.windows.push({ startedAt: Math.floor(startedAt / 1000) * 1000, endedAt });
+    this.windows = this.windows.filter((window) => endedAt - window.endedAt <= WINDOW_TTL_MS);
+  }
+
+  covers(timestampMs: number): boolean {
+    const now = Date.now();
+    return this.windows.some(
+      (window) =>
+        now - window.endedAt <= WINDOW_TTL_MS &&
+        timestampMs >= window.startedAt &&
+        timestampMs <= window.endedAt,
+    );
+  }
+
+  __resetForTests(): void {
+    this.windows = [];
+  }
+}
+
+export const updateBusyWindowService = new UpdateBusyWindowService();

src/bot/index.ts

@@ -23,10 +23,8 @@ import { normalizeRichMessage } from "./handlers/rich-message-handler.js";
 import { authMiddleware } from "./middleware/auth.js";
 import { interactionGuardMiddleware } from "./middleware/interaction-guard.js";
 import { staleUpdateMiddleware } from "./middleware/stale-update.js";
-import {
-  ensureCommandsInitialized,
-  registerCommandRouter,
-} from "./routers/command-router.js";
+import { updateBusyWindowMiddleware } from "./middleware/update-busy-window.js";
+import { ensureCommandsInitialized, registerCommandRouter } from "./routers/command-router.js";
 import { registerMessageRouter } from "./routers/message-router.js";
 import { createAttachPresentation } from "./services/attach-presentation.js";
 import { createTelegramBotOptions } from "./telegram-client-options.js";
@@ -44,6 +42,8 @@ const STARTUP_MANAGED_TELEGRAM_METHODS = new Set(["deleteWebhook", "getMe", "get
 const CHAT_DELIVERY_TELEGRAM_METHODS = new Set([
   "sendMessage",
   "sendRichMessage",
+  "sendMessageDraft",
+  "sendRichMessageDraft",
   "editMessageText",
   "sendDocument",
   "sendAudio",
@@ -211,7 +211,10 @@ export function createBot(
   });
 
   bot.use(authMiddleware);
+  // The busy timer must wrap only handlers that actually run: the stale check drops
+  // updates before it.
   bot.use(staleUpdateMiddleware);
+  bot.use(updateBusyWindowMiddleware);
   bot.on("message:rich_message", normalizeRichMessage);
   bot.use((ctx, next) => ensureCommandsInitialized(ctx, next, localCommandRegistry));
   const guardDeps = { ...container, localCommandRegistry };

src/bot/middleware/stale-update.ts

@@ -1,13 +1,23 @@
 import type { Context, NextFunction } from "grammy";
 import { telegramOutageNoticeService } from "../../app/services/telegram-outage-notice-service.js";
+import {
+  BUSY_CANCEL_MS,
+  STALE_THRESHOLD_MS,
+  updateBusyWindowService,
+} from "../../app/services/update-busy-window-service.js";
 import { flushTelegramOutageNotices } from "../telegram-outage-notices.js";
 import { logger } from "../../utils/logger.js";
 
 // Telegram keeps undelivered updates for up to 24 hours, so a message can reach
 // the bot long after it was sent - after a restart, or after long polling was
 // interrupted by a network outage. Acting on such a message is unwanted: it
 // would start tasks the user no longer expects to run.
-const MAX_MESSAGE_AGE_SECONDS = 60;
+const MAX_MESSAGE_AGE_SECONDS = STALE_THRESHOLD_MS / 1000;
+// A message the bot delayed itself is executed after the handler, but only within this
+// window: the chat has had feedback by then (the 5-second busy notice or streaming
+// progress), and older commands are dropped with an honest notice instead of being
+// executed late.
+const BUSY_CANCEL_SECONDS = BUSY_CANCEL_MS / 1000;
 
 export async function staleUpdateMiddleware(ctx: Context, next: NextFunction): Promise<void> {
   // Only `ctx.message` carries the time the user acted. `ctx.msg` also resolves
@@ -23,7 +33,7 @@ export async function staleUpdateMiddleware(ctx: Context, next: NextFunction): P
   const chatId = ctx.chat?.id;
   const canNotify = typeof chatId === "number" && ctx.api !== undefined;
 
-  if (ageSeconds <= MAX_MESSAGE_AGE_SECONDS) {
+  if (ageSeconds <= BUSY_CANCEL_SECONDS) {
     telegramOutageNoticeService.closeBurst();
     if (canNotify) {
       await flushTelegramOutageNotices({ api: ctx.api, chatId });
@@ -32,11 +42,36 @@ export async function staleUpdateMiddleware(ctx: Context, next: NextFunction): P
     return;
   }
 
-  telegramOutageNoticeService.markMessagesSkipped();
-  logger.warn(
-    `[StaleUpdate] Ignored stale message: ageSeconds=${ageSeconds}, updateId=${ctx.update.update_id}, messageId=${message.message_id}`,
-  );
+  // The bot was busy when this message arrived: Telegram delivered it, the update loop
+  // was held by a long handler. That is not an outage, so it gets its own notice.
+  const delayedByBusyBot = updateBusyWindowService.covers(message.date * 1000);
+  if (delayedByBusyBot) {
+    telegramOutageNoticeService.markMessagesSkipped("busy");
+    logger.warn(
+      `[StaleUpdate] Ignored a message delayed by a long handler: ageSeconds=${ageSeconds}, updateId=${ctx.update.update_id}, messageId=${message.message_id}`,
+    );
+    if (canNotify) {
+      await flushTelegramOutageNotices({ api: ctx.api, chatId });
+    }
+    return;
+  }
+
+  if (ageSeconds > MAX_MESSAGE_AGE_SECONDS) {
+    telegramOutageNoticeService.markMessagesSkipped("outage");
+    logger.warn(
+      `[StaleUpdate] Ignored stale message: ageSeconds=${ageSeconds}, updateId=${ctx.update.update_id}, messageId=${message.message_id}`,
+    );
+    if (canNotify) {
+      await flushTelegramOutageNotices({ api: ctx.api, chatId });
+    }
+    return;
+  }
+
+  // Delayed without a recorded busy window: the transport was slow, or the delay came from
+  // a backlog of shorter handlers. Execute it.
+  telegramOutageNoticeService.closeBurst();
   if (canNotify) {
     await flushTelegramOutageNotices({ api: ctx.api, chatId });
   }
+  await next();
 }

src/bot/middleware/update-busy-window.ts

@@ -0,0 +1,51 @@
+import type { Context, NextFunction } from "grammy";
+import { telegramOutageNoticeService } from "../../app/services/telegram-outage-notice-service.js";
+import { updateBusyWindowService } from "../../app/services/update-busy-window-service.js";
+import { t } from "../../i18n/index.js";
+import { logger } from "../../utils/logger.js";
+
+const BUSY_NOTICE_DELAY_MS = 5000;
+
+/**
+ * Records a handler that outlived the busy-cancel window, and tells the chat when a handler
+ * blocks silently for too long: a message delayed by the bot itself is not an outage, and
+ * the user must not be left without feedback long enough to resend it.
+ */
+export async function updateBusyWindowMiddleware(ctx: Context, next: NextFunction): Promise<void> {
+  const startedAt = Date.now();
+  const chatId = ctx.chat?.id;
+  let timer: ReturnType<typeof setTimeout> | null = null;
+  let completed = false;
+
+  if (typeof chatId === "number" && ctx.api) {
+    const api = ctx.api;
+    const checkSilence = (): void => {
+      timer = null;
+      if (completed) {
+        return;
+      }
+
+      const sinceLastSend = telegramOutageNoticeService.msSinceLastChatSend();
+      if (sinceLastSend !== null && sinceLastSend < BUSY_NOTICE_DELAY_MS) {
+        // The chat already shows progress; look again once the gap is long enough.
+        timer = setTimeout(checkSilence, BUSY_NOTICE_DELAY_MS - sinceLastSend);
+        return;
+      }
+
+      void api.sendMessage(chatId, t("bot.busy_operation")).catch((error) => {
+        logger.warn("[UpdateBusyWindow] Failed to send the busy notice:", error);
+      });
+    };
+    timer = setTimeout(checkSilence, BUSY_NOTICE_DELAY_MS);
+  }
+
+  try {
+    await next();
+  } finally {
+    completed = true;
+    if (timer !== null) {
+      clearTimeout(timer);
+    }
+    updateBusyWindowService.record(startedAt, Date.now());
+  }
+}

src/bot/telegram-outage-notices.ts

@@ -14,11 +14,14 @@ export interface FlushTelegramOutageNoticesOptions {
 
 const unretriedSend = new AsyncLocalStorage<true>();
 
-const NOTICE_TEXT: Record<TelegramOutageNoticeKind, "bot.assistant_reply_undelivered" | "bot.stale_messages_skipped"> =
-  {
-    undelivered: "bot.assistant_reply_undelivered",
-    skipped: "bot.stale_messages_skipped",
-  };
+const NOTICE_TEXT: Record<
+  TelegramOutageNoticeKind,
+  "bot.assistant_reply_undelivered" | "bot.stale_messages_skipped" | "bot.busy_messages_skipped"
+> = {
+  undelivered: "bot.assistant_reply_undelivered",
+  skipped: "bot.stale_messages_skipped",
+  busy: "bot.busy_messages_skipped",
+};
 
 export function isUnretriedTelegramSend(): boolean {
   return unretriedSend.getStore() === true;
@@ -73,6 +76,9 @@ export async function flushTelegramOutageNotices(
     if (due.skipped) {
       await sendNotice(options, "skipped");
     }
+    if (due.busy) {
+      await sendNotice(options, "busy");
+    }
   } finally {
     telegramOutageNoticeService.finishFlush();
   }

src/i18n/ar.ts

@@ -101,6 +101,10 @@ export const ar: I18nDictionary = {
   "bot.session_error": "🔴 أعاد OpenCode الخطأ التالي: {message}",
   "bot.assistant_reply_undelivered":
     "⚠️ The last assistant reply could not be delivered. Send your message again if you still need it.",
+  "bot.busy_operation":
+    "⏳ البوت مشغول بالعملية الحالية. انتظر حتى تنتهي — قد يتم تخطي الرسائل المرسلة الآن.",
+  "bot.busy_messages_skipped":
+    "⚠️ كان البوت مشغولاً وتخطى بعض الرسائل. يرجى إرسالها مرة أخرى.",
   "bot.stale_messages_skipped":
     "⚠️ Some messages were skipped while Telegram was unreachable. Please send them again.",
   "bot.session_retry":

src/i18n/de.ts

@@ -101,6 +101,10 @@ export const de: I18nDictionary = {
   "bot.session_error": "🔴 OpenCode meldete einen Fehler: {message}",
   "bot.assistant_reply_undelivered":
     "⚠️ The last assistant reply could not be delivered. Send your message again if you still need it.",
+  "bot.busy_operation":
+    "⏳ Der Bot ist mit der aktuellen Operation beschäftigt. Warten Sie, bis sie abgeschlossen ist — jetzt gesendete Nachrichten können übersprungen werden.",
+  "bot.busy_messages_skipped":
+    "⚠️ Der Bot war beschäftigt und hat einige Nachrichten übersprungen. Bitte senden Sie sie erneut.",
   "bot.stale_messages_skipped":
     "⚠️ Some messages were skipped while Telegram was unreachable. Please send them again.",
   "bot.session_retry":