Survive revoice's ffmpeg teardown and explain failed deletions

Switching tracks killed the process: revoice's #cleanUp() dereferences
this.fProc unconditionally, and its own ffmpeg error handler calls stop()
a second time after stop() has already nulled that field. Killing ffmpeg
is what triggers that error, so its handlers are detached first, the
instance's stop() is wrapped defensively (revoice calls it internally),
and an uncaughtException handler keeps the bot in the channel if the
dependency throws from another async callback.

Failed command-message deletions were logged at debug, i.e. invisible in
the default configuration; they now warn with Stoat's error type, and the
README says which permission the bot's role needs.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

README.md

@@ -178,8 +178,9 @@ cd /opt/stoat-mbot && docker compose up -d --build && docker compose logs -f
 Все параметры — в [.env.example](.env.example). Что стоит знать:
 
 - `DELETE_COMMAND_MESSAGES=true` (по умолчанию) — бот удаляет сообщение с командой, чтобы не
-  засорять канал. Нужно право `ManageMessages`; без него команда всё равно отработает,
-  а неудачное удаление уйдёт в лог на уровне `debug`.
+  засорять канал. Для этого роли бота нужно право **Manage Messages** в настройках сервера
+  (Settings → Roles → роль бота) или в правах самого канала. Без него команда всё равно
+  отработает, а в логе будет `could not delete command message` с причиной отказа.
 - `REQUIRE_DJ_ROLE=true` — управлять смогут только владелец сервера, обладатели `ManageServer`
   и роли из `DJ_ROLE_NAME`. По умолчанию `false`: играть может любой участник сервера.
 - `IDLE_TIMEOUT_SECONDS` — через сколько секунд простоя (или пустого канала) бот выходит из войса.

src/bot/index.ts

