performance - track calling stats when QUARTO_REPORT_PERFORMANCE_METRICS is set

Author: cscheid

src/core/main.ts

@@ -12,7 +12,9 @@ import { parse } from "flags";
 import { exitWithCleanup } from "./cleanup.ts";
 import {
   captureFileReads,
-  reportPeformanceMetrics,
+  makeTimedFunctionAsync,
+  type MetricsKeys,
+  reportPerformanceMetrics,
 } from "./performance/metrics.ts";
 import { isWindows } from "../deno_ral/platform.ts";
 
@@ -33,7 +35,10 @@ export async function mainRunner(runner: Runner) {
       captureFileReads();
     }
 
-    await runner(args);
+    const main = makeTimedFunctionAsync("main", async () => {
+      return await runner(args);
+    });
+    await main();
 
     // if profiling, wait for 10 seconds before quitting
     if (Deno.env.get("QUARTO_TS_PROFILE") !== undefined) {
@@ -42,8 +47,13 @@ export async function mainRunner(runner: Runner) {
       await new Promise((resolve) => setTimeout(resolve, 10000));
     }
 
-    if (Deno.env.get("QUARTO_REPORT_PERFORMANCE_METRICS") !== undefined) {
-      reportPeformanceMetrics();
+    const metricEnv = Deno.env.get("QUARTO_REPORT_PERFORMANCE_METRICS");
+    if (metricEnv !== undefined) {
+      if (metricEnv !== "true") {
+        reportPerformanceMetrics(metricEnv.split(",") as MetricsKeys[]);
+      } else {
+        reportPerformanceMetrics();
+      }
     }
 
     exitWithCleanup(0);

src/core/mapped-text.ts

@@ -15,6 +15,7 @@ import { debug } from "../deno_ral/log.ts";
 
 import * as mt from "./lib/mapped-text.ts";
 import { withTiming } from "./timing.ts";
+import { makeTimedFunction } from "./performance/metrics.ts";
 
 export type EitherString = mt.EitherString;
 export type MappedString = mt.MappedString;
@@ -33,7 +34,7 @@ export {
 // uses a diff algorithm to map on a line-by-line basis target lines
 // for `target` to `source`, allowing us to somewhat recover
 // MappedString information from third-party tools like knitr.
-export function mappedDiff(
+function mappedDiffInner(
   source: MappedString,
   target: string,
 ) {
@@ -82,6 +83,7 @@ export function mappedDiff(
     return mappedString(source, resultChunks, source.fileName);
   });
 }
+export const mappedDiff = makeTimedFunction("mappedDiff", mappedDiffInner);
 
 export function mappedStringFromFile(filename: string): MappedString {
   const value = Deno.readTextFileSync(filename);

src/core/performance/metrics.ts

@@ -5,6 +5,7 @@
  */
 
 import { inputTargetIndexCacheMetrics } from "../../project/project-index.ts";
+import { Stats } from "./stats.ts";
 
 type FileReadRecord = {
   path: string;
@@ -29,16 +30,86 @@ export function captureFileReads() {
   };
 }
 
-export function quartoPerformanceMetrics() {
-  return {
-    inputTargetIndexCache: inputTargetIndexCacheMetrics,
-    fileReads,
-  };
+const functionTimes: Record<string, Stats> = {};
+// deno-lint-ignore no-explicit-any
+export const makeTimedFunction = <T extends (...args: any[]) => any>(
+  name: string,
+  fn: T,
+): T => {
+  if (Deno.env.get("QUARTO_REPORT_PERFORMANCE_METRICS") === undefined) {
+    return fn;
+  }
+  functionTimes[name] = new Stats();
+  return function (...args: Parameters<T>): ReturnType<T> {
+    const start = performance.now();
+    try {
+      const result = fn(...args);
+      return result;
+    } finally {
+      const end = performance.now();
+      functionTimes[name].add(end - start);
+    }
+  } as T;
+};
+
+export const makeTimedFunctionAsync = <
+  // deno-lint-ignore no-explicit-any
+  T extends (...args: any[]) => Promise<any>,
+>(
+  name: string,
+  fn: T,
+): T => {
+  if (Deno.env.get("QUARTO_REPORT_PERFORMANCE_METRICS") === undefined) {
+    return fn;
+  }
+  functionTimes[name] = new Stats();
+  return async function (...args: Parameters<T>): Promise<ReturnType<T>> {
+    const start = performance.now();
+    try {
+      const result = await fn(...args);
+      return result;
+    } finally {
+      const end = performance.now();
+      functionTimes[name].add(end - start);
+    }
+  } as T;
+};
+
+const metricsObject = {
+  inputTargetIndexCache: inputTargetIndexCacheMetrics,
+  fileReads,
+  functionTimes,
+};
+export type MetricsKeys = keyof typeof metricsObject;
+
+export function quartoPerformanceMetrics(keys?: MetricsKeys[]) {
+  if (!keys) {
+    return metricsObject;
+  }
+  const result: Record<string, unknown> = {};
+  for (const key of keys) {
+    if (key === "functionTimes") {
+      const metricsObjects = metricsObject[key] as Record<string, Stats>;
+      const entries = Object.entries(metricsObjects);
+      result[key] = Object.fromEntries(
+        entries.map(([name, stats]) => [name, stats.report()]),
+      );
+    } else {
+      result[key] = metricsObject[key];
+    }
+  }
+  return result;
 }
 
-export function reportPeformanceMetrics() {
+export function reportPerformanceMetrics(keys?: MetricsKeys[]) {
   console.log("---");
   console.log("Performance metrics");
   console.log("Quarto:");
-  console.log(JSON.stringify(quartoPerformanceMetrics(), null, 2));
+  const content = JSON.stringify(quartoPerformanceMetrics(keys), null, 2);
+  const outFile = Deno.env.get("QUARTO_REPORT_PERFORMANCE_METRICS_FILE");
+  if (outFile) {
+    Deno.writeTextFileSync(outFile, content);
+  } else {
+    console.log(content);
+  }
 }

src/core/performance/stats.ts

@@ -0,0 +1,50 @@
+/*
+ * stats.ts
+ *
+ * Capture some sufficient statistics for performance analysis
+ *
+ * Copyright (C) 2025 Posit Software, PBC
+ */
+
+export class Stats {
+  // let's use Welford's algorithm for online variance calculation
+  count: number;
+  mean: number;
+  m2: number;
+
+  min: number;
+  max: number;
+
+  constructor() {
+    this.count = 0;
+    this.mean = 0;
+    this.m2 = 0;
+    this.min = Number.MAX_VALUE;
+    this.max = -Number.MAX_VALUE;
+  }
+
+  add(x: number) {
+    this.count++;
+    const delta = x - this.mean;
+    this.mean += delta / this.count;
+    const delta2 = x - this.mean;
+    this.m2 += delta * delta2;
+    this.min = Math.min(this.min, x);
+    this.max = Math.max(this.max, x);
+  }
+
+  report() {
+    if (this.count === 0) {
+      return {
+        count: 0,
+      };
+    }
+    return {
+      min: this.min,
+      max: this.max,
+      count: this.count,
+      mean: this.mean,
+      variance: this.m2 / this.count,
+    };
+  }
+}