From 1ddcffc51156d9bea3c55bb6963c6cd41629fb96 Mon Sep 17 00:00:00 2001 From: yohlo Date: Tue, 25 Aug 2026 23:26:34 -0700 Subject: [PATCH] fix(telemetry): review findings - wau/mau trailing scans run hourly and on day finalization, not every tick - exclusion lookup failures cached 30s so an st outage cannot amplify - unverified relation filter dropped; player emptiness checked in js - anonymous unauthenticated read failures no longer logged - alerts and exclusions ensure supertokens init on cold pods --- src/lib/telemetry/alerts.server.ts | 2 ++ src/lib/telemetry/exclusions.server.ts | 6 +++++ src/lib/telemetry/rollup-core.test.ts | 12 +++++++++ src/lib/telemetry/rollup-core.ts | 8 +++--- src/lib/telemetry/rollup.server.ts | 31 +++++++++++++++------- src/lib/telemetry/scheduler.server.ts | 7 ++++- src/utils/activities.test.ts | 36 ++++++++++++++++++++++++++ src/utils/activities.ts | 6 +++++ 8 files changed, 93 insertions(+), 15 deletions(-) diff --git a/src/lib/telemetry/alerts.server.ts b/src/lib/telemetry/alerts.server.ts index eb0863b..95b8138 100644 --- a/src/lib/telemetry/alerts.server.ts +++ b/src/lib/telemetry/alerts.server.ts @@ -31,6 +31,8 @@ const getAdminPlayerIds = async (): Promise => { return adminPlayersCache.playerIds; } + const { ensureSuperTokensBackend } = await import("@/lib/supertokens/server"); + ensureSuperTokensBackend(); const UserRoles = (await import("supertokens-node/recipe/userroles")).default; const response = await UserRoles.getUsersThatHaveRole("public", ADMIN_ROLE); const users = response.status === "OK" ? response.users : []; diff --git a/src/lib/telemetry/exclusions.server.ts b/src/lib/telemetry/exclusions.server.ts index c25dc7c..e95ad68 100644 --- a/src/lib/telemetry/exclusions.server.ts +++ b/src/lib/telemetry/exclusions.server.ts @@ -3,6 +3,7 @@ import { Logger } from "@/lib/logger"; const logger = new Logger("Telemetry"); const CACHE_TTL_MS = 10 * 60 * 1000; +const FAILURE_TTL_MS = 30 * 1000; const normalizePhone = (phone: string): string => phone.replace(/[^\d+]/g, ""); @@ -26,6 +27,8 @@ export const getExcludedPlayerIds = async (): Promise> => { if (phones.length > 0) { try { + const { ensureSuperTokensBackend } = await import("@/lib/supertokens/server"); + ensureSuperTokensBackend(); const SuperTokens = (await import("supertokens-node")).default; const { pbAdmin } = await import("@/lib/pocketbase/client"); for (const phoneNumber of phones) { @@ -37,6 +40,9 @@ export const getExcludedPlayerIds = async (): Promise> => { } } catch (error) { logger.error("Failed to resolve telemetry exclusions", error); + // Short-lived failure cache: an outage must not amplify into a + // per-request SuperTokens lookup storm. + cache = { playerIds, expiresAt: now + FAILURE_TTL_MS }; return playerIds; } } diff --git a/src/lib/telemetry/rollup-core.test.ts b/src/lib/telemetry/rollup-core.test.ts index 1267578..01d727c 100644 --- a/src/lib/telemetry/rollup-core.test.ts +++ b/src/lib/telemetry/rollup-core.test.ts @@ -95,6 +95,18 @@ describe("buildDayRollups", () => { } }); + it("omits wau/mau rows when trailing scans were skipped", () => { + const rollups = buildDayRollups("2026-08-25", { + activities: newActivityAccumulator(), + clientEvents: newClientEventAccumulator(), + clientErrors: newClientErrorAccumulator(), + partial: true, + }); + expect(rollupFor(rollups, "wau")).toBeUndefined(); + expect(rollupFor(rollups, "mau")).toBeUndefined(); + expect(rollupFor(rollups, "dau")?.value).toBe(0); + }); + it("marks partial days and is deterministic across re-runs", () => { const build = () => buildDayRollups("2026-08-25", { diff --git a/src/lib/telemetry/rollup-core.ts b/src/lib/telemetry/rollup-core.ts index 22a91aa..ed8ec3a 100644 --- a/src/lib/telemetry/rollup-core.ts +++ b/src/lib/telemetry/rollup-core.ts @@ -113,8 +113,8 @@ export const buildDayRollups = ( activities: ActivityAccumulator; clientEvents: ClientEventAccumulator; clientErrors: ClientErrorAccumulator; - wau: number; - mau: number; + wau?: number; + mau?: number; partial: boolean; } ): RollupInput[] => { @@ -133,8 +133,8 @@ export const buildDayRollups = ( const dayPlayers = new Set([...activities.players, ...clientEvents.players]); push("dau", "", dayPlayers.size); - push("wau", "", wau); - push("mau", "", mau); + if (wau !== undefined) push("wau", "", wau); + if (mau !== undefined) push("mau", "", mau); for (const [name, fn] of activities.perFn) { push("server_fn.count", name, fn.count); diff --git a/src/lib/telemetry/rollup.server.ts b/src/lib/telemetry/rollup.server.ts index 579e1f1..756c67d 100644 --- a/src/lib/telemetry/rollup.server.ts +++ b/src/lib/telemetry/rollup.server.ts @@ -30,7 +30,7 @@ const dayFilter = (dateStr: string): string => const distinctPlayersInWindow = async (fromDate: string, toDateExclusive: string): Promise => { const players = new Set(); - const filter = `created >= '${bound(fromDate)}' && created < '${bound(toDateExclusive)}' && player != ''`; + const filter = `created >= '${bound(fromDate)}' && created < '${bound(toDateExclusive)}'`; await pbAdmin.pageCollection<{ player?: string }>("activities", { filter, fields: "player,created" }, (rows) => { for (const row of rows) if (row.player) players.add(row.player); @@ -42,7 +42,10 @@ const distinctPlayersInWindow = async (fromDate: string, toDateExclusive: string return players.size; }; -export const runRollups = async (dateStr: string): Promise => { +export const runRollups = async ( + dateStr: string, + opts: { trailing?: boolean } = {} +): Promise => { await pbAdmin.authPromise; const activities = newActivityAccumulator(); @@ -65,11 +68,16 @@ export const runRollups = async (dateStr: string): Promise => { (rows) => accumulateClientErrors(clientErrors, rows) ); - const nextDay = addDays(dateStr, 1); - const [wau, mau] = await Promise.all([ - distinctPlayersInWindow(addDays(dateStr, -6), nextDay), - distinctPlayersInWindow(addDays(dateStr, -29), nextDay), - ]); + // Trailing scans re-read the full 7/30-day windows; hourly at most. + let wau: number | undefined; + let mau: number | undefined; + if (opts.trailing !== false) { + const nextDay = addDays(dateStr, 1); + [wau, mau] = await Promise.all([ + distinctPlayersInWindow(addDays(dateStr, -6), nextDay), + distinctPlayersInWindow(addDays(dateStr, -29), nextDay), + ]); + } const partial = dateStr >= utcDay(new Date()); const rollups = buildDayRollups(dateStr, { @@ -89,11 +97,14 @@ export const runRollups = async (dateStr: string): Promise => { return rollups.length; }; -export const runScheduledRollups = async (lastRunDay?: string): Promise => { +export const runScheduledRollups = async ( + lastRunDay: string | undefined, + opts: { trailing?: boolean } = {} +): Promise => { const today = utcDay(new Date()); if (lastRunDay && lastRunDay !== today) { - await runRollups(lastRunDay); + await runRollups(lastRunDay, { trailing: true }); } - await runRollups(today); + await runRollups(today, opts); return today; }; diff --git a/src/lib/telemetry/scheduler.server.ts b/src/lib/telemetry/scheduler.server.ts index b19cd57..e950f3d 100644 --- a/src/lib/telemetry/scheduler.server.ts +++ b/src/lib/telemetry/scheduler.server.ts @@ -6,6 +6,7 @@ const logger = new Logger("Telemetry"); const ROLLUP_INTERVAL_MS = 15 * 60 * 1000; const ALERT_INTERVAL_MS = 5 * 60 * 1000; +const TRAILING_INTERVAL_MS = 60 * 60 * 1000; interface SchedulerStatus { running: boolean; @@ -21,12 +22,16 @@ let initialized = false; let rollupInFlight = false; let alertsInFlight = false; let lastRollupDay: string | undefined; +let lastTrailingAt = 0; const tickRollups = async () => { if (rollupInFlight) return; rollupInFlight = true; try { - lastRollupDay = await runScheduledRollups(lastRollupDay); + const now = Date.now(); + const trailing = now - lastTrailingAt >= TRAILING_INTERVAL_MS; + lastRollupDay = await runScheduledRollups(lastRollupDay, { trailing }); + if (trailing) lastTrailingAt = now; status.lastRollupAt = new Date().toISOString(); status.lastRollupError = undefined; } catch (error) { diff --git a/src/utils/activities.test.ts b/src/utils/activities.test.ts index ae18c22..08c6b9a 100644 --- a/src/utils/activities.test.ts +++ b/src/utils/activities.test.ts @@ -308,6 +308,42 @@ describe("serverFnLoggingMiddleware control flow and dedup", () => { expect(h.createActivity.mock.calls[0][0].error).toContain("FORBIDDEN"); }); + it("does not record anonymous Unauthenticated failures", async () => { + setRequest("http://localhost:3000/_serverFn/x"); + + await expect( + runMiddleware({ + next: async () => { + throw new Error("Unauthenticated"); + }, + data: undefined, + context: {}, + serverFnMeta: { id: "x", name: "fetchMe" }, + }) + ).rejects.toThrow("Unauthenticated"); + + await flushWrites(); + expect(h.createActivity).not.toHaveBeenCalled(); + }); + + it("still records Unauthenticated failures for identified actors", async () => { + setRequest("http://localhost:3000/_serverFn/x"); + setRequestActor(h.request as unknown as Request, { playerId: "p1" }); + + await expect( + runMiddleware({ + next: async () => { + throw new Error("Unauthenticated"); + }, + data: undefined, + context: {}, + serverFnMeta: { id: "x", name: "fetchMe" }, + }) + ).rejects.toThrow("Unauthenticated"); + + await vi.waitFor(() => expect(h.createActivity).toHaveBeenCalledTimes(1)); + }); + it("does not record activity for excluded players", async () => { setRequest("http://localhost:3000/_serverFn/doThing"); setRequestActor(h.request as unknown as Request, { playerId: "excluded-player" }); diff --git a/src/utils/activities.ts b/src/utils/activities.ts index 5490a8d..f1a6d76 100644 --- a/src/utils/activities.ts +++ b/src/utils/activities.ts @@ -129,6 +129,12 @@ export const serverFnLoggingMiddleware = createMiddleware({ const duration = Date.now() - startTime; const errorMessage = error instanceof Error ? error.message : String(error); + // Anonymous visitors (crawlers included) hitting authed reads are noise, + // not failures worth a row each. + if (errorMessage === "Unauthenticated" && !resolveActor()) { + throw error; + } + recordActivity({ name, player: resolveActor(),