From f6c2ad14e8fa97fcc42faf8d8d588d0173ef9a2e Mon Sep 17 00:00:00 2001 From: KM Koushik <24666922+KMKoushik@users.noreply.github.com> Date: Thu, 15 Oct 2026 09:40:21 +0000 Subject: [PATCH 1/2] feat(logging): log billing, email event and API failures with identifiers Co-authored-by: polylane[bot] <277585245+polylane[bot]@users.noreply.github.com> --- apps/web/src/app/api/ses_callback/route.ts | 40 +++++++++++++---- apps/web/src/app/api/trpc/[trpc]/route.ts | 27 +++++++---- .../app/api/webhook/stripe/route.api.test.ts | 45 ++++++++++++++++++- apps/web/src/app/api/webhook/stripe/route.ts | 20 ++++++--- apps/web/src/server/aws/ses.ts | 5 ++- apps/web/src/server/billing/payments.ts | 4 ++ 6 files changed, 116 insertions(+), 25 deletions(-) diff --git a/apps/web/src/app/api/ses_callback/route.ts b/apps/web/src/app/api/ses_callback/route.ts index 70913c1ee..6fa5aeb7c 100644 --- a/apps/web/src/app/api/ses_callback/route.ts +++ b/apps/web/src/app/api/ses_callback/route.ts @@ -14,13 +14,22 @@ export async function GET() { export async function POST(req: Request) { const data = await req.json(); - console.log(data, data.Message); + logger.info( + { + snsMessageId: data.MessageId, + snsType: data.Type, + topicArn: data.TopicArn, + }, + "[SesCallback]: Received an SNS notification", + ); const isEventValid = await checkEventValidity(data); - console.log("Is event valid: ", isEventValid); - if (!isEventValid) { + logger.warn( + { snsMessageId: data.MessageId, topicArn: data.TopicArn }, + "[SesCallback]: Dropped the SES event because the topic is not configured", + ); return Response.json({ data: "Event is not valid" }); } @@ -28,10 +37,8 @@ export async function POST(req: Request) { return handleSubscription(data); } - let message = null; - try { - message = JSON.parse(data.Message || "{}"); + const message = JSON.parse(data.Message || "{}"); const status = await SesHookParser.queue({ event: message, messageId: data.MessageId, @@ -42,7 +49,10 @@ export async function POST(req: Request) { return Response.json({ data: "Success" }); } catch (e) { - console.error(e); + logger.error( + { err: e, snsMessageId: data.MessageId, topicArn: data.TopicArn }, + "[SesCallback]: Failed to queue the SES event", + ); return Response.json({ data: "Error is parsing hook" }); } } @@ -51,11 +61,19 @@ export async function POST(req: Request) { * Handles the subscription confirmation event. called only once for a webhook */ async function handleSubscription(message: any) { - await fetch(message.SubscribeURL, { + const topicArn = message.TopicArn as string; + + const confirmResponse = await fetch(message.SubscribeURL, { method: "GET", }); - const topicArn = message.TopicArn as string; + if (!confirmResponse.ok) { + logger.error( + { status: confirmResponse.status, topicArn }, + "[SesCallback]: SNS subscription confirmation returned a non-success status", + ); + } + const setting = await db.sesSetting.findFirst({ where: { topicArn, @@ -63,6 +81,10 @@ async function handleSubscription(message: any) { }); if (!setting) { + logger.warn( + { topicArn }, + "[SesCallback]: No SES setting matches the confirmed topic ARN", + ); return Response.json({ data: "Setting not found" }); } diff --git a/apps/web/src/app/api/trpc/[trpc]/route.ts b/apps/web/src/app/api/trpc/[trpc]/route.ts index 5fbd827d9..3dde11941 100644 --- a/apps/web/src/app/api/trpc/[trpc]/route.ts +++ b/apps/web/src/app/api/trpc/[trpc]/route.ts @@ -1,9 +1,9 @@ import { fetchRequestHandler } from "@trpc/server/adapters/fetch"; import { type NextRequest } from "next/server"; -import { env } from "~/env"; import { appRouter } from "~/server/api/root"; import { createTRPCContext } from "~/server/api/trpc"; +import { logger } from "~/server/logger/log"; /** * This wraps the `createTRPCContext` helper and provides the required context for the tRPC API when @@ -21,14 +21,23 @@ const handler = (req: NextRequest) => req, router: appRouter, createContext: () => createContext(req), - onError: - env.NODE_ENV === "development" - ? ({ path, error }) => { - console.error( - `❌ tRPC failed on ${path ?? ""}: ${error.message}` - ); - } - : undefined, + // Only server-side failures are logged. Rejected input, bad credentials and + // missing records are a normal part of the API surface and stay unlogged. + onError: ({ path, error }) => { + if (error.code !== "INTERNAL_SERVER_ERROR" && error.code !== "TIMEOUT") { + return; + } + + logger.error( + { + err: error, + cause: error.cause, + trpcPath: path, + trpcCode: error.code, + }, + "[Trpc]: Request failed" + ); + }, }); export { handler as GET, handler as POST }; diff --git a/apps/web/src/app/api/webhook/stripe/route.api.test.ts b/apps/web/src/app/api/webhook/stripe/route.api.test.ts index 02eea44dd..1e7ed129b 100644 --- a/apps/web/src/app/api/webhook/stripe/route.api.test.ts +++ b/apps/web/src/app/api/webhook/stripe/route.api.test.ts @@ -3,6 +3,7 @@ import { describe, expect, it, vi } from "vitest"; const { state } = vi.hoisted(() => ({ state: { signature: null as string | null, + secret: undefined as string | undefined, }, })); @@ -27,11 +28,23 @@ vi.mock("~/server/billing/payments", () => ({ vi.mock("~/env", () => ({ env: { - STRIPE_WEBHOOK_SECRET: undefined, + get STRIPE_WEBHOOK_SECRET() { + return state.secret; + }, + }, +})); + +vi.mock("~/server/logger/log", () => ({ + logger: { + error: vi.fn(), + warn: vi.fn(), + info: vi.fn(), }, })); import { POST } from "~/app/api/webhook/stripe/route"; +import { getStripe, syncStripeData } from "~/server/billing/payments"; +import { logger } from "~/server/logger/log"; describe("stripe webhook route", () => { it("returns 400 when signature header is missing", async () => { @@ -58,4 +71,34 @@ describe("stripe webhook route", () => { expect(response.status).toBe(400); await expect(response.text()).resolves.toBe("No webhook secret"); }); + + it("logs the stripe event identity when the billing sync fails", async () => { + state.signature = "test-signature"; + state.secret = "whsec_test"; + + vi.mocked(getStripe).mockReturnValue({ + webhooks: { + constructEvent: vi.fn(() => ({ + id: "evt_123", + type: "invoice.paid", + data: { object: { customer: "cus_123" } }, + })), + }, + } as never); + vi.mocked(syncStripeData).mockRejectedValue(new Error("stripe API error")); + + const response = await POST( + new Request("http://localhost", { method: "POST", body: "{}" }), + ); + + expect(response.status).toBe(400); + expect(logger.error).toHaveBeenCalledWith( + expect.objectContaining({ + stripeEventId: "evt_123", + stripeEventType: "invoice.paid", + stripeCustomerId: "cus_123", + }), + expect.any(String), + ); + }); }); diff --git a/apps/web/src/app/api/webhook/stripe/route.ts b/apps/web/src/app/api/webhook/stripe/route.ts index 73d1921d3..db9f4f51f 100644 --- a/apps/web/src/app/api/webhook/stripe/route.ts +++ b/apps/web/src/app/api/webhook/stripe/route.ts @@ -3,6 +3,7 @@ import { NextResponse } from "next/server"; import Stripe from "stripe"; import { env } from "~/env"; import { getStripe, syncStripeData } from "~/server/billing/payments"; +import { logger } from "~/server/logger/log"; const allowedEvents: Stripe.Event.Type[] = [ "checkout.session.completed", @@ -41,8 +42,11 @@ export async function POST(req: Request) { const stripe = getStripe(); + let event: Stripe.Event | undefined; + let customerId: string | undefined; + try { - const event = stripe.webhooks.constructEvent( + event = stripe.webhooks.constructEvent( body, signature, env.STRIPE_WEBHOOK_SECRET @@ -53,9 +57,7 @@ export async function POST(req: Request) { } // All the events I track have a customerId - const { customer: customerId } = event?.data?.object as { - customer: string; // Sadly TypeScript does not know this - }; + customerId = (event.data.object as { customer: string }).customer; // This helps make it typesafe and also lets me know if my assumption is wrong if (typeof customerId !== "string") { @@ -68,7 +70,15 @@ export async function POST(req: Request) { return new NextResponse("OK", { status: 200 }); } catch (err) { - console.error("Error processing webhook:", err); + logger.error( + { + err, + stripeEventId: event?.id, + stripeEventType: event?.type, + stripeCustomerId: customerId, + }, + "[StripeHook]: Failed to process the billing event" + ); return new NextResponse("Webhook error", { status: 400 }); } } diff --git a/apps/web/src/server/aws/ses.ts b/apps/web/src/server/aws/ses.ts index 5b6e9ab1c..95ab760d4 100644 --- a/apps/web/src/server/aws/ses.ts +++ b/apps/web/src/server/aws/ses.ts @@ -259,7 +259,10 @@ export async function sendRawEmail({ logger.info({ messageId: response.MessageId }, "Email sent!"); return response.MessageId; } catch (error) { - logger.error({ err: error }, "Failed to send email"); + logger.error( + { err: error, emailId, region }, + "Failed to send email" + ); // It's better to throw the original error or a new error with more context // throw new Error("Failed to send email"); throw error; diff --git a/apps/web/src/server/billing/payments.ts b/apps/web/src/server/billing/payments.ts index a73fd04f3..4539fe6b7 100644 --- a/apps/web/src/server/billing/payments.ts +++ b/apps/web/src/server/billing/payments.ts @@ -123,6 +123,10 @@ export async function syncStripeData(customerId: string) { }); if (!team) { + logger.warn( + { stripeCustomerId: customerId }, + "[Billing]: No team matches the Stripe customer; plan was not synced", + ); return; } From 33fa7f3291176c4f46be81ff1c4c6fcda171f859 Mon Sep 17 00:00:00 2001 From: KM Koushik <24666922+KMKoushik@users.noreply.github.com> Date: Thu, 15 Oct 2026 09:46:17 +0000 Subject: [PATCH 2/2] feat(logging): record campaign, domain and contact failure identifiers Co-authored-by: polylane[bot] <277585245+polylane[bot]@users.noreply.github.com> --- .../api/domains/get-domain.api.test.ts | 112 ++++++++++++++++++ .../public-api/api/domains/get-domain.ts | 7 ++ .../src/server/service/campaign-service.ts | 24 +++- .../service/campaign-service.unit.test.ts | 77 ++++++++++++ .../server/service/double-opt-in-service.ts | 3 +- .../double-opt-in-service.unit.test.ts | 9 +- 6 files changed, 226 insertions(+), 6 deletions(-) create mode 100644 apps/web/src/server/public-api/api/domains/get-domain.api.test.ts diff --git a/apps/web/src/server/public-api/api/domains/get-domain.api.test.ts b/apps/web/src/server/public-api/api/domains/get-domain.api.test.ts new file mode 100644 index 000000000..aacaec690 --- /dev/null +++ b/apps/web/src/server/public-api/api/domains/get-domain.api.test.ts @@ -0,0 +1,112 @@ +import { beforeEach, describe, expect, it, vi } from "vitest"; + +const { mockGetTeamFromToken, mockRedis, mockGetDomainService, mockLogger } = + vi.hoisted(() => ({ + mockGetTeamFromToken: vi.fn(), + mockRedis: { + incr: vi.fn(), + expire: vi.fn(), + ttl: vi.fn(), + }, + mockGetDomainService: vi.fn(), + mockLogger: { + debug: vi.fn(), + error: vi.fn(), + info: vi.fn(), + warn: vi.fn(), + }, + })); + +vi.mock("~/server/public-api/auth", () => ({ + getTeamFromToken: mockGetTeamFromToken, +})); + +vi.mock("~/server/redis", () => ({ + getRedis: () => mockRedis, + redisKey: (key: string) => key, +})); + +vi.mock("~/server/db", () => ({ + db: { + domain: { findUnique: vi.fn() }, + team: { findUnique: vi.fn() }, + }, +})); + +vi.mock("~/utils/common", () => ({ + isSelfHosted: () => false, +})); + +vi.mock("~/server/service/domain-service", () => ({ + getDomain: mockGetDomainService, +})); + +vi.mock("~/server/logger/log", () => ({ + logger: mockLogger, +})); + +import { UnsendApiError } from "~/server/public-api/api-error"; +import getDomain from "~/server/public-api/api/domains/get-domain"; +import { getApp } from "~/server/public-api/hono"; + +describe("GET /v1/domains/{id}", () => { + beforeEach(() => { + mockGetTeamFromToken.mockReset(); + mockGetDomainService.mockReset(); + mockLogger.error.mockReset(); + mockRedis.incr.mockReset(); + mockRedis.expire.mockReset(); + mockRedis.ttl.mockReset(); + + mockGetTeamFromToken.mockResolvedValue({ + id: 1, + apiRateLimit: 20, + apiKeyId: 11, + apiKey: { domainId: null }, + }); + + mockRedis.incr.mockResolvedValue(1); + mockRedis.expire.mockResolvedValue(1); + mockRedis.ttl.mockResolvedValue(1); + }); + + function request() { + const app = getApp(); + getDomain(app); + return app.request("http://localhost/api/v1/domains/42", { + headers: { Authorization: "Bearer test-key" }, + }); + } + + it("records the original error, the domain and the team when enrichment fails", async () => { + mockGetDomainService.mockRejectedValue( + new Error("SES identity lookup failed"), + ); + + const response = await request(); + + expect(response.status).toBe(500); + expect(mockLogger.error).toHaveBeenCalledWith( + expect.objectContaining({ + domainId: 42, + teamId: 1, + err: expect.any(Error), + }), + "Failed to enrich domain", + ); + }); + + it("records no enrichment failure for an expected missing domain", async () => { + mockGetDomainService.mockRejectedValue( + new UnsendApiError({ code: "NOT_FOUND", message: "Domain not found" }), + ); + + const response = await request(); + + expect(response.status).toBe(500); + const enrichmentFailureLogs = mockLogger.error.mock.calls.filter( + ([, message]) => message === "Failed to enrich domain", + ); + expect(enrichmentFailureLogs).toHaveLength(0); + }); +}); diff --git a/apps/web/src/server/public-api/api/domains/get-domain.ts b/apps/web/src/server/public-api/api/domains/get-domain.ts index 28572b059..4765b5c52 100644 --- a/apps/web/src/server/public-api/api/domains/get-domain.ts +++ b/apps/web/src/server/public-api/api/domains/get-domain.ts @@ -2,6 +2,7 @@ import { createRoute, z } from "@hono/zod-openapi"; import { DomainSchema } from "~/lib/zod/domain-schema"; import { PublicAPIApp } from "~/server/public-api/hono"; import { UnsendApiError } from "../../api-error"; +import { logger } from "~/server/logger/log"; import { db } from "~/server/db"; import { getDomain as getDomainService } from "~/server/service/domain-service"; @@ -46,6 +47,12 @@ function getDomain(app: PublicAPIApp) { try { enriched = await getDomainService(id, team.id); } catch (e) { + if (!(e instanceof UnsendApiError) || e.status >= 500) { + logger.error( + { err: e, domainId: id, teamId: team.id }, + "Failed to enrich domain", + ); + } throw new UnsendApiError({ code: "INTERNAL_SERVER_ERROR", message: e instanceof Error ? e.message : "Internal server error", diff --git a/apps/web/src/server/service/campaign-service.ts b/apps/web/src/server/service/campaign-service.ts index da5d7cd98..d13cbdaf8 100644 --- a/apps/web/src/server/service/campaign-service.ts +++ b/apps/web/src/server/service/campaign-service.ts @@ -87,7 +87,10 @@ async function prepareCampaignHtml( return { campaign, html }; } catch (error) { - logger.error({ err: error }, "Failed to parse campaign content"); + logger.error( + { err: error, campaignId: campaign.id }, + "Failed to parse campaign content", + ); throw new Error("Failed to parse campaign content"); } } @@ -149,7 +152,10 @@ async function renderCampaignHtmlForContact({ linkValues, }); } catch (error) { - logger.error({ err: error }, "Failed to parse campaign content"); + logger.error( + { err: error, campaignId: campaign.id, contactId: contact.id }, + "Failed to parse campaign content", + ); throw new Error("Failed to parse campaign content"); } } @@ -412,6 +418,10 @@ export async function scheduleCampaign({ campaign = prepared.campaign; html = prepared.html; } catch (err) { + logger.error( + { err, campaignId, teamId }, + "Failed to prepare campaign content for scheduling", + ); throw new UnsendApiError({ code: "BAD_REQUEST", message: err instanceof Error ? err.message : "Invalid campaign content", @@ -642,7 +652,10 @@ export async function unsubscribeContact({ return contact; } catch (error) { - logger.error({ err: error }, "Error unsubscribing contact"); + logger.error( + { err: error, contactId, campaignId, reason }, + "Error unsubscribing contact", + ); throw new Error("Failed to unsubscribe contact"); } } @@ -692,7 +705,10 @@ export async function subscribeContact(id: string, hash: string) { return true; } catch (error) { - logger.error({ err: error }, "Error subscribing contact"); + logger.error( + { err: error, contactId, campaignId }, + "Error subscribing contact", + ); throw new Error("Failed to subscribe contact"); } } diff --git a/apps/web/src/server/service/campaign-service.unit.test.ts b/apps/web/src/server/service/campaign-service.unit.test.ts index 52a5d4206..68e4209be 100644 --- a/apps/web/src/server/service/campaign-service.unit.test.ts +++ b/apps/web/src/server/service/campaign-service.unit.test.ts @@ -99,9 +99,11 @@ vi.mock("~/server/logger/log", () => ({ import { CampaignBatchService, recordCampaignContactFailure, + scheduleCampaign, subscribeContact, unsubscribeContact, } from "~/server/service/campaign-service"; +import { logger } from "~/server/logger/log"; const input = { contact: { @@ -284,3 +286,78 @@ describe("campaign contact subscription changes", () => { }); }); }); + +describe("campaign failure logs carry the failing identifiers", () => { + beforeEach(() => { + vi.clearAllMocks(); + }); + + it("logs the campaign and the contact when the unsubscribe write fails", async () => { + mockDb.contact.findUnique.mockResolvedValue({ + id: "contact_1", + contactBookId: "book_1", + email: "alice@example.com", + subscribed: true, + }); + mockUpdateContactSubscription.mockRejectedValue(new Error("write failed")); + + await expect( + unsubscribeContact({ + contactId: "contact_1", + campaignId: "campaign_1", + reason: UnsubscribeReason.UNSUBSCRIBED, + }), + ).rejects.toThrow("Failed to unsubscribe contact"); + + expect(vi.mocked(logger.error)).toHaveBeenCalledWith( + expect.objectContaining({ + contactId: "contact_1", + campaignId: "campaign_1", + reason: UnsubscribeReason.UNSUBSCRIBED, + }), + "Error unsubscribing contact", + ); + }); + + it("logs the campaign and the contact when the re-subscribe write fails", async () => { + mockDb.contact.findUnique.mockResolvedValue({ + id: "contact_1", + contactBookId: "book_1", + email: "alice@example.com", + subscribed: false, + }); + mockUpdateContactSubscription.mockRejectedValue(new Error("write failed")); + const id = "contact_1-campaign_1"; + const hash = createHash("sha256").update(`${id}-test-secret`).digest("hex"); + + await expect(subscribeContact(id, hash)).rejects.toThrow( + "Failed to subscribe contact", + ); + + expect(vi.mocked(logger.error)).toHaveBeenCalledWith( + expect.objectContaining({ + contactId: "contact_1", + campaignId: "campaign_1", + }), + "Error subscribing contact", + ); + }); + + it("logs the campaign and the team when scheduling cannot prepare the campaign content", async () => { + mockDb.campaign.findUnique.mockResolvedValue({ + id: "campaign_1", + teamId: 7, + content: null, + html: null, + }); + + await expect( + scheduleCampaign({ campaignId: "campaign_1", teamId: 7 }), + ).rejects.toThrow("No content added for campaign"); + + expect(vi.mocked(logger.error)).toHaveBeenCalledWith( + expect.objectContaining({ campaignId: "campaign_1", teamId: 7 }), + "Failed to prepare campaign content for scheduling", + ); + }); +}); diff --git a/apps/web/src/server/service/double-opt-in-service.ts b/apps/web/src/server/service/double-opt-in-service.ts index dbdf73715..2a72808c8 100644 --- a/apps/web/src/server/service/double-opt-in-service.ts +++ b/apps/web/src/server/service/double-opt-in-service.ts @@ -139,8 +139,9 @@ export async function sendDoubleOptInConfirmationEmail({ } catch (error) { logger.error( { - error, + err: error, contactBookId, + contactId, }, "[DoubleOptInService]: Failed to render custom template, using fallback HTML", ); diff --git a/apps/web/src/server/service/double-opt-in-service.unit.test.ts b/apps/web/src/server/service/double-opt-in-service.unit.test.ts index cb2ac3f52..d082afe7a 100644 --- a/apps/web/src/server/service/double-opt-in-service.unit.test.ts +++ b/apps/web/src/server/service/double-opt-in-service.unit.test.ts @@ -202,7 +202,14 @@ describe("double-opt-in-service", () => { const sendArgs = mockSendEmail.mock.calls[0]?.[0]; expect(sendArgs.html).toContain("Please confirm your subscription"); expect(sendArgs.html).toContain("contactId=contact_1"); - expect(mockLogger.error).toHaveBeenCalled(); + expect(mockLogger.error).toHaveBeenCalledWith( + expect.objectContaining({ + contactId: "contact_1", + contactBookId: "book_1", + err: expect.any(Error), + }), + "[DoubleOptInService]: Failed to render custom template, using fallback HTML", + ); }); it("replaces empty template variables instead of leaving tokens", async () => {