Acknowledge Discord interactions before database work

docs/guides/discord.md

@@ -139,6 +139,16 @@ visible.
 - **Discord rejects the interaction endpoint:** verify HTTPS routing, the
   application's Public Key, and that the reverse proxy preserves signed
   requests. Discord must reach the endpoint without an interactive login.
+- **Buttons time out without a private loading message:** inspect the controller
+  logs while clicking once (`docker compose logs --since=5m electric-cherry`).
+  A `[discord] Deferring interaction` entry means the signed request reached the
+  handler and it prepared a private acknowledgement before database work. A
+  rejection entry identifies signature, body, or application-ID validation
+  failures. An application-ID mismatch also returns a private explanation;
+  `EC_DISCORD_APPLICATION_ID` must identify the same application as the Public
+  Key and bot token. If no entry appears, check the proxy and saved Interactions
+  Endpoint URL. A verified endpoint and working boards alone do not confirm
+  that button clicks are reaching the running controller.
 - **Commands are missing:** save the correct Discord server ID, install the bot
   with `applications.commands`, then select **Register commands**. Register again
   after upgrading to a release that changes the command schema.

src/routes/api/discord/interactions/+server.ts

@@ -10,6 +10,7 @@ import {
     validInteractionEnvelope,
     verifiedDiscordBody
 } from '$lib/server/discord/webhook.js';
+import { discordCredentials } from '$lib/server/discord/config.js';
 
 const seen = new Map<string, number>();
 const actors = new Map<string, number>();
