diff --git a/app/routes/webhooks.orders.create.tsx b/app/routes/webhooks.orders.create.tsx index 0450b7c..8598d0c 100644 --- a/app/routes/webhooks.orders.create.tsx +++ b/app/routes/webhooks.orders.create.tsx @@ -5,6 +5,8 @@ import { generateAndEmailInvoice, isManualPaymentOrder, } from "../services/invoice/automations.server"; +import { isDuplicateWebhook } from "../services/webhooks/dedupe.server"; +import { runWebhookInBackground } from "../services/webhooks/background.server"; /** * orders/create — Automation 1: when a wire-transfer (manual-payment-gateway) @@ -16,31 +18,42 @@ export const action = async ({ request }: ActionFunctionArgs) => { const { shop, topic, payload, session, admin } = await authenticate.webhook(request); console.log(`Received ${topic} webhook for ${shop}`); - if (!session || !admin) return new Response(); + // Drop Shopify retries we've already processed (prevents the duplicate + // invoice email we saw when the first delivery exceeded Shopify's 5s ack + // timeout — the work still completed, but Shopify resent the webhook). + if (await isDuplicateWebhook(request, shop, topic)) return new Response(); - const settings = await db.shopSettings.findUnique({ where: { shopDomain: shop } }); - if (!settings?.autoEmailOnWireTransferPlaced) return new Response(); + if (!session || !admin) return new Response(); const orderId = payload?.id; if (orderId == null) return new Response(); - const orderGid = `gid://shopify/Order/${String(orderId).replace(/^.*\//, "")}`; - const isManual = await isManualPaymentOrder(admin, orderGid); - if (!isManual) return new Response(); + const customerLocale = + typeof payload?.customer_locale === "string" ? payload.customer_locale : undefined; + + // Respond 200 immediately and run the (slow) PDF + email work in the + // background — keeps us well under Shopify's ~5s ack timeout. Dedupe + // above guarantees we don't double-process a retry while the first + // delivery is still working. + runWebhookInBackground(`${topic} order=${orderId} shop=${shop}`, async () => { + const settings = await db.shopSettings.findUnique({ where: { shopDomain: shop } }); + if (!settings?.autoEmailOnWireTransferPlaced) return; + + const orderGid = `gid://shopify/Order/${String(orderId).replace(/^.*\//, "")}`; + if (!(await isManualPaymentOrder(admin, orderGid))) return; - try { const result = await generateAndEmailInvoice({ shopDomain: shop, admin, orderId, - customerLocale: typeof payload?.customer_locale === "string" ? payload.customer_locale : undefined, + customerLocale, }); if (!result.ok) { - console.warn(`auto-email (wire-transfer placed) failed for order ${orderId} on ${shop}: ${result.reason}`); + console.warn( + `auto-email (wire-transfer placed) failed for order ${orderId} on ${shop}: ${result.reason}`, + ); } - } catch (err) { - console.error(`auto-email (wire-transfer placed) crashed for order ${orderId} on ${shop}:`, err); - } + }); return new Response(); }; diff --git a/app/routes/webhooks.orders.fulfilled.tsx b/app/routes/webhooks.orders.fulfilled.tsx index 807bcaa..201ca2d 100644 --- a/app/routes/webhooks.orders.fulfilled.tsx +++ b/app/routes/webhooks.orders.fulfilled.tsx @@ -5,6 +5,8 @@ import { generateAndEmailInvoice, isManualPaymentOrder, } from "../services/invoice/automations.server"; +import { isDuplicateWebhook } from "../services/webhooks/dedupe.server"; +import { runWebhookInBackground } from "../services/webhooks/background.server"; /** * orders/fulfilled — Automation 2: when an order is fulfilled and is NOT a @@ -16,36 +18,42 @@ export const action = async ({ request }: ActionFunctionArgs) => { const { shop, topic, payload, session, admin } = await authenticate.webhook(request); console.log(`Received ${topic} webhook for ${shop}`); + // Idempotency against Shopify retries — see webhooks/dedupe.server.ts. + if (await isDuplicateWebhook(request, shop, topic)) return new Response(); + if (!session || !admin) { // App was uninstalled before the webhook drained — nothing to do. return new Response(); } - const settings = await db.shopSettings.findUnique({ where: { shopDomain: shop } }); - if (!settings?.autoEmailOnFulfilledNonWireTransfer) return new Response(); - const orderId = payload?.id; if (orderId == null) return new Response(); - const orderGid = `gid://shopify/Order/${String(orderId).replace(/^.*\//, "")}`; - if (await isManualPaymentOrder(admin, orderGid)) { - // Manual / wire-transfer order — handled by Automation 1, skip here. - return new Response(); - } + const customerLocale = + typeof payload?.customer_locale === "string" ? payload.customer_locale : undefined; + + // Respond fast; do the heavy lifting after the response (see notes in + // webhooks.orders.create.tsx for the rationale). + runWebhookInBackground(`${topic} order=${orderId} shop=${shop}`, async () => { + const settings = await db.shopSettings.findUnique({ where: { shopDomain: shop } }); + if (!settings?.autoEmailOnFulfilledNonWireTransfer) return; + + const orderGid = `gid://shopify/Order/${String(orderId).replace(/^.*\//, "")}`; + if (await isManualPaymentOrder(admin, orderGid)) { + // Manual / wire-transfer order — handled by Automation 1, skip here. + return; + } - try { const result = await generateAndEmailInvoice({ shopDomain: shop, admin, orderId, - customerLocale: typeof payload?.customer_locale === "string" ? payload.customer_locale : undefined, + customerLocale, }); if (!result.ok) { console.warn(`auto-email (fulfilled) failed for order ${orderId} on ${shop}: ${result.reason}`); } - } catch (err) { - console.error(`auto-email (fulfilled) crashed for order ${orderId} on ${shop}:`, err); - } + }); return new Response(); }; diff --git a/app/routes/webhooks.orders.updated.tsx b/app/routes/webhooks.orders.updated.tsx index 0039d3a..1c47386 100644 --- a/app/routes/webhooks.orders.updated.tsx +++ b/app/routes/webhooks.orders.updated.tsx @@ -1,10 +1,13 @@ import type { ActionFunctionArgs } from "react-router"; import { authenticate } from "../shopify.server"; +import { isDuplicateWebhook } from "../services/webhooks/dedupe.server"; // Acknowledged but not yet acted on. Future: invalidate cached invoice // snapshots when a relevant field on the order changes. export const action = async ({ request }: ActionFunctionArgs) => { const { shop, topic } = await authenticate.webhook(request); console.log(`Received ${topic} webhook for ${shop}`); + // Idempotency against Shopify retries — see webhooks/dedupe.server.ts. + if (await isDuplicateWebhook(request, shop, topic)) return new Response(); return new Response(); }; diff --git a/app/services/invoice/i18n.ts b/app/services/invoice/i18n.ts index 0781f60..d898b0a 100644 --- a/app/services/invoice/i18n.ts +++ b/app/services/invoice/i18n.ts @@ -167,11 +167,19 @@ const en: InvoiceStrings = { paidStamp: "PAID", }; +// Locale → invoice language. We only render in German (`de`) when the +// caller is explicitly German-speaking (de, de-AT, de-DE, de_CH, …). +// Everything else (it, fr, es, en, …) falls back to English so that +// non-German-speaking customers don't receive a German invoice. Callers +// that have a per-shop default fall back to it via +// `pickLanguage(customerLocale ?? settings.defaultLanguage)`, which is why +// `null`/`undefined` still maps to `de` (the legacy default for the +// Austrian shops this app was built for). export function pickLanguage(input: string | null | undefined): InvoiceLanguage { if (!input) return "de"; const v = input.toLowerCase(); - if (v.startsWith("en")) return "en"; - return "de"; + if (v.startsWith("de")) return "de"; + return "en"; } export function getStrings(language: InvoiceLanguage): InvoiceStrings { diff --git a/app/services/webhooks/background.server.ts b/app/services/webhooks/background.server.ts new file mode 100644 index 0000000..37c77d7 --- /dev/null +++ b/app/services/webhooks/background.server.ts @@ -0,0 +1,27 @@ +/** + * Fire-and-forget runner for webhook side-effects. + * + * Shopify expects a 200 response within ~5 seconds, otherwise it considers + * the delivery failed and retries it. Heavy automation work (PDF render, + * Shopify Files upload, SMTP send) routinely exceeded that budget, which + * caused duplicate invoice emails before we added the dedupe table. + * + * Returning the response immediately and letting the work finish in the + * background keeps Shopify happy. Combined with the dedupe table this is + * defence-in-depth: dedupe ensures *correctness* even if a retry sneaks + * through, while async processing makes retries unlikely in the first + * place. + * + * Errors are caught and logged \u2014 they cannot reach a dispatcher because + * the HTTP response is already gone. + */ +export function runWebhookInBackground( + description: string, + work: () => Promise, +): void { + // `void` so we don't accidentally `await` the floating promise; the + // node event loop keeps the task alive until it settles. + void work().catch((err) => { + console.error(`background webhook task '${description}' failed:`, err); + }); +} diff --git a/app/services/webhooks/dedupe.server.ts b/app/services/webhooks/dedupe.server.ts new file mode 100644 index 0000000..272e07c --- /dev/null +++ b/app/services/webhooks/dedupe.server.ts @@ -0,0 +1,67 @@ +import db from "../../db.server"; + +/** + * Minimal shape of the Prisma client surface we use — declared inline so + * the helper can be unit-tested with a tiny stub instead of pulling in a + * real database. + */ +export interface DedupeDeps { + db: { + processedWebhook: { + create: (args: { + data: { webhookId: string; topic: string; shopDomain: string }; + }) => Promise; + }; + }; +} + +/** + * Returns `true` when this Shopify webhook delivery has already been + * processed and the caller should short-circuit without doing the work. + * + * Shopify retries webhook deliveries when it doesn't receive a 200 within + * its (~5s) timeout window. Without dedupe this caused us to email an + * invoice twice for the same order: the first slow delivery completed its + * work but Shopify timed out and re-sent the webhook, which then ran the + * automation a second time. + * + * We key on the `X-Shopify-Webhook-Id` header — Shopify guarantees the same + * value for retries of the same delivery, but a new value for genuinely + * new events. The insert is the lock: a unique-constraint violation + * (Prisma error code `P2002`) means another delivery already claimed this + * id. + */ +export async function isDuplicateWebhook( + request: Request, + shop: string, + topic: string, + deps: DedupeDeps = { db }, +): Promise { + const webhookId = request.headers.get("x-shopify-webhook-id"); + if (!webhookId) { + // Defensive: in unit tests / non-Shopify callers there is no id. + // Don't dedupe — that would silently drop legitimate calls. + return false; + } + try { + await deps.db.processedWebhook.create({ + data: { webhookId, topic, shopDomain: shop }, + }); + return false; + } catch (err) { + // Duck-typed P2002 check so callers can stub the db without pulling + // in the real `Prisma` namespace. + if ((err as { code?: string } | null)?.code === "P2002") { + console.log( + `dedupe: skipping duplicate ${topic} delivery for ${shop} (webhookId=${webhookId})`, + ); + return true; + } + // Don't fail the webhook on a logging-table issue; just process it. + console.warn( + `dedupe: failed to record webhook ${webhookId} (${topic}/${shop}):`, + err, + ); + return false; + } +} diff --git a/package-lock.json b/package-lock.json index 4634db4..3282f47 100644 --- a/package-lock.json +++ b/package-lock.json @@ -12,6 +12,7 @@ "@prisma/client": "^6.16.3", "@react-pdf/renderer": "^4.5.1", "@react-router/dev": "^7.12.0", + "@react-router/express": "^7.14.2", "@react-router/fs-routes": "^7.12.0", "@react-router/node": "^7.12.0", "@react-router/serve": "^7.12.0", @@ -26,7 +27,10 @@ "@tiptap/react": "^3.23.1", "@tiptap/starter-kit": "^3.23.1", "@types/nodemailer": "^8.0.0", + "compression": "^1.8.1", + "express": "^4.22.1", "isbot": "^5.1.31", + "morgan": "^1.10.1", "nodemailer": "^8.0.7", "prisma": "^6.16.3", "qrcode": "^1.5.4", @@ -61,6 +65,15 @@ "node": ">=20.19 <22 || >=22.12" } }, + "extensions/customer-account-payment": { + "version": "1.0.0", + "devDependencies": { + "@preact/signals": "^1.3.0", + "@shopify/ui-extensions": "^2026.1.0", + "preact": "^10.22.0", + "typescript": "^5.6.0" + } + }, "extensions/invoice-order-action": { "version": "1.0.0", "devDependencies": { @@ -6670,6 +6683,10 @@ "integrity": "sha512-z1HGKcYy2xA8AGQfwrn0PAy+PB7X/GSj3UVJW9qKyn43xWa+gl5nXmU4qqLMRzWVLFC8KusUX8T/0kCiOYpAIQ==", "license": "MIT" }, + "node_modules/customer-account-payment": { + "resolved": "extensions/customer-account-payment", + "link": true + }, "node_modules/damerau-levenshtein": { "version": "1.0.8", "resolved": "https://registry.npmjs.org/damerau-levenshtein/-/damerau-levenshtein-1.0.8.tgz", diff --git a/package.json b/package.json index 387aaf3..edb3d05 100644 --- a/package.json +++ b/package.json @@ -9,7 +9,7 @@ "deploy": "shopify app deploy", "config:use": "shopify app config use", "env": "shopify app env", - "start": "react-router-serve ./build/server/index.js", + "start": "node ./server.js", "docker-start": "npm run setup && npm run start", "setup": "prisma generate && prisma migrate deploy", "lint": "eslint --ignore-path .gitignore --cache --cache-location ./node_modules/.cache/eslint .", @@ -17,7 +17,8 @@ "prisma": "prisma", "graphql-codegen": "graphql-codegen", "vite": "vite", - "typecheck": "react-router typegen && tsc --noEmit" + "typecheck": "react-router typegen && tsc --noEmit", + "test": "tsx --test tests" }, "type": "module", "engines": { @@ -29,7 +30,11 @@ "@react-router/dev": "^7.12.0", "@react-router/fs-routes": "^7.12.0", "@react-router/node": "^7.12.0", + "@react-router/express": "^7.14.2", "@react-router/serve": "^7.12.0", + "compression": "^1.8.1", + "express": "^4.22.1", + "morgan": "^1.10.1", "@shopify/app-bridge-react": "^4.2.4", "@shopify/shopify-app-react-router": "^1.1.0", "@shopify/shopify-app-session-storage-prisma": "^8.0.0", diff --git a/prisma/migrations/20260515083638_add_processed_webhook/migration.sql b/prisma/migrations/20260515083638_add_processed_webhook/migration.sql new file mode 100644 index 0000000..fa58a68 --- /dev/null +++ b/prisma/migrations/20260515083638_add_processed_webhook/migration.sql @@ -0,0 +1,13 @@ +-- Idempotency table for inbound Shopify webhooks. We insert a row keyed on +-- the X-Shopify-Webhook-Id header at the start of webhook processing; a +-- duplicate insert (P2002) means Shopify retried a delivery we've already +-- seen, so we short-circuit and return 200 without doing the work twice. +CREATE TABLE "ProcessedWebhook" ( + "webhookId" TEXT NOT NULL PRIMARY KEY, + "topic" TEXT NOT NULL, + "shopDomain" TEXT NOT NULL, + "receivedAt" DATETIME NOT NULL DEFAULT CURRENT_TIMESTAMP +); + +CREATE INDEX "ProcessedWebhook_shopDomain_topic_idx" + ON "ProcessedWebhook"("shopDomain", "topic"); diff --git a/prisma/schema.prisma b/prisma/schema.prisma index 1247b67..8ca456d 100644 --- a/prisma/schema.prisma +++ b/prisma/schema.prisma @@ -182,6 +182,17 @@ model EmailLog { @@index([shopDomain, invoiceId]) } +// Idempotency table for inbound Shopify webhooks. See +// `app/services/webhooks/dedupe.server.ts` for details. +model ProcessedWebhook { + webhookId String @id + topic String + shopDomain String + receivedAt DateTime @default(now()) + + @@index([shopDomain, topic]) +} + // Per-shop logo bytes cache. Avoids fetching the logo from Shopify Files on // every PDF render. model LogoCache { diff --git a/server.js b/server.js new file mode 100644 index 0000000..3ff8d74 --- /dev/null +++ b/server.js @@ -0,0 +1,81 @@ +// Custom production server for the React Router build. +// +// Replaces `react-router-serve` so we can: +// - prefix every console line with an ISO timestamp, +// - use a richer morgan format (with timestamp + content-length), +// - skip access logs for successful /healthz probes (they would otherwise +// drown out everything useful — Docker/Caddy poll them every couple of +// seconds). +// +// Behaviour is otherwise intentionally identical to `@react-router/serve`'s +// CLI (compression, /assets immutable cache, public/ static, SIGTERM/SIGINT +// handling). + +import { createRequestHandler } from "@react-router/express"; +import compression from "compression"; +import express from "express"; +import morgan from "morgan"; + +// --------------------------------------------------------------------------- +// Console timestamps — patch BEFORE anything else logs. +// --------------------------------------------------------------------------- +const ts = () => `[${new Date().toISOString()}]`; +for (const level of ["log", "info", "warn", "error", "debug"]) { + const original = console[level].bind(console); + console[level] = (...args) => original(ts(), ...args); +} + +const PORT = Number(process.env.PORT || 3000); +const HOST = process.env.HOST; + +const buildModule = await import("./build/server/index.js"); +const build = buildModule.default ?? buildModule; + +const app = express(); +app.disable("x-powered-by"); +app.use(compression()); + +// Static assets emitted by the React Router build. +app.use( + "/assets", + express.static("build/client/assets", { immutable: true, maxAge: "1y" }), +); +app.use(express.static("build/client", { maxAge: "1h" })); +app.use(express.static("public", { maxAge: "1h" })); + +// Access log: ISO timestamp + standard request info; suppress healthy +// /healthz polls so real traffic stays visible. +morgan.token("isotime", () => new Date().toISOString()); +app.use( + morgan( + ":isotime :method :url :status :res[content-length] - :response-time ms", + { + skip: (req, res) => req.url === "/healthz" && res.statusCode < 400, + }, + ), +); + +app.all( + "*", + createRequestHandler({ build, mode: process.env.NODE_ENV }), +); + +const onListen = () => { + console.log( + `[server] listening on http://${HOST ?? "localhost"}:${PORT}`, + ); +}; + +const server = HOST + ? app.listen(PORT, HOST, onListen) + : app.listen(PORT, onListen); + +for (const signal of ["SIGTERM", "SIGINT"]) { + process.once(signal, () => { + console.log(`[server] received ${signal}, shutting down`); + server.close((err) => { + if (err) console.error("[server] close error:", err); + process.exit(0); + }); + }); +} diff --git a/tests/dedupe-and-language.test.ts b/tests/dedupe-and-language.test.ts new file mode 100644 index 0000000..a10409a --- /dev/null +++ b/tests/dedupe-and-language.test.ts @@ -0,0 +1,79 @@ +import { strict as assert } from "node:assert"; +import { describe, it } from "node:test"; + +import { pickLanguage } from "../app/services/invoice/i18n"; +import { isDuplicateWebhook, type DedupeDeps } from "../app/services/webhooks/dedupe.server"; + +describe("pickLanguage", () => { + it("returns 'de' only for explicit German locales", () => { + assert.equal(pickLanguage("de"), "de"); + assert.equal(pickLanguage("de-AT"), "de"); + assert.equal(pickLanguage("de-DE"), "de"); + assert.equal(pickLanguage("de_CH"), "de"); + assert.equal(pickLanguage("DE-AT"), "de"); // case-insensitive + }); + + it("returns 'en' for non-German locales (regression: it/fr/es no longer fall back to de)", () => { + assert.equal(pickLanguage("en"), "en"); + assert.equal(pickLanguage("en-US"), "en"); + assert.equal(pickLanguage("it"), "en"); + assert.equal(pickLanguage("it-IT"), "en"); + assert.equal(pickLanguage("fr"), "en"); + assert.equal(pickLanguage("fr-FR"), "en"); + assert.equal(pickLanguage("es"), "en"); + assert.equal(pickLanguage("hu-HU"), "en"); + }); + + it("falls back to 'de' for empty/unknown input so the per-shop default chain still works", () => { + assert.equal(pickLanguage(undefined), "de"); + assert.equal(pickLanguage(null), "de"); + assert.equal(pickLanguage(""), "de"); + }); +}); + +function makeRequest(headers: Record = {}): Request { + return new Request("https://example.com/webhooks/test", { + method: "POST", + headers, + }); +} + +function makeDeps(behaviour: "ok" | "p2002" | "boom"): DedupeDeps { + return { + db: { + processedWebhook: { + create: async () => { + if (behaviour === "ok") return {}; + if (behaviour === "p2002") { + const err = new Error("Unique constraint failed") as Error & { code?: string }; + err.code = "P2002"; + throw err; + } + throw new Error("DB unavailable"); + }, + }, + }, + }; +} + +describe("isDuplicateWebhook", () => { + it("returns false on first delivery (insert succeeds)", async () => { + const req = makeRequest({ "x-shopify-webhook-id": "abc-123" }); + assert.equal(await isDuplicateWebhook(req, "shop.myshopify.com", "ORDERS_CREATE", makeDeps("ok")), false); + }); + + it("returns true on a retried delivery (P2002)", async () => { + const req = makeRequest({ "x-shopify-webhook-id": "abc-123" }); + assert.equal(await isDuplicateWebhook(req, "shop.myshopify.com", "ORDERS_CREATE", makeDeps("p2002")), true); + }); + + it("returns false (and proceeds) when the dedupe table itself errors \u2014 fail-open, never drop a webhook silently", async () => { + const req = makeRequest({ "x-shopify-webhook-id": "abc-123" }); + assert.equal(await isDuplicateWebhook(req, "shop.myshopify.com", "ORDERS_CREATE", makeDeps("boom")), false); + }); + + it("returns false when the X-Shopify-Webhook-Id header is missing (test harness / non-Shopify caller)", async () => { + const req = makeRequest(); + assert.equal(await isDuplicateWebhook(req, "shop.myshopify.com", "ORDERS_CREATE", makeDeps("ok")), false); + }); +});