diff --git a/packages/studio/src/utils/sdkResolverShadow.test.ts b/packages/studio/src/utils/sdkResolverShadow.test.ts index 71ceaba2f0..6274ed6029 100644 --- a/packages/studio/src/utils/sdkResolverShadow.test.ts +++ b/packages/studio/src/utils/sdkResolverShadow.test.ts @@ -1,10 +1,14 @@ -import { describe, expect, it, vi, beforeEach } from "vitest"; +// @vitest-environment happy-dom +import { describe, expect, it, vi, beforeEach, afterEach } from "vitest"; import { sdkResolverShadowCheck, runResolverShadow, recordResolverParity, recordAnimationResolverParity, evaluateSoakGate, + recordAttempt, + flushAttemptCounts, + __resetAttemptSchedulingForTests, type SdkResolverMismatch, } from "./sdkResolverShadow"; import type { PatchOperation } from "./sourcePatcher"; @@ -13,12 +17,15 @@ import { openComposition } from "@hyperframes/sdk"; // ─── Telemetry capture ──────────────────────────────────────────────────────── const trackedEvents: Array<{ event: string; props: Record }> = []; +const flushViaBeacon = vi.fn(); vi.mock("./studioTelemetry", () => ({ trackStudioEvent: (event: string, props: Record) => trackedEvents.push({ event, props }), + flushViaBeacon: () => flushViaBeacon(), })); beforeEach(() => { trackedEvents.length = 0; + flushViaBeacon.mockClear(); }); const lastShadow = () => trackedEvents.filter((e) => e.event === "sdk_resolver_shadow").at(-1)?.props; @@ -532,3 +539,175 @@ describe("H. inlined sub-composition leaf", () => { expect(mismatches.some((m) => m.kind === "element_not_found")).toBe(false); }); }); + +// ─── I. Attempt counter (denominator for the soak gate) ─────────────────────── + +describe("I. recordAttempt / flushAttemptCounts", () => { + beforeEach(() => { + // Drain any counts left over from a prior test so each test starts clean. + flushAttemptCounts(); + }); + + it("flushAttemptCounts returns null when nothing has been recorded", () => { + expect(flushAttemptCounts()).toBeNull(); + }); + + it("increments the counter for a given op label", () => { + recordAttempt("setTiming"); + expect(flushAttemptCounts()).toEqual({ setTiming: 1 }); + }); + + it("accumulates multiple calls with the same label", () => { + recordAttempt("setTiming"); + recordAttempt("setTiming"); + recordAttempt("setTiming"); + expect(flushAttemptCounts()).toEqual({ setTiming: 3 }); + }); + + it("tracks different labels independently", () => { + recordAttempt("setTiming"); + recordAttempt("addGsapTween"); + recordAttempt("setTiming"); + expect(flushAttemptCounts()).toEqual({ setTiming: 2, addGsapTween: 1 }); + }); + + it("resets to empty after a flush", () => { + recordAttempt("setTiming"); + flushAttemptCounts(); + expect(flushAttemptCounts()).toBeNull(); + }); +}); + +describe("I. attempt counting inside the three emit functions", () => { + beforeEach(() => { + flushAttemptCounts(); + }); + + it("runResolverShadow counts an attempt on the parity (silent) path", async () => { + mockFlags.STUDIO_SDK_RESOLVER_SHADOW_ENABLED = true; + const session = await openComposition(BASE_HTML); + runResolverShadow(session, "hf-box", [ + { type: "inline-style", property: "color", value: "blue" }, + ]); + expect(flushAttemptCounts()).toEqual({ "dom-edit": 1 }); + expect(trackedEvents.filter((e) => e.event === "sdk_resolver_shadow")).toHaveLength(0); + }); + + it("runResolverShadow counts an attempt on the divergence (emits) path too", async () => { + mockFlags.STUDIO_SDK_RESOLVER_SHADOW_ENABLED = true; + const session = await openComposition(BASE_HTML); + runResolverShadow(session, "hf-missing", [ + { type: "inline-style", property: "color", value: "blue" }, + ]); + expect(flushAttemptCounts()).toEqual({ "dom-edit": 1 }); + expect(trackedEvents.filter((e) => e.event === "sdk_resolver_shadow")).toHaveLength(1); + }); + + it("recordResolverParity counts an attempt on the parity (silent) path", async () => { + mockFlags.STUDIO_SDK_RESOLVER_SHADOW_ENABLED = true; + const session = await openComposition(BASE_HTML); + await recordResolverParity(session, "hf-box", "setTiming"); + expect(flushAttemptCounts()).toEqual({ setTiming: 1 }); + }); + + it("recordResolverParity counts an attempt on the divergence (emits) path too", async () => { + mockFlags.STUDIO_SDK_RESOLVER_SHADOW_ENABLED = true; + const session = await openComposition(BASE_HTML); + await recordResolverParity(session, "hf-missing", "setTiming"); + expect(flushAttemptCounts()).toEqual({ setTiming: 1 }); + }); + + it("recordAnimationResolverParity counts an attempt on the parity (silent) path", async () => { + mockFlags.STUDIO_SDK_RESOLVER_SHADOW_ENABLED = true; + const session = await openComposition(GSAP_HTML); + const realId = session.getElements().flatMap((e) => [...e.animationIds])[0] ?? ""; + expect(realId).not.toBe(""); // fixture has a tween on hf-box, see block G above + recordAnimationResolverParity(session, realId, "removeGsapTween"); + expect(flushAttemptCounts()).toEqual({ removeGsapTween: 1 }); + expect(trackedEvents.filter((e) => e.event === "sdk_resolver_shadow")).toHaveLength(0); + }); + + it("recordAnimationResolverParity counts an attempt on the divergence (emits) path too", async () => { + mockFlags.STUDIO_SDK_RESOLVER_SHADOW_ENABLED = true; + const session = await openComposition(GSAP_HTML); + recordAnimationResolverParity(session, "no-such-anim", "setGsapTween"); + expect(flushAttemptCounts()).toEqual({ setGsapTween: 1 }); + expect(trackedEvents.filter((e) => e.event === "sdk_resolver_shadow")).toHaveLength(1); + }); + + it("counts accumulate across multiple different chokepoints in one rollup", async () => { + mockFlags.STUDIO_SDK_RESOLVER_SHADOW_ENABLED = true; + const session = await openComposition(BASE_HTML); + await recordResolverParity(session, "hf-box", "setTiming"); + await recordResolverParity(session, "hf-box", "setTiming"); + recordAnimationResolverParity(session, "no-such-anim", "setGsapTween"); + expect(flushAttemptCounts()).toEqual({ setTiming: 2, setGsapTween: 1 }); + }); + + it("does not count an attempt when the flag is off", async () => { + mockFlags.STUDIO_SDK_RESOLVER_SHADOW_ENABLED = false; + const session = await openComposition(BASE_HTML); + runResolverShadow(session, "hf-box", [ + { type: "inline-style", property: "color", value: "blue" }, + ]); + await recordResolverParity(session, "hf-box", "setTiming"); + recordAnimationResolverParity(session, "no-such-anim", "setGsapTween"); + expect(flushAttemptCounts()).toBeNull(); + }); +}); + +describe("I. production rollup wiring", () => { + beforeEach(() => { + flushAttemptCounts(); + __resetAttemptSchedulingForTests(); + vi.useFakeTimers({ toFake: ["setTimeout", "setInterval", "clearInterval", "clearTimeout"] }); + }); + + afterEach(() => { + __resetAttemptSchedulingForTests(); + vi.useRealTimers(); + Object.defineProperty(document, "visibilityState", { value: "visible", configurable: true }); + }); + + it("does not emit a rollup event when nothing was recorded", () => { + mockFlags.STUDIO_SDK_RESOLVER_SHADOW_ENABLED = true; + vi.advanceTimersByTime(5 * 60_000); + expect(trackedEvents.filter((e) => e.event === "sdk_resolver_shadow_attempt")).toHaveLength(0); + }); + + it("emits a sdk_resolver_shadow_attempt rollup event every 5 minutes after the first attempt", async () => { + mockFlags.STUDIO_SDK_RESOLVER_SHADOW_ENABLED = true; + const session = await openComposition(BASE_HTML); + await recordResolverParity(session, "hf-box", "setTiming"); + vi.advanceTimersByTime(5 * 60_000); + const rollups = trackedEvents.filter((e) => e.event === "sdk_resolver_shadow_attempt"); + expect(rollups).toHaveLength(1); + expect(rollups[0].props.counts).toBe(JSON.stringify({ setTiming: 1 })); + }); + + it("flushes a rollup and forces a beacon delivery on visibilitychange -> hidden", async () => { + mockFlags.STUDIO_SDK_RESOLVER_SHADOW_ENABLED = true; + const session = await openComposition(BASE_HTML); + await recordResolverParity(session, "hf-box", "setTiming"); + Object.defineProperty(document, "visibilityState", { value: "hidden", configurable: true }); + document.dispatchEvent(new Event("visibilitychange")); + const rollups = trackedEvents.filter((e) => e.event === "sdk_resolver_shadow_attempt"); + expect(rollups).toHaveLength(1); + expect(rollups[0].props.counts).toBe(JSON.stringify({ setTiming: 1 })); + // Delivery must not depend on studioTelemetry's own visibilitychange listener + // winning a race — this module forces its own beacon flush. + expect(flushViaBeacon).toHaveBeenCalledTimes(1); + }); + + it("does not register a duplicate visibilitychange listener after a scheduling reset", async () => { + mockFlags.STUDIO_SDK_RESOLVER_SHADOW_ENABLED = true; + const session = await openComposition(BASE_HTML); + await recordResolverParity(session, "hf-box", "setTiming"); + __resetAttemptSchedulingForTests(); + await recordResolverParity(session, "hf-box", "setTiming"); // re-arms scheduling, incl. listener + Object.defineProperty(document, "visibilityState", { value: "hidden", configurable: true }); + document.dispatchEvent(new Event("visibilitychange")); + // If the reset had leaked the old listener, this would fire twice. + expect(flushViaBeacon).toHaveBeenCalledTimes(1); + }); +}); diff --git a/packages/studio/src/utils/sdkResolverShadow.ts b/packages/studio/src/utils/sdkResolverShadow.ts index 537a1e3b60..56c9724f77 100644 --- a/packages/studio/src/utils/sdkResolverShadow.ts +++ b/packages/studio/src/utils/sdkResolverShadow.ts @@ -19,7 +19,7 @@ import type { Composition, JsonPatchOp } from "@hyperframes/sdk"; import type { PatchOperation } from "./sourcePatcher"; import { STUDIO_SDK_RESOLVER_SHADOW_ENABLED } from "../components/editor/manualEditingAvailability"; import { patchOpsToSdkEditOps } from "./sdkOpMapping"; -import { trackStudioEvent } from "./studioTelemetry"; +import { trackStudioEvent, flushViaBeacon } from "./studioTelemetry"; // ─── Types ──────────────────────────────────────────────────────────────────── @@ -229,6 +229,96 @@ export function sdkResolverShadowCheck( } } +// ─── Attempt counter (denominator for the soak gate) ────────────────────────── +// +// The three emit functions below only fire a PostHog event on divergence — +// parity is silent, by design, to avoid firing on every edit. That leaves no +// way to compute a rate (divergences / attempts): we can count failures but +// never attempts. This counter tracks attempts in memory and rolls them up +// into ONE low-frequency event instead of firing per-attempt, which would +// recreate the exact chattiness problem the divergence-only design avoids. + +const attemptCounts: Record = {}; + +/** + * Record that the resolver-shadow tripwire ran for `opLabel`, regardless of + * outcome (parity or divergence). No flag check of its own — only ever called + * from inside the three emit functions below, after their own + * STUDIO_SDK_RESOLVER_SHADOW_ENABLED guard, so it's already flag-gated. + */ +export function recordAttempt(opLabel: string): void { + attemptCounts[opLabel] = (attemptCounts[opLabel] ?? 0) + 1; + ensureAttemptFlushScheduled(); +} + +/** + * Return the accumulated attempt counts since the last flush (or `null` if + * nothing has been recorded — no point emitting an empty rollup), and reset + * the counter to empty. + */ +export function flushAttemptCounts(): Record | null { + const keys = Object.keys(attemptCounts); + if (keys.length === 0) return null; + const snapshot: Record = {}; + for (const key of keys) { + snapshot[key] = attemptCounts[key]; + delete attemptCounts[key]; + } + return snapshot; +} + +const ATTEMPT_FLUSH_INTERVAL_MS = 5 * 60_000; +let attemptFlushTimer: ReturnType | null = null; +let attemptVisibilityHandler: (() => void) | null = null; + +function flushAndEmitAttempts(): void { + const counts = flushAttemptCounts(); + if (counts === null) return; + trackStudioEvent("sdk_resolver_shadow_attempt", { counts: JSON.stringify(counts) }); +} + +// Lazily starts the rollup timer + visibilitychange listener on the FIRST +// attempt in a session — mirrors studioTelemetry.ts's own lazy flushTimer +// start, so a session that never exercises the tripwire never runs a +// background timer. +function ensureAttemptFlushScheduled(): void { + if (!attemptFlushTimer) { + attemptFlushTimer = setInterval(flushAndEmitAttempts, ATTEMPT_FLUSH_INTERVAL_MS); + } + if (!attemptVisibilityHandler && typeof document !== "undefined") { + attemptVisibilityHandler = () => { + if (document.visibilityState !== "hidden") return; + flushAndEmitAttempts(); + // studioTelemetry.ts registers its own visibilitychange listener (on + // window, at module load) that drains its queue via sendBeacon. Listener + // execution order between that handler and this one (on document, + // registered lazily) is not something to rely on — whichever runs + // first could otherwise beacon-flush before or after this rollup lands + // in the queue. Forcing a beacon flush here makes delivery of this + // rollup event correct regardless of that order. + flushViaBeacon(); + }; + document.addEventListener("visibilitychange", attemptVisibilityHandler); + } +} + +/** + * Test-only: clears the lazy timer/listener singleton state so tests can + * verify the "starts on first attempt" behavior in isolation, without an + * earlier test's real-timer interval (or visibilitychange listener) silently + * surviving into a later test. Does NOT touch attemptCounts — only the + * scheduling state. Not part of the public module contract; only imported + * from sdkResolverShadow.test.ts. + */ +export function __resetAttemptSchedulingForTests(): void { + if (attemptFlushTimer) clearInterval(attemptFlushTimer); + attemptFlushTimer = null; + if (attemptVisibilityHandler && typeof document !== "undefined") { + document.removeEventListener("visibilitychange", attemptVisibilityHandler); + } + attemptVisibilityHandler = null; +} + // ─── Telemetry ──────────────────────────────────────────────────────────────── // Redact all user-content values before telemetry: style values and text both @@ -266,6 +356,7 @@ export function runResolverShadow( if (!STUDIO_SDK_RESOLVER_SHADOW_ENABLED) return; if (!hfId) return; try { + recordAttempt("dom-edit"); const mismatches = sdkResolverShadowCheck(session, hfId, ops, sourceContent); // Emit only on divergence — parity is silent, matching recordResolverParity // and recordAnimationResolverParity. Otherwise this fires a PostHog event on @@ -318,6 +409,7 @@ export async function recordResolverParity( if (!STUDIO_SDK_RESOLVER_SHADOW_ENABLED) return; if (!session || !hfId) return; try { + recordAttempt(opLabel); if (resolveSnapshot(session, hfId)) return; // resolves — parity, nothing to record // Capture BEFORE any await: this call is fire-and-forget (`void recordResolverParity(...)`) // and the caller runs its own session mutation synchronously right after this call @@ -380,6 +472,7 @@ export function recordAnimationResolverParity( if (!STUDIO_SDK_RESOLVER_SHADOW_ENABLED) return; if (!session || !animationId) return; try { + recordAttempt(opLabel); const elements = session.getElements(); const resolves = elements.some((el) => el.animationIds.includes(animationId)); if (resolves) return; // SDK locates the animation — parity diff --git a/packages/studio/src/utils/studioTelemetry.ts b/packages/studio/src/utils/studioTelemetry.ts index 49406bb078..d72b148209 100644 --- a/packages/studio/src/utils/studioTelemetry.ts +++ b/packages/studio/src/utils/studioTelemetry.ts @@ -90,27 +90,34 @@ async function flushEvents(): Promise { } } +// Synchronously drains the queue via sendBeacon — safe to call from any +// tab-hide handler regardless of listener registration order. Exported so +// other modules (e.g. sdkResolverShadow.ts) can force delivery of an event +// they just queued without racing this module's own visibilitychange +// listener below. +export function flushViaBeacon(): void { + if (flushTimer) { + clearInterval(flushTimer); + flushTimer = null; + } + if (queue.length === 0) return; + const batch = queue.map((e) => ({ + event: e.event, + properties: { ...e.properties, $ip: null }, + distinct_id: getDistinctId(), + timestamp: e.timestamp, + })); + queue = []; + const body = JSON.stringify({ api_key: POSTHOG_API_KEY, batch }); + try { + navigator.sendBeacon(`${POSTHOG_HOST}/batch/`, body); + } catch { + // best-effort + } +} + if (typeof window !== "undefined") { window.addEventListener("visibilitychange", () => { - if (document.visibilityState === "hidden") { - if (flushTimer) { - clearInterval(flushTimer); - flushTimer = null; - } - if (queue.length === 0) return; - const batch = queue.map((e) => ({ - event: e.event, - properties: { ...e.properties, $ip: null }, - distinct_id: getDistinctId(), - timestamp: e.timestamp, - })); - queue = []; - const body = JSON.stringify({ api_key: POSTHOG_API_KEY, batch }); - try { - navigator.sendBeacon(`${POSTHOG_HOST}/batch/`, body); - } catch { - // best-effort - } - } + if (document.visibilityState === "hidden") flushViaBeacon(); }); }