buzz/desktop/src/shared/lib/channelSwitchPerf.test.mjs

import assert from "node:assert/strict";
import test from "node:test";

import {
  shouldAttributeFetch,
  buildSwitchPerfLogRecord,
  resolveSettleAction,
  resolveSettleWait,
  summarizeChannelSwitchTrace,
} from "./channelSwitchPerf.ts";

function trace(overrides = {}) {
  return {
    channelId: "abcdef1234567890",
    startedAt: 1_000,
    routeCommitAt: null,
    windowFetch: null,
    membersFetch: null,
    ...overrides,
  };
}

test("summary reports total and cache-served fetches", () => {
  const summary = summarizeChannelSwitchTrace(trace(), 1_412.4);
  assert.equal(
    summary,
    "[switch-perf] channel=abcdef12 total=412ms commit=? window=cache members=cache",
  );
});

test("summary includes route commit offset and fetch timings", () => {
  const summary = summarizeChannelSwitchTrace(
    trace({
      routeCommitAt: 1_038,
      windowFetch: { durationMs: 180.6, eventCount: 250 },
      membersFetch: { durationMs: 320.2, memberCount: 10_000 },
    }),
    1_912,
  );
  assert.equal(
    summary,
    "[switch-perf] channel=abcdef12 total=912ms commit=+38ms " +
      "window=250 events in 181ms members=10000 members in 320ms",
  );
});

test("log record carries rounded stage timings and fetch attributions", () => {
  const record = buildSwitchPerfLogRecord(
    trace({
      routeCommitAt: 1_038.4,
      windowFetch: { durationMs: 180.6, eventCount: 250 },
      membersFetch: { durationMs: 320.2, memberCount: 10_000 },
    }),
    1_912.3,
  );
  assert.equal(record.channelId, "abcdef1234567890");
  assert.equal(record.totalMs, 912);
  assert.equal(record.commitOffsetMs, 38);
  assert.deepEqual(record.windowFetch, { durationMs: 181, eventCount: 250 });
  assert.deepEqual(record.membersFetch, {
    durationMs: 320,
    memberCount: 10_000,
  });
  assert.equal(typeof record.ts, "string");
});

test("log record marks cache-served fetches and missing commit as null", () => {
  const record = buildSwitchPerfLogRecord(trace(), 1_412);
  assert.equal(record.commitOffsetMs, null);
  assert.equal(record.windowFetch, null);
  assert.equal(record.membersFetch, null);
});

test("settle resolves only the trace for the settled channel", () => {
  const active = trace();
  assert.deepEqual(resolveSettleAction(active, "abcdef1234567890", 2_000), {
    settledTrace: active,
    clearActive: true,
  });
  assert.deepEqual(resolveSettleAction(null, "abcdef1234567890", 2_000), {
    settledTrace: null,
    clearActive: false,
  });
});

test("a mismatched settle never clobbers a newer switch's trace", () => {
  // Channel A settles after the user already clicked channel B: B's trace
  // must survive so B still gets measured.
  const nextSwitch = trace({ channelId: "bbbb0000bbbb0000" });
  assert.deepEqual(resolveSettleAction(nextSwitch, "abcdef1234567890", 2_000), {
    settledTrace: null,
    clearActive: false,
  });
});

test("settle drops a trace that has timed out", () => {
  const stale = trace({ startedAt: 1_000 });
  assert.deepEqual(resolveSettleAction(stale, "abcdef1234567890", 31_001), {
    settledTrace: null,
    clearActive: true,
  });
  assert.deepEqual(
    resolveSettleAction(stale, "abcdef1234567890", 11_000).settledTrace,
    stale,
  );
});

test("the settle wait records truncated — never as an honest settle — at deadline", () => {
  // Still pending, before the deadline: keep waiting.
  assert.equal(resolveSettleWait(4_999, 5_000, true, 0), "wait");
  // Render caught up: record cleanly.
  assert.deepEqual(resolveSettleWait(1_000, 5_000, false, 0), {
    settleWaitTruncated: false,
  });
  // Deadline expired while still pending: the record must say so — a >5s
  // switch reported as an ordinary settle would hide exactly the tail this
  // tracer exists to expose.
  assert.deepEqual(resolveSettleWait(5_000, 5_000, true, 0), {
    settleWaitTruncated: true,
  });
});