@@ -1,101 +1,105 @@
-import { Client, type Message } from "stoat.js";
-import { config } from "../config.js";
-import { logger } from "../logger.js";
-import type { MusicManager } from "../core/manager.js";
-import { UserFacingError } from "../types.js";
-import { findCommand, type CommandContext } from "./commands.js";
-import { BotStoatContext } from "./context.js";
-
-const log = logger.child({ mod: "bot" });
-
-export interface Bot {
-  client: Client;
-  context: BotStoatContext;
-  stop(): Promise<void>;
-}
-
-export async function startBot(manager: MusicManager): Promise<Bot> {
-  const client = new Client({ baseURL: config.STOAT_API_URL });
-  const context = new BotStoatContext(client);
-  manager.attachStoat(context);
-
-  client.on("ready", () => {
-    log.info({ user: client.user?.username }, "bot is ready");
-  });
-  client.on("error", (error) => {
-    log.error({ err: error }, "client error");
-  });
-  client.on("disconnected", () => log.warn("gateway disconnected"));
-
-  client.on("messageCreate", (message) => {
-    void handleMessage(manager, message).catch((err) => {
-      log.error({ err }, "unhandled command failure");
-    });
-  });
-
-  await client.loginBot(config.STOAT_BOT_TOKEN);
-
-  return {
-    client,
-    context,
-    async stop() {
-      await manager.destroyAll();
-    },
-  };
-}
-
-async function handleMessage(manager: MusicManager, message: Message): Promise<void> {
-  const content = message.content?.trim();
-  if (!content || !content.startsWith(config.COMMAND_PREFIX)) return;
-  if (!message.authorId || message.author?.bot) return;
-
-  const serverId = message.server?.id;
-  const reply = async (text: string) => {
-    await message.channel?.sendMessage(text);
-  };
-
-  if (!serverId) {
-    await reply("Команды работают только внутри сервера.");
-    return;
-  }
-
-  const withoutPrefix = content.slice(config.COMMAND_PREFIX.length).trim();
-  const [rawName, ...args] = withoutPrefix.split(/\s+/);
-  if (!rawName) return;
-
-  const command = findCommand(rawName);
-  if (!command) return;
-
-  if (config.DELETE_COMMAND_MESSAGES) {
-    // Fire-and-forget: a missing ManageMessages permission must not block playback.
-    void message.delete().catch((err) => {
-      log.debug({ err, command: command.name }, "could not delete command message");
-    });
-  }
-
-  const ctx: CommandContext = {
-    manager,
-    serverId,
-    channelId: message.channelId,
-    actor: {
-      id: message.authorId,
-      username: message.member?.nickname || message.author?.username || "user",
-    },
-    args,
-    rest: withoutPrefix.slice(rawName.length).trim(),
-    reply,
-  };
-
-  log.debug({ command: command.name, user: ctx.actor.id, server: serverId }, "command");
-
-  try {
-    await command.run(ctx);
-  } catch (err) {
-    if (err instanceof UserFacingError) {
-      await reply(`⚠️ ${err.message}`);
-      return;
-    }
-    log.error({ err, command: command.name }, "command failed");
-    await reply("⚠️ Внутренняя ошибка, подробности в логах бота.");
-  }
-}
+import { Client, type Message } from "stoat.js";
+import { config } from "../config.js";
+import { logger } from "../logger.js";
+import type { MusicManager } from "../core/manager.js";
+import { UserFacingError } from "../types.js";
+import { findCommand, type CommandContext } from "./commands.js";
+import { BotStoatContext } from "./context.js";
+
+const log = logger.child({ mod: "bot" });
+
+export interface Bot {
+  client: Client;
+  context: BotStoatContext;
+  stop(): Promise<void>;
+}
+
+export async function startBot(manager: MusicManager): Promise<Bot> {
+  const client = new Client({ baseURL: config.STOAT_API_URL });
+  const context = new BotStoatContext(client);
+  manager.attachStoat(context);
+
+  client.on("ready", () => {
+    log.info({ user: client.user?.username }, "bot is ready");
+  });
+  client.on("error", (error) => {
+    log.error({ err: error }, "client error");
+  });
+  client.on("disconnected", () => log.warn("gateway disconnected"));
+
+  client.on("messageCreate", (message) => {
+    void handleMessage(manager, message).catch((err) => {
+      log.error({ err }, "unhandled command failure");
+    });
+  });
+
+  await client.loginBot(config.STOAT_BOT_TOKEN);
+
+  return {
+    client,
+    context,
+    async stop() {
+      await manager.destroyAll();
+    },
+  };
+}
+
+async function handleMessage(manager: MusicManager, message: Message): Promise<void> {
+  const content = message.content?.trim();
+  if (!content || !content.startsWith(config.COMMAND_PREFIX)) return;
+  if (!message.authorId || message.author?.bot) return;
+
+  const serverId = message.server?.id;
+  const reply = async (text: string) => {
+    await message.channel?.sendMessage(text);
+  };
+
+  if (!serverId) {
+    await reply("Команды работают только внутри сервера.");
+    return;
+  }
+
+  const withoutPrefix = content.slice(config.COMMAND_PREFIX.length).trim();
+  const [rawName, ...args] = withoutPrefix.split(/\s+/);
+  if (!rawName) return;
+
+  const command = findCommand(rawName);
+  if (!command) return;
+
+  if (config.DELETE_COMMAND_MESSAGES) {
+    // Fire-and-forget: a missing ManageMessages permission must not block playback.
+    void message.delete().catch((err: unknown) => {
+      const type = (err as { response?: { data?: { type?: string } } })?.response?.data?.type;
+      log.warn(
+        { type: type ?? String(err), command: command.name },
+        "could not delete command message (bot needs ManageMessages)",
+      );
+    });
+  }
+
+  const ctx: CommandContext = {
+    manager,
+    serverId,
+    channelId: message.channelId,
+    actor: {
+      id: message.authorId,
+      username: message.member?.nickname || message.author?.username || "user",
+    },
+    args,
+    rest: withoutPrefix.slice(rawName.length).trim(),
+    reply,
+  };
+
+  log.debug({ command: command.name, user: ctx.actor.id, server: serverId }, "command");
+
+  try {
+    await command.run(ctx);
+  } catch (err) {
+    if (err instanceof UserFacingError) {
+      await reply(`⚠️ ${err.message}`);
+      return;
+    }
+    log.error({ err, command: command.name }, "command failed");
+    await reply("⚠️ Внутренняя ошибка, подробности в логах бота.");
+  }
+}

src/core/player.ts

