Move StageTrace to services-core and add UTs (#25929)

## Description

There are several locations that we need/want to use `StageTrace`. It
should live in a shared location to facilitate that. This takes the move
from #25643 into its own PR.

## Breaking Changes

Not technically breaking: moves internal `StageTrace` API from Nexus and
R11s-base utils into `services-core`

## Reviewer Guidance

I'm open to moving this to `services-client`, but I think this is fine.

Author: znewton

server/routerlicious/packages/lambdas/src/nexus/connect.ts

@@ -27,6 +27,7 @@ import {
 	type ICollaborationSessionClient,
 	clusterDrainingRetryTimeInMs,
 	type IDenyList,
+	StageTrace,
 } from "@fluidframework/server-services-core";
 import {
 	CommonProperties,
@@ -47,7 +48,7 @@ import type {
 } from "./interfaces";
 import { ProtocolVersions, checkProtocolVersion } from "./protocol";
 import { checkThrottleAndUsage, getSocketConnectThrottleId } from "./throttleAndUsage";
-import { StageTrace, sampleMessages } from "./trace";
+import { sampleMessages } from "./trace";
 import {
 	getMessageMetadata,
 	handleServerErrorAndConvertToNetworkError,

server/routerlicious/packages/lambdas/src/nexus/trace.ts

@@ -3,7 +3,6 @@
  * Licensed under the MIT License.
  */
 
-import { performance } from "@fluidframework/common-utils";
 import type { IDocumentMessage } from "@fluidframework/protocol-definitions";
 import { getRandomInt } from "@fluidframework/server-services-client";
 import { DefaultServiceConfiguration } from "@fluidframework/server-services-core";
@@ -52,31 +51,3 @@ export function addNexusMessageTrace(
 
 	return message;
 }
-
-interface IStageTrace {
-	/**
-	 * Name of the Stage.
-	 */
-	stage: string;
-	/**
-	 * Start time of the stage relative to the previous stage's start time.
-	 */
-	ts: number;
-}
-export class StageTrace<T extends { toString(): string }> {
-	private readonly traces: IStageTrace[] = [];
-	private lastStampedTraceTime: number = performance.now();
-	constructor(initialStage?: T) {
-		if (initialStage) {
-			this.traces.push({ stage: initialStage.toString(), ts: 0 });
-		}
-	}
-	public get trace(): IStageTrace[] {
-		return this.traces;
-	}
-	public stampStage(stage: T): void {
-		const now = performance.now();
-		this.traces.push({ stage: stage.toString(), ts: now - this.lastStampedTraceTime });
-		this.lastStampedTraceTime = now;
-	}
-}

server/routerlicious/packages/routerlicious-base/src/alfred/routes/api/documents.ts

@@ -23,17 +23,18 @@ import {
 	InternalErrorCode,
 	getNetworkInformationFromIP,
 } from "@fluidframework/server-services-client";
-import type {
-	IDocumentStorage,
-	IThrottler,
-	ITenantManager,
-	ICache,
-	IDocumentRepository,
-	ITokenRevocationManager,
-	IRevokeTokenOptions,
-	IRevokedTokenChecker,
-	IClusterDrainingChecker,
-	IDenyList,
+import {
+	type IDocumentStorage,
+	type IThrottler,
+	type ITenantManager,
+	type ICache,
+	type IDocumentRepository,
+	type ITokenRevocationManager,
+	type IRevokeTokenOptions,
+	type IRevokedTokenChecker,
+	type IClusterDrainingChecker,
+	type IDenyList,
+	StageTrace,
 } from "@fluidframework/server-services-core";
 import {
 	getLumberBaseProperties,
@@ -63,7 +64,6 @@ import {
 	generateCacheKey,
 	getSession,
 	setGetSessionResultInCache,
-	StageTrace,
 } from "../../../utils";
 import type { IDocumentDeleteService } from "../../services";
 

server/routerlicious/packages/routerlicious-base/src/utils/index.ts

@@ -9,4 +9,3 @@ export { catch404, handleError } from "./middleware";
 export { getIdFromRequest, getTenantIdFromRequest } from "./params";
 export { getSession, generateCacheKey, setGetSessionResultInCache } from "./sessionHelper";
 export { configureThrottler } from "./throttling";
-export { StageTrace } from "./trace";

server/routerlicious/packages/routerlicious-base/src/utils/sessionHelper.ts

@@ -15,11 +15,10 @@ import {
 	type IDocumentRepository,
 	type IClusterDrainingChecker,
 	type ICache,
+	type StageTrace,
 } from "@fluidframework/server-services-core";
 import { getLumberBaseProperties, Lumberjack } from "@fluidframework/server-services-telemetry";
 
-import type { StageTrace } from "./trace";
-
 const defaultSessionStickinessDurationMs = 60 * 60 * 1000; // 60 minutes
 const defaultGetSessionCacheTtlInSeconds = 5 * 60; // 5 mins
 

server/routerlicious/packages/services-core/src/index.ts

@@ -169,6 +169,7 @@ export {
 	ThrottlingError,
 } from "./throttler";
 export type { TokenGenerator } from "./token";
+export { StageTrace, IStageTrace } from "./trace";
 export {
 	clientConnectivityStorageId,
 	type IUsageData,

server/routerlicious/packages/services-core/src/test/trace.spec.ts

@@ -0,0 +1,50 @@
+/*!
+ * Copyright (c) Microsoft Corporation and contributors. All rights reserved.
+ * Licensed under the MIT License.
+ */
+
+import { strict as assert } from "assert";
+import sinon from "sinon";
+import { StageTrace } from "../trace";
+import { performance } from "@fluidframework/common-utils";
+
+describe("StageTrace", () => {
+	let clock: sinon.SinonFakeTimers;
+	beforeEach(() => {
+		// Stub the `globalThis.performance.now` method
+		clock = sinon.useFakeTimers({ now: 0 });
+		sinon.stub(performance, "now").callsFake(() => Date.now());
+	});
+
+	afterEach(() => {
+		sinon.restore();
+	});
+	it("should initialize with initial stage", () => {
+		const trace = new StageTrace("initial");
+		assert.strictEqual(trace.trace[0]?.stage, "initial");
+	});
+	it("should initialize without initial stage", () => {
+		const trace = new StageTrace();
+		assert.strictEqual(trace.trace.length, 0);
+	});
+	it("should stamp stages with relative timestamps", () => {
+		const start = performance.now();
+		const trace = new StageTrace("start");
+		clock.tick(50);
+		trace.stampStage("middle");
+		clock.tick(50);
+		trace.stampStage("end");
+
+		const traces = trace.trace;
+		assert.strictEqual(traces.length, 3);
+		assert.strictEqual(traces[0].stage, "start");
+		assert.strictEqual(traces[1].stage, "middle");
+		assert.strictEqual(traces[2].stage, "end");
+		// 0 for initial stage
+		assert.strictEqual(traces[0].ts, start);
+		// 50ms between start and middle
+		assert.strictEqual(traces[1].ts, 50);
+		// 50ms between middle and end
+		assert.strictEqual(traces[2].ts, 50);
+	});
+});

…es/routerlicious-base/src/utils/trace.ts …ious/packages/services-core/src/trace.tsserver/routerlicious/packages/routerlicious-base/src/utils/trace.ts renamed to server/routerlicious/packages/services-core/src/trace.ts server/routerlicious/packages/routerlicious-base/src/utils/trace.ts renamed to server/routerlicious/packages/services-core/src/trace.ts

@@ -5,7 +5,10 @@
 
 import { performance } from "@fluidframework/common-utils";
 
-interface IStageTrace {
+/**
+ * @internal
+ */
+export interface IStageTrace {
 	/**
 	 * Name of the Stage.
 	 */
@@ -15,20 +18,37 @@ interface IStageTrace {
 	 */
 	ts: number;
 }
+
+/**
+ * Utility class to trace different stages of an operation with timestamps relative to each other.
+ * @internal
+ */
 export class StageTrace<T extends { toString(): string }> {
 	private readonly traces: IStageTrace[] = [];
-	private lastStampedTraceTime: number = performance.now();
+	#lastStampedTraceTime: number = performance.now();
+
 	constructor(initialStage?: T) {
 		if (initialStage) {
 			this.traces.push({ stage: initialStage.toString(), ts: 0 });
 		}
 	}
+	/**
+	 * Get the collected trace information.
+	 */
 	public get trace(): IStageTrace[] {
 		return this.traces;
 	}
+	/**
+	 * Stamp a new stage with the time elapsed since the last stage stamp.
+	 * @remarks
+	 * If this is the first stage being stamped after construction, the time elapsed
+	 * will be since construction.
+	 *
+	 * @param stage - stage to be stringified for trace stage name.
+	 */
 	public stampStage(stage: T): void {
 		const now = performance.now();
-		this.traces.push({ stage: stage.toString(), ts: now - this.lastStampedTraceTime });
-		this.lastStampedTraceTime = now;
+		this.traces.push({ stage: stage.toString(), ts: now - this.#lastStampedTraceTime });
+		this.#lastStampedTraceTime = now;
 	}
 }