test("a frame-starved trace is dropped, not recorded as a clean settle", () => {
  // rAF suspends in hidden windows, so a queued settle can fire minutes
  // after the click with renderPending long since false — the absence must
  // not be charged to the switch. Nothing legitimate can be older than the
  // 30s settle-entry timeout plus the 5s render wait.
  assert.equal(resolveSettleWait(35_001, 40_000, false, 0), "drop");
  assert.equal(resolveSettleWait(35_001, 40_000, true, 0), "drop");
  // At the bound (a 29.9s settle plus a truncated 5s wait) records survive.
  assert.deepEqual(resolveSettleWait(35_000, 34_900, true, 0), {
    settleWaitTruncated: true,
  });
});

test("a truncated settle is flagged in the summary and the log record", () => {
  const summary = summarizeChannelSwitchTrace(trace(), 1_412, true);
  assert.ok(summary.endsWith(" settle=truncated"), summary);
  const record = buildSwitchPerfLogRecord(trace(), 1_412, true);
  assert.equal(record.settleWaitTruncated, true);
  // Clean settles keep the field out of the line entirely.
  assert.ok(
    !("settleWaitTruncated" in buildSwitchPerfLogRecord(trace(), 1_412)),
  );
});

test("fetches attribute only when started after the switch began", () => {
  const active = trace({ channelId: "abcdef1234567890", startedAt: 1_000 });
  // Started before the switch (stale A→B→A leg): not attributable.
  assert.equal(shouldAttributeFetch(active, "abcdef1234567890", 999), false);
  // Started at/after the switch: attributable.
  assert.equal(shouldAttributeFetch(active, "abcdef1234567890", 1_000), true);
  assert.equal(shouldAttributeFetch(active, "abcdef1234567890", 1_500), true);
  // Other channel or no trace: never.
  assert.equal(shouldAttributeFetch(active, "bbbb0000bbbb0000", 1_500), false);
  assert.equal(shouldAttributeFetch(null, "abcdef1234567890", 1_500), false);
});

// --- Settle lifecycle: rapid switches and community resets ----------------

async function withSettleHarness(run, documentOverrides = {}) {
  const frames = [];
  const originalWindow = globalThis.window;
  const originalDocument = globalThis.document;
  globalThis.window = {
    requestAnimationFrame: (cb) => frames.push(cb) && frames.length,
    cancelAnimationFrame: () => {},
  };
  globalThis.document = {
    addEventListener: () => {},
    querySelector: () => null,
    removeEventListener: () => {},
    visibilityState: "visible",
    ...documentOverrides,
  };
  const {
    abandonChannelSwitchTrace,
    beginChannelSwitchTrace,
    cancelRouteExitAbandon,
    scheduleRouteExitAbandon,
    settleChannelSwitchTrace,
    resetChannelSwitchTrace,
    CHANNEL_SWITCH_MEASURE,
  } = await import("./channelSwitchPerf.ts");
  performance.clearMeasures?.(CHANNEL_SWITCH_MEASURE);
  const flush = () => {
    // Drain chained rAFs until quiescent.
    for (let i = 0; i < 20 && frames.length > 0; i += 1) {
      for (const cb of frames.splice(0, frames.length)) cb();
    }
  };
  const measures = () =>
    performance
      .getEntriesByName(CHANNEL_SWITCH_MEASURE)
      .map((entry) => entry.detail?.channelId);
  try {
    await run({
      abandon: abandonChannelSwitchTrace,
      begin: beginChannelSwitchTrace,
      cancelAbandon: cancelRouteExitAbandon,
      scheduleAbandon: scheduleRouteExitAbandon,
      settle: settleChannelSwitchTrace,
      reset: resetChannelSwitchTrace,
      flush,
      measures,
    });
  } finally {
    resetChannelSwitchTrace();
    performance.clearMeasures?.(CHANNEL_SWITCH_MEASURE);
    if (originalWindow === undefined) delete globalThis.window;
    else globalThis.window = originalWindow;
    if (originalDocument === undefined) delete globalThis.document;
    else globalThis.document = originalDocument;
  }
}