@@ -185,6 +185,18 @@ export class GuildPlayer extends EventEmitter<GuildPlayerEvents> {
     connection.on("userJoin", () => this.clearIdleTimer());
 
     const media = new MediaPlayer(true);
+    // revoice's #cleanUp() dereferences this.fProc unconditionally, so a second
+    // stop() (which its own ffmpeg error handler triggers) throws and would take
+    // the whole process down. Everything it calls goes through this instance
+    // method, so guarding it here covers its internal paths too.
+    const stop = media.stop.bind(media);
+    media.stop = (init?: boolean) => {
+      try {
+        stop(init);
+      } catch (err) {
+        this.log.debug({ err }, "revoice cleanup threw, ignoring");
+      }
+    };
     media.on("startplay", () => {
       this.setStatus(media.paused ? "paused" : "playing");
       this.startTicker();
@@ -298,7 +310,14 @@ export class GuildPlayer extends EventEmitter<GuildPlayerEvents> {
     if (this.media) {
       this.expectingStop = true;
       try {
-        this.media.fProc?.kill("SIGKILL");
+        // Detach revoice's own handlers first: killing ffmpeg makes it emit
+        // "error", and its handler would call stop() again on a half-reset player.
+        const proc = this.media.fProc;
+        if (proc) {
+          proc.removeAllListeners("error");
+          proc.removeAllListeners("end");
+          proc.kill("SIGKILL");
+        }
       } catch {
         // ffmpeg may already be gone.
       }

src/core/revoice.ts

@@ -12,7 +12,7 @@ export interface MediaPlayerLike {
   codecData?: { duration?: string } | null;
   paused: boolean;
   playing: boolean;
-  fProc?: { kill(signal?: string): void } | null;
+  fProc?: { kill(signal?: string): void; removeAllListeners(event?: string): void } | null;
   originStream?: { destroy(): void } | null;
   playStream(input: Readable | string, inputOptions?: string[]): Promise<void>;
   pause(): void;

src/index.ts

@@ -1,55 +1,59 @@
-import { startApiServer } from "./api/server.js";
-import { startBot } from "./bot/index.js";
-import { config } from "./config.js";
-import { MusicManager } from "./core/manager.js";
-import { logger } from "./logger.js";
-import { checkCookies, checkYtDlp } from "./sources/index.js";
-
-async function main(): Promise<void> {
-  const ytdlpVersion = await checkYtDlp();
-  if (ytdlpVersion) {
-    logger.info({ version: ytdlpVersion }, "yt-dlp detected");
-  } else {
-    logger.warn(
-      { path: config.YTDLP_PATH },
-      "yt-dlp not found — YouTube/SoundCloud playback will fail; only direct links and local files will work",
-    );
-  }
-
-  const cookies = await checkCookies();
-  if (cookies === "ok") {
-    logger.info({ path: config.YTDLP_COOKIES }, "using YouTube cookies");
-  } else if (cookies === "read-only") {
-    logger.warn(
-      { path: config.YTDLP_COOKIES },
-      "cookie file is not writable — yt-dlp cannot persist rotated cookies and the session will expire early",
-    );
-  } else if (cookies === "missing") {
-    logger.warn({ path: config.YTDLP_COOKIES }, "cookie file from YTDLP_COOKIES does not exist");
-  }
-
-  const manager = new MusicManager();
-  const bot = await startBot(manager);
-  const app = await startApiServer({ manager, context: bot.context });
-
-  const shutdown = async (signal: string): Promise<void> => {
-    logger.info({ signal }, "shutting down");
-    try {
-      await app.close();
-      await bot.stop();
-    } catch (err) {
-      logger.error({ err }, "shutdown failed");
-    } finally {
-      process.exit(0);
-    }
-  };
-
-  process.on("SIGINT", () => void shutdown("SIGINT"));
-  process.on("SIGTERM", () => void shutdown("SIGTERM"));
-  process.on("unhandledRejection", (err) => logger.error({ err }, "unhandled rejection"));
-}
-
-main().catch((err) => {
-  logger.fatal({ err }, "failed to start");
-  process.exit(1);
-});
+import { startApiServer } from "./api/server.js";
+import { startBot } from "./bot/index.js";
+import { config } from "./config.js";
+import { MusicManager } from "./core/manager.js";
+import { logger } from "./logger.js";
+import { checkCookies, checkYtDlp } from "./sources/index.js";
+
+async function main(): Promise<void> {
+  const ytdlpVersion = await checkYtDlp();
+  if (ytdlpVersion) {
+    logger.info({ version: ytdlpVersion }, "yt-dlp detected");
+  } else {
+    logger.warn(
+      { path: config.YTDLP_PATH },
+      "yt-dlp not found — YouTube/SoundCloud playback will fail; only direct links and local files will work",
+    );
+  }
+
+  const cookies = await checkCookies();
+  if (cookies === "ok") {
+    logger.info({ path: config.YTDLP_COOKIES }, "using YouTube cookies");
+  } else if (cookies === "read-only") {
+    logger.warn(
+      { path: config.YTDLP_COOKIES },
+      "cookie file is not writable — yt-dlp cannot persist rotated cookies and the session will expire early",
+    );
+  } else if (cookies === "missing") {
+    logger.warn({ path: config.YTDLP_COOKIES }, "cookie file from YTDLP_COOKIES does not exist");
+  }
+
+  const manager = new MusicManager();
+  const bot = await startBot(manager);
+  const app = await startApiServer({ manager, context: bot.context });
+
+  const shutdown = async (signal: string): Promise<void> => {
+    logger.info({ signal }, "shutting down");
+    try {
+      await app.close();
+      await bot.stop();
+    } catch (err) {
+      logger.error({ err }, "shutdown failed");
+    } finally {
+      process.exit(0);
+    }
+  };
+
+  process.on("SIGINT", () => void shutdown("SIGINT"));
+  process.on("SIGTERM", () => void shutdown("SIGTERM"));
+  process.on("unhandledRejection", (err) => logger.error({ err }, "unhandled rejection"));
+  // revoice.js throws from async callbacks we cannot wrap (its ffmpeg teardown
+  // in particular). Dying there would drop the bot out of the voice channel
+  // mid-track, so we log loudly and keep serving instead.
+  process.on("uncaughtException", (err) => logger.error({ err }, "uncaught exception, continuing"));
+}
+
+main().catch((err) => {
+  logger.fatal({ err }, "failed to start");
+  process.exit(1);
+});