diff --git a/src/discord/monitor/provider.test.ts b/src/discord/monitor/provider.test.ts index 8fdab085f53..bdbb62f7eb2 100644 --- a/src/discord/monitor/provider.test.ts +++ b/src/discord/monitor/provider.test.ts @@ -26,6 +26,7 @@ function baseDiscordAccountConfig() { } const { + clientHandleDeployRequestMock, clientFetchUserMock, clientGetPluginMock, clientConstructorOptionsMock, @@ -49,6 +50,7 @@ const { } = vi.hoisted(() => { const createdBindingManagers: Array<{ stop: ReturnType }> = []; return { + clientHandleDeployRequestMock: vi.fn(async () => undefined), clientConstructorOptionsMock: vi.fn(), createDiscordAutoPresenceControllerMock: vi.fn(() => ({ enabled: false, @@ -131,6 +133,20 @@ function getFirstDiscordMessageHandlerParams() { vi.mock("@buape/carbon", () => { class ReadyListener {} + class RateLimitError extends Error { + status = 429; + discordCode?: number; + retryAfter: number; + scope: string | null; + bucket: string | null; + constructor(response: Response, body: { message: string; retry_after: number; code?: number }) { + super(body.message); + this.discordCode = body.code; + this.retryAfter = body.retry_after; + this.scope = response.headers.get("X-RateLimit-Scope"); + this.bucket = response.headers.get("X-RateLimit-Bucket"); + } + } class Client { listeners: unknown[]; rest: { put: ReturnType }; @@ -142,7 +158,7 @@ vi.mock("@buape/carbon", () => { clientConstructorOptionsMock(options); } async handleDeployRequest() { - return undefined; + return await clientHandleDeployRequestMock(); } async fetchUser(target: string) { return await clientFetchUserMock(target); @@ -151,7 +167,7 @@ vi.mock("@buape/carbon", () => { return clientGetPluginMock(name); } } - return { Client, ReadyListener }; + return { Client, RateLimitError, ReadyListener }; }); vi.mock("@buape/carbon/gateway", () => ({ @@ -373,6 +389,7 @@ describe("monitorDiscordProvider", () => { }; beforeEach(() => { + clientHandleDeployRequestMock.mockClear().mockResolvedValue(undefined); clientConstructorOptionsMock.mockClear(); createDiscordAutoPresenceControllerMock.mockClear().mockImplementation(() => ({ enabled: false, @@ -757,6 +774,40 @@ describe("monitorDiscordProvider", () => { expect(commandNames).toContain("cron_jobs"); }); + it("continues startup when Discord daily slash-command create quota is exhausted", async () => { + const { RateLimitError } = await import("@buape/carbon"); + const { monitorDiscordProvider } = await import("./provider.js"); + const runtime = baseRuntime(); + clientHandleDeployRequestMock.mockRejectedValueOnce( + new RateLimitError( + new Response(null, { + status: 429, + headers: { + "X-RateLimit-Scope": "shared", + "X-RateLimit-Bucket": "bucket-1", + }, + }), + { + message: "Max number of daily application command creates has been reached (200)", + retry_after: 193.632, + code: 30034, + }, + ), + ); + + await monitorDiscordProvider({ + config: baseConfig(), + runtime, + }); + + expect(clientHandleDeployRequestMock).toHaveBeenCalledTimes(1); + expect(clientFetchUserMock).toHaveBeenCalledWith("@me"); + expect(monitorLifecycleMock).toHaveBeenCalledTimes(1); + expect(runtime.log).toHaveBeenCalledWith( + expect.stringContaining("daily application command create limit reached"), + ); + }); + it("reports connected status on startup and shutdown", async () => { const { monitorDiscordProvider } = await import("./provider.js"); const setStatus = vi.fn(); diff --git a/src/discord/monitor/provider.ts b/src/discord/monitor/provider.ts index b1bfdde58c1..1d2256e5d12 100644 --- a/src/discord/monitor/provider.ts +++ b/src/discord/monitor/provider.ts @@ -1,6 +1,7 @@ import { inspect } from "node:util"; import { Client, + RateLimitError, ReadyListener, type BaseCommand, type BaseMessageInteractiveComponent, @@ -39,12 +40,12 @@ import { import { createConnectedChannelStatusPatch } from "../../gateway/channel-status-patches.js"; import { danger, logVerbose, shouldLogVerbose, warn } from "../../globals.js"; import { formatErrorMessage } from "../../infra/errors.js"; -import { createDiscordRetryRunner } from "../../infra/retry-policy.js"; import { createSubsystemLogger } from "../../logging/subsystem.js"; import { getPluginCommandSpecs } from "../../plugins/commands.js"; import { createNonExitingRuntime, type RuntimeEnv } from "../../runtime.js"; import { summarizeStringEntries } from "../../shared/string-sample.js"; import { resolveDiscordAccount } from "../accounts.js"; +import { getDiscordGatewayEmitter } from "../monitor.gateway.js"; import { fetchDiscordApplicationId } from "../probe.js"; import { normalizeDiscordToken } from "../token.js"; import { createDiscordVoiceCommand } from "../voice/command.js"; @@ -240,21 +241,133 @@ async function deployDiscordCommands(params: { client: Client; runtime: RuntimeEnv; enabled: boolean; + accountId?: string; + startupStartedAt?: number; }) { if (!params.enabled) { return; } - const runWithRetry = createDiscordRetryRunner({ verbose: shouldLogVerbose() }); + const startupStartedAt = params.startupStartedAt ?? Date.now(); + const accountId = params.accountId ?? "default"; + const maxAttempts = 3; + const maxRetryDelayMs = 15_000; + const sleep = (ms: number) => new Promise((resolve) => setTimeout(resolve, Math.max(0, ms))); + const isDailyCreateLimit = (err: unknown) => + err instanceof RateLimitError && + err.discordCode === 30034 && + /daily application command creates/i.test(err.message); + const restClient = params.client.rest as { + put: (path: string, data?: unknown, query?: unknown) => Promise; + options?: { queueRequests?: boolean }; + }; + const originalPut = restClient.put.bind(restClient); + const previousQueueRequests = restClient.options?.queueRequests; + restClient.put = async (path: string, data?: unknown, query?: unknown) => { + const startedAt = Date.now(); + const body = + data && typeof data === "object" && "body" in data + ? (data as { body?: unknown }).body + : undefined; + const commandCount = Array.isArray(body) ? body.length : undefined; + const bodyBytes = + body === undefined + ? undefined + : Buffer.byteLength(typeof body === "string" ? body : JSON.stringify(body), "utf8"); + params.runtime.log?.( + `discord startup [${accountId}] deploy-rest:put:start ${Math.max(0, Date.now() - startupStartedAt)}ms path=${path}${typeof commandCount === "number" ? ` commands=${commandCount}` : ""}${typeof bodyBytes === "number" ? ` bytes=${bodyBytes}` : ""}`, + ); + try { + const result = await originalPut(path, data, query); + params.runtime.log?.( + `discord startup [${accountId}] deploy-rest:put:done ${Math.max(0, Date.now() - startupStartedAt)}ms path=${path} requestMs=${Date.now() - startedAt}`, + ); + return result; + } catch (err) { + params.runtime.error?.( + `discord startup [${accountId}] deploy-rest:put:error ${Math.max(0, Date.now() - startupStartedAt)}ms path=${path} requestMs=${Date.now() - startedAt} error=${formatErrorMessage(err)}`, + ); + throw err; + } + }; try { - await runWithRetry(() => params.client.handleDeployRequest(), "command deploy"); + if (restClient.options) { + // Carbon's request queue retries 429s internally and can block startup for + // minutes before surfacing the real error. Disable it for deploy so quota + // errors like Discord 30034 fail fast and don't wedge the provider. + restClient.options.queueRequests = false; + } + for (let attempt = 1; attempt <= maxAttempts; attempt += 1) { + try { + await params.client.handleDeployRequest(); + return; + } catch (err) { + if (isDailyCreateLimit(err)) { + params.runtime.log?.( + warn( + `discord: native command deploy skipped for ${accountId}; daily application command create limit reached. Existing slash commands stay active until Discord resets the quota.`, + ), + ); + return; + } + if (!(err instanceof RateLimitError) || attempt >= maxAttempts) { + throw err; + } + const retryAfterMs = Math.max(0, Math.ceil(err.retryAfter * 1000)); + if (retryAfterMs > maxRetryDelayMs) { + params.runtime.log?.( + warn( + `discord: native command deploy skipped for ${accountId}; retry_after=${retryAfterMs}ms exceeds startup budget. Existing slash commands stay active.`, + ), + ); + return; + } + if (shouldLogVerbose()) { + params.runtime.log?.( + `discord startup [${accountId}] deploy-retry ${Math.max(0, Date.now() - startupStartedAt)}ms attempt=${attempt}/${maxAttempts - 1} retryAfterMs=${retryAfterMs} scope=${err.scope ?? "unknown"} code=${err.discordCode ?? "unknown"}`, + ); + } + await sleep(retryAfterMs); + } + } } catch (err) { const details = formatDiscordDeployErrorDetails(err); params.runtime.error?.( danger(`discord: failed to deploy native commands: ${formatErrorMessage(err)}${details}`), ); + } finally { + if (restClient.options) { + restClient.options.queueRequests = previousQueueRequests; + } + restClient.put = originalPut; } } +function formatDiscordStartupGatewayState(gateway?: GatewayPlugin): string { + if (!gateway) { + return "gateway=missing"; + } + const reconnectAttempts = (gateway as unknown as { reconnectAttempts?: unknown }) + .reconnectAttempts; + return `gatewayConnected=${gateway.isConnected ? "true" : "false"} reconnectAttempts=${typeof reconnectAttempts === "number" ? reconnectAttempts : "na"}`; +} + +function logDiscordStartupPhase(params: { + runtime: RuntimeEnv; + accountId: string; + phase: string; + startAt: number; + gateway?: GatewayPlugin; + details?: string; +}) { + const elapsedMs = Math.max(0, Date.now() - params.startAt); + const suffix = [params.details, formatDiscordStartupGatewayState(params.gateway)] + .filter((value): value is string => Boolean(value)) + .join(" "); + params.runtime.log?.( + `discord startup [${params.accountId}] ${params.phase} ${elapsedMs}ms${suffix ? ` ${suffix}` : ""}`, + ); +} + function formatDiscordDeployErrorDetails(err: unknown): string { if (!err || typeof err !== "object") { return ""; @@ -297,6 +410,7 @@ function isDiscordDisallowedIntentsError(err: unknown): boolean { } export async function monitorDiscordProvider(opts: MonitorDiscordOpts = {}) { + const startupStartedAt = Date.now(); const cfg = opts.config ?? loadConfig(); const account = resolveDiscordAccount({ cfg, @@ -414,10 +528,23 @@ export async function monitorDiscordProvider(opts: MonitorDiscordOpts = {}) { ); } + logDiscordStartupPhase({ + runtime, + accountId: account.accountId, + phase: "fetch-application-id:start", + startAt: startupStartedAt, + }); const applicationId = await fetchDiscordApplicationId(token, 4000, discordRestFetch); if (!applicationId) { throw new Error("Failed to resolve Discord application id"); } + logDiscordStartupPhase({ + runtime, + accountId: account.accountId, + phase: "fetch-application-id:done", + startAt: startupStartedAt, + details: `applicationId=${applicationId}`, + }); const maxDiscordCommands = 100; let skillCommands = @@ -490,6 +617,8 @@ export async function monitorDiscordProvider(opts: MonitorDiscordOpts = {}) { let releaseEarlyGatewayErrorGuard = () => {}; let deactivateMessageHandler: (() => void) | undefined; let autoPresenceController: ReturnType | null = null; + let earlyGatewayEmitter: ReturnType | undefined; + let onEarlyGatewayDebug: ((msg: unknown) => void) | undefined; try { const commands: BaseCommand[] = commandSpecs.map((spec) => createDiscordNativeCommand({ @@ -638,6 +767,13 @@ export async function monitorDiscordProvider(opts: MonitorDiscordOpts = {}) { releaseEarlyGatewayErrorGuard = earlyGatewayErrorGuard.release; const lifecycleGateway = client.getPlugin("gateway"); + earlyGatewayEmitter = getDiscordGatewayEmitter(lifecycleGateway); + onEarlyGatewayDebug = (msg: unknown) => { + runtime.log?.( + `discord startup [${account.accountId}] gateway-debug ${Math.max(0, Date.now() - startupStartedAt)}ms ${String(msg)}`, + ); + }; + earlyGatewayEmitter?.on("debug", onEarlyGatewayDebug); if (lifecycleGateway) { autoPresenceController = createDiscordAutoPresenceController({ accountId: account.accountId, @@ -648,7 +784,28 @@ export async function monitorDiscordProvider(opts: MonitorDiscordOpts = {}) { autoPresenceController.start(); } - await deployDiscordCommands({ client, runtime, enabled: nativeEnabled }); + logDiscordStartupPhase({ + runtime, + accountId: account.accountId, + phase: "deploy-commands:start", + startAt: startupStartedAt, + gateway: lifecycleGateway, + details: `native=${nativeEnabled ? "on" : "off"} commandCount=${commands.length}`, + }); + await deployDiscordCommands({ + client, + runtime, + enabled: nativeEnabled, + accountId: account.accountId, + startupStartedAt, + }); + logDiscordStartupPhase({ + runtime, + accountId: account.accountId, + phase: "deploy-commands:done", + startAt: startupStartedAt, + gateway: lifecycleGateway, + }); const logger = createSubsystemLogger("discord/monitor"); const guildHistories = new Map(); @@ -657,19 +814,56 @@ export async function monitorDiscordProvider(opts: MonitorDiscordOpts = {}) { let voiceManager: DiscordVoiceManager | null = null; if (nativeDisabledExplicit) { + logDiscordStartupPhase({ + runtime, + accountId: account.accountId, + phase: "clear-native-commands:start", + startAt: startupStartedAt, + gateway: lifecycleGateway, + }); await clearDiscordNativeCommands({ client, applicationId, runtime, }); + logDiscordStartupPhase({ + runtime, + accountId: account.accountId, + phase: "clear-native-commands:done", + startAt: startupStartedAt, + gateway: lifecycleGateway, + }); } + logDiscordStartupPhase({ + runtime, + accountId: account.accountId, + phase: "fetch-bot-identity:start", + startAt: startupStartedAt, + gateway: lifecycleGateway, + }); try { const botUser = await client.fetchUser("@me"); botUserId = botUser?.id; botUserName = botUser?.username?.trim() || botUser?.globalName?.trim() || undefined; + logDiscordStartupPhase({ + runtime, + accountId: account.accountId, + phase: "fetch-bot-identity:done", + startAt: startupStartedAt, + gateway: lifecycleGateway, + details: `botUserId=${botUserId ?? ""} botUserName=${botUserName ?? ""}`, + }); } catch (err) { runtime.error?.(danger(`discord: failed to fetch bot identity: ${String(err)}`)); + logDiscordStartupPhase({ + runtime, + accountId: account.accountId, + phase: "fetch-bot-identity:error", + startAt: startupStartedAt, + gateway: lifecycleGateway, + details: String(err), + }); } if (voiceEnabled) { @@ -766,6 +960,8 @@ export async function monitorDiscordProvider(opts: MonitorDiscordOpts = {}) { } lifecycleStarted = true; + earlyGatewayEmitter?.removeListener("debug", onEarlyGatewayDebug); + onEarlyGatewayDebug = undefined; await runDiscordGatewayLifecycle({ accountId: account.accountId, client, @@ -784,6 +980,9 @@ export async function monitorDiscordProvider(opts: MonitorDiscordOpts = {}) { deactivateMessageHandler?.(); autoPresenceController?.stop(); opts.setStatus?.({ connected: false }); + if (onEarlyGatewayDebug) { + earlyGatewayEmitter?.removeListener("debug", onEarlyGatewayDebug); + } releaseEarlyGatewayErrorGuard(); if (!lifecycleStarted) { threadBindings.stop();