test("a switch begun during A's deferred wait drops A's record (no clock theft)", async () => {
  await withSettleHarness(async ({ begin, settle, flush, measures }) => {
    begin("aaaa1111aaaa1111");
    settle("aaaa1111aaaa1111"); // A's deferred-paint wait is now queued
    begin("bbbb2222bbbb2222"); // rapid follow-up switch replaces the trace
    flush();
    // A must NOT be recorded: its settledAt would be sampled from B's
    // timeline, charging B's delay to A.
    assert.deepEqual(measures(), []);
    settle("bbbb2222bbbb2222");
    flush();
    assert.deepEqual(measures(), ["bbbb2222bbbb2222"]);
  });
});

test("a community reset during the deferred wait drops the record", async () => {
  await withSettleHarness(async ({ begin, settle, reset, flush, measures }) => {
    begin("aaaa1111aaaa1111");
    settle("aaaa1111aaaa1111");
    reset();
    flush();
    assert.deepEqual(measures(), []);
  });
});

test("an undisturbed settle records exactly one measure", async () => {
  await withSettleHarness(async ({ begin, settle, flush, measures }) => {
    begin("aaaa1111aaaa1111");
    settle("aaaa1111aaaa1111");
    flush();
    assert.deepEqual(measures(), ["aaaa1111aaaa1111"]);
  });
});

test("a settle in a hidden window drops the trace instead of recording", async () => {
  await withSettleHarness(
    async ({ begin, settle, flush, measures }) => {
      begin("aaaa1111aaaa1111");
      // rAF is suspended while hidden; the queued chain would only fire when
      // the user returns, charging the whole absence to the switch.
      settle("aaaa1111aaaa1111");
      flush();
      assert.deepEqual(measures(), []);
      // The trace was released, not wedged: a later stale settle is a no-op.
      settle("aaaa1111aaaa1111");
      flush();
      assert.deepEqual(measures(), []);
    },
    { visibilityState: "hidden" },
  );
});

test("a window hidden during the settle wait drops the record", async () => {
  const visibilityListeners = [];
  await withSettleHarness(
    async ({ begin, settle, flush, measures }) => {
      begin("aaaa1111aaaa1111");
      settle("aaaa1111aaaa1111");
      assert.equal(visibilityListeners.length, 1, "wait registers a listener");
      // The user cmd-tabs away mid-wait; frames resume only on return.
      visibilityListeners[0]();
      flush();
      assert.deepEqual(measures(), []);
    },
    {
      addEventListener: (type, listener) => {
        if (type === "visibilitychange") visibilityListeners.push(listener);
      },
    },
  );
});

test("a scheduled route-exit abandon canceled in the same task keeps the trace", async () => {
  await withSettleHarness(
    async ({
      begin,
      cancelAbandon,
      scheduleAbandon,
      settle,
      flush,
      measures,
    }) => {
      begin("aaaa1111aaaa1111");
      // StrictMode's dev-only effect replay: cleanup schedules the abandon,
      // the synchronous re-setup cancels it before the microtask runs.
      scheduleAbandon("aaaa1111aaaa1111");
      cancelAbandon("aaaa1111aaaa1111");
      await Promise.resolve();
      settle("aaaa1111aaaa1111");
      flush();
      assert.deepEqual(measures(), ["aaaa1111aaaa1111"]);
    },
  );
});

test("an uncanceled route-exit abandon drops the trace before any frame fires", async () => {
  await withSettleHarness(
    async ({ begin, scheduleAbandon, settle, flush, measures }) => {
      begin("aaaa1111aaaa1111");
      scheduleAbandon("aaaa1111aaaa1111");
      await Promise.resolve();
      settle("aaaa1111aaaa1111");
      flush();
      assert.deepEqual(measures(), []);
    },
  );
});

test("leaving the channel surface abandons the trace; history-back records nothing", async () => {
  await withSettleHarness(
    async ({ abandon, begin, settle, flush, measures }) => {
      begin("aaaa1111aaaa1111");
      // Route exit (Projects/Home): the channel screen unmounts before the
      // trace settled and abandons it.
      abandon("aaaa1111aaaa1111");
      // History-back re-enters the channel without goChannel; its settle must
      // find no trace — otherwise the time spent away would be recorded as
      // switch latency.
      settle("aaaa1111aaaa1111");
      flush();
      assert.deepEqual(measures(), []);
    },
  );
});