@@ -23,11 +24,23 @@ export async function POST({ request }: { request: Request }) {
     try {
         const body = await verifiedDiscordBody(request);
         if (body.type === 1) return json({ type: 1 });
-        if (![2, 3].includes(body.type as number) || !validInteractionEnvelope(body))
+        if (![2, 3].includes(body.type as number) || !validInteractionEnvelope(body)) {
+            if (
+                [2, 3].includes(body.type as number) &&
+                body.application_id !== discordCredentials().applicationId
+            ) {
+                console.error(
+                    '[discord] Interaction application ID does not match EC_DISCORD_APPLICATION_ID.'
+                );
+                return json(
+                    privateReply(
+                        'Electric Cherry’s Discord application ID is misconfigured. Ask an administrator to check EC_DISCORD_APPLICATION_ID.'
+                    )
+                );
+            }
+            console.warn('[discord] Rejected an invalid interaction envelope.');
             return json({ error: 'Invalid Discord interaction.' }, { status: 400 });
-        const settings = getDiscordSettings();
-        if (!settings.enabled || body.guild_id !== settings.guildId)
-            return json(privateReply('Electric Cherry is not enabled for this Discord server.'));
+        }
         const now = Date.now();
         for (const [key, at] of seen) if (now - at > 5 * 60_000) seen.delete(key);
         for (const [key, at] of actors) if (now - at > 60_000) actors.delete(key);
@@ -36,15 +49,27 @@ export async function POST({ request }: { request: Request }) {
         if (seen.has(id)) return json({ type: 5, data: { flags: 64 } });
         if (pending >= 32 || seen.size >= 10_000 || now - (actors.get(actor) ?? 0) < 1000)
             return json(privateReply('Please wait a moment before trying again.'));
-        if (!claimDiscordInteraction(id)) return json({ type: 5, data: { flags: 64 } });
         seen.set(id, now);
         actors.set(actor, now);
         pending++;
-        // Acknowledge immediately; report queries and Discord delivery must not consume
-        // the three-second response window. Durable watches are saved by the handler.
+        // Do not read or write SQLite before returning the acknowledgement. In particular,
+        // acquiring the replay-claim write lock can outlast Discord's three-second deadline.
+        console.info('[discord] Deferring interaction.', { id, type: body.type });
         setImmediate(() => {
             void (async () => {
                 try {
+                    if (!claimDiscordInteraction(id)) return;
+                    const settings = getDiscordSettings();
+                    if (!settings.enabled || body.guild_id !== settings.guildId) {
+                        await completeDiscordInteraction(
+                            body.application_id as string,
+                            body.token as string,
+                            privateMessage(
+                                'Electric Cherry is not enabled for this Discord server.'
+                            )
+                        );
+                        return;
+                    }
                     const reply = await handleDiscordInteraction(
                         body as unknown as DiscordInteraction
                     );
@@ -56,6 +81,7 @@ export async function POST({ request }: { request: Request }) {
                         () => JSON.stringify(getDiscordSettings()) === JSON.stringify(settings)
                     );
                 } catch {
+                    console.error('[discord] Deferred interaction failed.', { id });
                     try {
                         await completeDiscordInteraction(
                             body.application_id as string,
@@ -74,8 +100,14 @@ export async function POST({ request }: { request: Request }) {
         });
         return json({ type: 5, data: { flags: 64 } });
     } catch (cause) {
-        if (isHttpError(cause))
+        if (isHttpError(cause)) {
+            console.warn('[discord] Interaction request rejected.', {
+                status: cause.status,
+                reason: cause.body.message
+            });
             return json({ error: cause.body.message }, { status: cause.status });
+        }
+        console.error('[discord] Interaction request failed before acknowledgement.');
         return json({ error: 'Could not process Discord interaction.' }, { status: 500 });
     }
 }

tests/unit/discord-webhook.test.ts

@@ -14,9 +14,11 @@ const guildId = '223456789012345678';
 const userId = '323456789012345678';
 const settings = vi.hoisted(() => ({ enabled: true, guildId: '223456789012345678' }));
 const handle = vi.hoisted(() => vi.fn());
+const readSettings = vi.hoisted(() => vi.fn());
+const claimInteraction = vi.hoisted(() => vi.fn());
 vi.mock('../../src/lib/server/discord/store.js', () => ({
-    getDiscordSettings: () => settings,
-    claimDiscordInteraction: () => true
+    getDiscordSettings: readSettings,
+    claimDiscordInteraction: claimInteraction
 }));
 vi.mock('../../src/lib/server/discord/interactions.js', () => ({
     handleDiscordInteraction: handle
@@ -54,6 +56,11 @@ beforeEach(() => {
     );
     vi.stubEnv('EC_DISCORD_APPLICATION_ID', applicationId);
     settings.enabled = true;
+    readSettings.mockReset().mockImplementation(() => settings);
+    claimInteraction.mockReset().mockReturnValue(true);
+    vi.spyOn(console, 'info').mockImplementation(() => {});
+    vi.spyOn(console, 'warn').mockImplementation(() => {});
+    vi.spyOn(console, 'error').mockImplementation(() => {});
     handle.mockReset().mockResolvedValue({
         type: 4,
         data: { flags: 64, content: 'Private results', allowed_mentions: { parse: [] } }
@@ -63,6 +70,7 @@ afterEach(() => {
     vi.useRealTimers();
     vi.unstubAllEnvs();
     vi.unstubAllGlobals();
+    vi.restoreAllMocks();
 });
 
 describe('Discord signed webhook boundary', () => {
@@ -114,19 +122,76 @@ describe('Discord signed webhook boundary', () => {
         ).toBe(false);
     });
 
-    it('does not dispatch disabled or foreign-guild interactions', async () => {
+    it.each(['disabled', 'foreign-guild'])(
+        'acknowledges %s interactions before checking configuration without dispatching them',
+        async (mode) => {
+            const fetcher = vi.fn().mockResolvedValue(new Response('{}'));
+            vi.stubGlobal('fetch', fetcher);
+            const { POST } = await import('../../src/routes/api/discord/interactions/+server.js');
+            settings.enabled = mode !== 'disabled';
+            const result = await POST({
+                request: signedRequest({
+                    ...interaction(),
+                    guild_id: mode === 'foreign-guild' ? userId : guildId
+                })
+            });
+            expect(await result.json()).toEqual({ type: 5, data: { flags: 64 } });
+            expect(readSettings).not.toHaveBeenCalled();
+            expect(claimInteraction).not.toHaveBeenCalled();
+            await new Promise((resolve) => setImmediate(resolve));
+            expect(fetcher).toHaveBeenCalledOnce();
+            expect(fetcher.mock.calls[0][1].body).toContain('not enabled');
+            expect(handle).not.toHaveBeenCalled();
+        }
+    );
+
+    it('explains a signed application ID mismatch instead of making the button time out', async () => {
         const { POST } = await import('../../src/routes/api/discord/interactions/+server.js');
-        const foreign = await POST({
-            request: signedRequest({ ...interaction(), guild_id: userId })
+        const result = await POST({
+            request: signedRequest({ ...interaction(), application_id: guildId })
         });
-        expect((await foreign.json()).data.flags).toBe(64);
-        settings.enabled = false;
-        expect(
-            (await (await POST({ request: signedRequest(interaction()) })).json()).data.flags
-        ).toBe(64);
+        expect(result.status).toBe(200);
+        expect(await result.json()).toMatchObject({
+            type: 4,
+            data: { flags: 64, content: expect.stringContaining('EC_DISCORD_APPLICATION_ID') }
+        });
+        expect(claimInteraction).not.toHaveBeenCalled();
         expect(handle).not.toHaveBeenCalled();
     });
 
+    it.each(['ec:d:01234567890123456789', 'ec:b:t5:all:0:', 'ec:maps:t5', 'ec:leader:t5'])(
+        'acknowledges %s before any database work, even when the replay write fails',
+        async (customId) => {
+            const fetcher = vi.fn().mockResolvedValue(new Response('{}'));
+            vi.stubGlobal('fetch', fetcher);
+            claimInteraction.mockImplementation(() => {
+                throw new Error('private database failure');
+            });
+            const { POST } = await import('../../src/routes/api/discord/interactions/+server.js');
+            const result = await POST({
+                request: signedRequest({
+                    ...interaction(),
+                    type: 3,
+                    data: { custom_id: customId, component_type: 2 }
+                })
+            });
+            expect(result.status).toBe(200);
+            expect(await result.json()).toEqual({ type: 5, data: { flags: 64 } });
+            expect(claimInteraction).not.toHaveBeenCalled();
+            expect(readSettings).not.toHaveBeenCalled();
+            await new Promise((resolve) => setImmediate(resolve));
+            expect(claimInteraction).toHaveBeenCalledOnce();
+            expect(handle).not.toHaveBeenCalled();
+            expect(fetcher.mock.calls[0][1].body).toContain('could not complete');
+            expect(JSON.stringify(vi.mocked(console.error).mock.calls)).not.toContain(
+                'private database failure'
+            );
+            expect(JSON.stringify(vi.mocked(console.error).mock.calls)).not.toContain(
+                'private-interaction-token'
+            );
+        }
+    );
+
     it('defers privately, dispatches once per interaction and delivers without bot credentials', async () => {
         const fetcher = vi.fn().mockResolvedValue(new Response('{}'));
         vi.stubGlobal('fetch', fetcher);
@@ -139,6 +204,8 @@ describe('Discord signed webhook boundary', () => {
             pending
         );
         expect(handle).not.toHaveBeenCalled();
+        expect(readSettings).not.toHaveBeenCalled();
+        expect(claimInteraction).not.toHaveBeenCalled();
         await new Promise((resolve) => setImmediate(resolve));
         expect(handle).toHaveBeenCalledTimes(1);
         expect(fetcher).toHaveBeenCalledOnce();