Aggregate function calls or named code blocks over a single frame. Like console.time/timeEnd but aggregated across many calls.

timePerFrame.ts

/* eslint-disable import/no-unused-modules */

/**

Usage:

// logs out the calls per frame, mean time, etc, under "myFunction"
const myFunction = instrumentPerFrame(function myFunction() {...});

// pass the name as the first parameter to wrap around methods and give them a name.
// if you don't do this, the name is the stringified function!
const object = {
  method: instrumentPerFrame("method", () => {...});
}

// you can use timePerFrame.start/end like console.time/timeEnd except it
// aggregates the accumulated time over all the calls in a frame.
function someOtherFunctionThatIsCalledALot() {
  timePerFrame.start("thing a");
  doThingA();
  anotherAThing();
  timePerFrame.end("thing a");

  timePerFrame.start("thing b");
  doThingB();
  anotherBThing();
  timePerFrame.end("thing b");
}
*/

// Record call usage per frame.
let isInstrumentingCalls = false;
type LoggingThreshold = {
  property: "count" | "time";
  value: number;
};

type TrackedCall = {
  key: string;
  threshold: LoggingThreshold;
  count: number;
  time: number;
  lastStartTimes: number[];
};
const calls: Map<string, TrackedCall> = new Map();
function logInstrumentedCalls() {
  const tableData: Record<
    string,
    { count: number; "total time (ms)": number; "mean time (ms)": number }
  > = {};
  for (const [, entry] of calls) {
    if (entry.lastStartTimes.length) {
      // eslint-disable-next-line no-console
      console.warn(
        `Unfinsihed timePerFrame.start("${entry.key}"). It looks like you forgot to call timePerFrame.end("${entry.key}").`
      );
      entry.lastStartTimes = [];
    }
    if (
      (entry.threshold.property === "count" &&
        entry.count > entry.threshold.value) ||
      (entry.threshold.property === "time" &&
        entry.time > entry.threshold.value)
    ) {
      tableData[entry.key] = {
        "total time (ms)": +entry.time.toFixed(5),
        "mean time (ms)": +(entry.time / entry.count).toFixed(5),
        count: entry.count,
      };
    }

    entry.count = 0;
    entry.time = 0;
  }

  if (Object.keys(tableData).length) {
    // eslint-disable-next-line no-console
    console.table(tableData);
  }

  if (logInstrumentedCalls) {
    window.requestAnimationFrame(logInstrumentedCalls);
  }
}

function getOrCreate(key: string, threshold?: TrackedCall["threshold"]) {
  const existing = calls.get(key);
  if (existing) return existing;

  const newCall: TrackedCall = {
    key,
    count: 0,
    time: 0,
    lastStartTimes: [],
    threshold: threshold ?? { property: "count", value: 0 },
  };
  calls.set(key, newCall);

  return newCall;
}

function startTrackingCall(key: string) {
  const trackEntry = getOrCreate(key);
  trackEntry.lastStartTimes.push(performance.now());
}

function endTrackingCall(key: string) {
  const trackEntry = getOrCreate(key);
  const start = trackEntry.lastStartTimes.pop();
  if (!start) {
    // eslint-disable-next-line no-console
    console.error(new Error("No tracking call found"));
    return;
  }

  trackEntry.count += 1;
  trackEntry.time += performance.now() - start;
}

function startInstrumenting() {
  if (!isInstrumentingCalls) {
    // eslint-disable-next-line no-console
    console.log("Starting instrumentation");
    isInstrumentingCalls = true;
    window.requestAnimationFrame(logInstrumentedCalls);
  }
}

// eslint-disable-next-line @typescript-eslint/no-explicit-any
type AnyFn = (this: any, ...args: any[]) => unknown;
type Options = {
  key?: string;
  threshold?: LoggingThreshold;
};

export function instrumentPerFrame<F extends AnyFn>(fn: F): F;
export function instrumentPerFrame<F extends AnyFn>(options: Options, fn: F): F;
export function instrumentPerFrame<F extends AnyFn>(key: string, fn: F): F;

export function instrumentPerFrame<F extends AnyFn>(
  fnOrOptions: F | Options | string,
  nothingOrFn?: typeof fnOrOptions extends AnyFn ? never : F
): F {
  startInstrumenting();
  const fn = nothingOrFn ?? (fnOrOptions as F);
  const options =
    typeof fnOrOptions === "function"
      ? {}
      : typeof fnOrOptions === "string"
      ? { key: fnOrOptions }
      : fnOrOptions;

  if (!options?.key && !fn.name) {
    // eslint-disable-next-line no-console
    console.warn(
      `Instrumented function does not have a name: ${fn
        .toString()
        .slice(0, 100)}`
    );
  }
  const key =
    options?.key ?? (fn.name || fn.toString().split("\n")[0]) ?? "(anonymous)";

  const alreadyInstrumented = calls.has(key);
  if (typeof fnOrOptions === "function" && alreadyInstrumented) {
    // eslint-disable-next-line no-console
    console.warn(
      `There is already an instrumented function with the key "${key}". This might be a mistake. If you really mean to instrument different functions under the same grouping, give them an explicit key by passing a key as the first parameter.`
    );
  }
  if (!alreadyInstrumented) {
    // eslint-disable-next-line no-console
    console.log(`Instrumenting ${calls.get(key)?.key}`);
    getOrCreate(key, options?.threshold);
  }

  return function (
    this: ThisParameterType<F>,
    ...args: Parameters<F>
  ): ReturnType<F> {
    startTrackingCall(key);
    const result = fn.apply(this, args) as ReturnType<F>;
    endTrackingCall(key);
    return result;
  } as F;
}

export const timePerFrame = {
  start: (key: string) => {
    startInstrumenting();
    startTrackingCall(key);
  },
  end: endTrackingCall,
};