Added HTTP telemetry logging in restWrapper

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

@@ -21,6 +21,7 @@ import {
 	getBooleanFromConfig,
 	verifyToken,
 	verifyStorageToken,
+	logHttpMetrics,
 } from "@fluidframework/server-services-utils";
 import { validateRequestParams, handleResponse } from "@fluidframework/server-services";
 import {
@@ -384,6 +385,8 @@ const uploadBlob = async (
 			getGlobalTelemetryContext().getProperties().correlationId ??
 			uuid() /* getCorrelationId */,
 		() => getGlobalTelemetryContext().getProperties() /* getTelemetryContextProperties */,
+		undefined /* refreshTokenIfNeeded */,
+		logHttpMetrics /* logHttpMetrics */,
 	);
 	return restWrapper.post(uri, blobData, undefined, {
 		"Content-Type": "application/json",

server/routerlicious/packages/services-client/api-report/server-services-client.api.md

@@ -25,7 +25,7 @@ import { SummaryObject } from '@fluidframework/protocol-definitions';
 
 // @internal (undocumented)
 export class BasicRestWrapper extends RestWrapper {
-    constructor(baseurl?: string, defaultQueryString?: Record<string, string | number | boolean>, maxBodyLength?: number, maxContentLength?: number, defaultHeaders?: RawAxiosRequestHeaders, axios?: AxiosInstance, refreshDefaultQueryString?: (() => Record<string, string | number | boolean>) | undefined, refreshDefaultHeaders?: (() => RawAxiosRequestHeaders) | undefined, getCorrelationId?: (() => string | undefined) | undefined, getTelemetryContextProperties?: (() => Record<string, string | number | boolean> | undefined) | undefined, refreshTokenIfNeeded?: ((authorizationHeader: RawAxiosRequestHeaders) => Promise<RawAxiosRequestHeaders | undefined>) | undefined);
+    constructor(baseurl?: string, defaultQueryString?: Record<string, string | number | boolean>, maxBodyLength?: number, maxContentLength?: number, defaultHeaders?: RawAxiosRequestHeaders, axios?: AxiosInstance, refreshDefaultQueryString?: (() => Record<string, string | number | boolean>) | undefined, refreshDefaultHeaders?: (() => RawAxiosRequestHeaders) | undefined, getCorrelationId?: (() => string | undefined) | undefined, getTelemetryContextProperties?: (() => Record<string, string | number | boolean> | undefined) | undefined, refreshTokenIfNeeded?: ((authorizationHeader: RawAxiosRequestHeaders) => Promise<RawAxiosRequestHeaders | undefined>) | undefined, serviceName?: string | undefined, enableTelemetry?: boolean);
     // (undocumented)
     protected request<T>(requestConfig: AxiosRequestConfig, statusCode: number, canRetry?: boolean): Promise<T>;
 }

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

@@ -41,7 +41,7 @@ export {
 export { IAlfredTenant, ISession } from "./interfaces";
 export { promiseTimeout } from "./promiseTimeout";
 export { RestLessClient, RestLessFieldNames } from "./restLessClient";
-export { BasicRestWrapper, RestWrapper } from "./restWrapper";
+export { BasicRestWrapper, RestWrapper, IBasicRestWrapperMetricProps } from "./restWrapper";
 export { defaultHash, getNextHash } from "./rollingHash";
 export {
 	canRead,

server/routerlicious/packages/services-client/src/restWrapper.ts

@@ -10,12 +10,25 @@ import {
 	AxiosInstance,
 	AxiosRequestConfig,
 	RawAxiosRequestHeaders,
+	type AxiosResponse,
 } from "axios";
 import { v4 as uuid } from "uuid";
 import { debug } from "./debug";
 import { createFluidServiceNetworkError, INetworkErrorDetails } from "./error";
 import { CorrelationIdHeaderName, TelemetryContextHeaderName } from "./constants";
 
+/**
+ * @internal
+ */
+export interface IBasicRestWrapperMetricProps {
+	axiosError: AxiosError<any>;
+	status: number | string;
+	method: string;
+	url: string;
+	correlationId: string;
+	durationInMs: number;
+}
+
 /**
  * @internal
  */
@@ -170,6 +183,7 @@ export class BasicRestWrapper extends RestWrapper {
 		private readonly refreshTokenIfNeeded?: (
 			authorizationHeader: RawAxiosRequestHeaders,
 		) => Promise<RawAxiosRequestHeaders | undefined>,
+		private readonly logHttpMetrics?: (requestProps: IBasicRestWrapperMetricProps) => void,
 	) {
 		super(baseurl, defaultQueryString, maxBodyLength, maxContentLength);
 	}
@@ -180,9 +194,10 @@ export class BasicRestWrapper extends RestWrapper {
 		canRetry = true,
 	): Promise<T> {
 		const options = { ...requestConfig };
+		const correlationId = this.getCorrelationId?.() ?? uuid();
 		options.headers = this.generateHeaders(
 			options.headers,
-			this.getCorrelationId?.() ?? uuid(),
+			correlationId,
 			this.getTelemetryContextProperties?.(),
 		);
 
@@ -202,9 +217,13 @@ export class BasicRestWrapper extends RestWrapper {
 		}
 
 		return new Promise<T>((resolve, reject) => {
+			const startTime = performance.now();
+			let axiosError: AxiosError;
+			let axiosResponse: AxiosResponse;
 			this.axios
 				.request<T>(options)
 				.then((response) => {
+					axiosResponse = response;
 					resolve(response.data);
 				})
 				.catch((error: AxiosError<any>) => {
@@ -248,6 +267,7 @@ export class BasicRestWrapper extends RestWrapper {
 
 						this.request<T>(retryConfig, statusCode, false).then(resolve).catch(reject);
 					} else {
+						axiosError = error;
 						const errorSourceMessage = `[${error?.config?.method ?? ""}] request to [${
 							error?.config?.baseURL ?? options.baseURL ?? ""
 						}] failed with [${error.response?.status}] status code`;
@@ -292,6 +312,22 @@ export class BasicRestWrapper extends RestWrapper {
 							reject(createFluidServiceNetworkError(500, details));
 						}
 					}
+				})
+				.finally(() => {
+					if (this.logHttpMetrics) {
+						const status: string | number = axiosError
+							? axiosError?.response?.status ?? "STATUS_UNAVAILABLE"
+							: axiosResponse?.status ?? "STATUS_UNAVAILABLE";
+						const requestProps: IBasicRestWrapperMetricProps = {
+							axiosError,
+							status,
+							method: options.method ?? "METHOD_UNAVAILABLE",
+							url: options.url ?? "URL_UNAVAILABLE",
+							correlationId,
+							durationInMs: performance.now() - startTime,
+						};
+						this.logHttpMetrics(requestProps);
+					}
 				});
 		});
 	}

server/routerlicious/packages/services-telemetry/src/lumberEventNames.ts

@@ -72,4 +72,5 @@ export enum LumberEventName {
 	LivenessProbe = "LivenessProbe",
 	ReadinessProbe = "ReadinessProbe",
 	CircuitBreaker = "CircuitBreaker",
+	RestWrapper = "RestWrapper",
 }

server/routerlicious/packages/services-utils/src/httpRequestMetricsLogger.ts

@@ -0,0 +1,19 @@
+import type { IBasicRestWrapperMetricProps } from "@fluidframework/server-services-client";
+import {
+	CommonProperties,
+	LumberEventName,
+	Lumberjack,
+} from "@fluidframework/server-services-telemetry";
+
+export const logHttpMetrics = (requestProps: IBasicRestWrapperMetricProps) => {
+	const properties = {
+		...requestProps,
+		[CommonProperties.telemetryGroupName]: "http_requests",
+	};
+	const httpMetric = Lumberjack.newLumberMetric(LumberEventName.RestWrapper, properties);
+	if (requestProps.axiosError) {
+		httpMetric.error("HttpRequest failed");
+	} else {
+		httpMetric.success("HttpRequest completed");
+	}
+};

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

@@ -66,3 +66,4 @@ export {
 } from "./redisClientConnectionManager";
 export { ITenantKeyGenerator, TenantKeyGenerator } from "./tenantKeyGenerator";
 export { ResponseSizeMiddleware } from "./responseSizeMiddleware";
+export { logHttpMetrics } from "./httpRequestMetricsLogger";

server/routerlicious/packages/services/src/deltaManager.ts

@@ -9,6 +9,7 @@ import { BasicRestWrapper } from "@fluidframework/server-services-client";
 import { IDeltaService, type ITenantManager } from "@fluidframework/server-services-core";
 import { getGlobalTelemetryContext } from "@fluidframework/server-services-telemetry";
 import { getRefreshTokenIfNeededCallback, TenantManager } from "./tenant";
+import { logHttpMetrics } from "@fluidframework/server-services-utils";
 
 /**
  * Manager to fetch deltas from Alfred using the internal URL.
@@ -116,6 +117,7 @@ export class DeltaManager implements IDeltaService {
 			() => getGlobalTelemetryContext().getProperties().correlationId /* getCorrelationId */,
 			() => getGlobalTelemetryContext().getProperties() /* getTelemetryContextProperties */,
 			refreshTokenIfNeeded,
+			logHttpMetrics,
 		);
 		return restWrapper;
 	}

server/routerlicious/packages/services/src/documentManager.ts

@@ -18,6 +18,7 @@ import {
 	getGlobalTelemetryContext,
 } from "@fluidframework/server-services-telemetry";
 import { getRefreshTokenIfNeededCallback } from "./tenant";
+import { logHttpMetrics } from "@fluidframework/server-services-utils";
 
 /**
  * Manager to fetch document from Alfred using the internal URL.
@@ -150,6 +151,7 @@ export class DocumentManager implements IDocumentManager {
 			() => getGlobalTelemetryContext().getProperties().correlationId /* getCorrelationId */,
 			() => getGlobalTelemetryContext().getProperties() /* getTelemetryContextProperties */,
 			refreshTokenIfNeeded /* refreshTokenIfNeeded */,
+			logHttpMetrics,
 		);
 		return restWrapper;
 	}

server/routerlicious/packages/services/src/tenant.ts

@@ -15,7 +15,11 @@ import {
 } from "@fluidframework/server-services-client";
 import * as core from "@fluidframework/server-services-core";
 import { fromUtf8ToBase64 } from "@fluidframework/common-utils";
-import { extractTokenFromHeader, getValidAccessToken } from "@fluidframework/server-services-utils";
+import {
+	extractTokenFromHeader,
+	getValidAccessToken,
+	logHttpMetrics,
+} from "@fluidframework/server-services-utils";
 import {
 	CommonProperties,
 	getLumberBaseProperties,
@@ -113,6 +117,8 @@ export class TenantManager implements core.ITenantManager, core.ITenantConfigMan
 			undefined /* refreshDefaultHeaders */,
 			() => getGlobalTelemetryContext().getProperties().correlationId,
 			() => getGlobalTelemetryContext().getProperties(),
+			undefined /* refreshTokenIfNeeded */,
+			logHttpMetrics,
 		);
 		const result = await restWrapper.post<core.ITenantConfig & { key: string }>(
 			`${this.endpoint}/api/tenants/${encodeURIComponent(tenantId || "")}`,
@@ -231,6 +237,7 @@ export class TenantManager implements core.ITenantManager, core.ITenantConfigMan
 			() => getGlobalTelemetryContext().getProperties().correlationId,
 			() => getGlobalTelemetryContext().getProperties(),
 			refreshTokenIfNeeded,
+			logHttpMetrics,
 		);
 		const historian = new Historian(baseUrl, true, false, tenantRestWrapper);
 		const gitManager = new GitManager(historian);
@@ -250,6 +257,8 @@ export class TenantManager implements core.ITenantManager, core.ITenantConfigMan
 			undefined /* refreshDefaultHeaders */,
 			() => getGlobalTelemetryContext().getProperties().correlationId,
 			() => getGlobalTelemetryContext().getProperties(),
+			undefined /* refreshTokenIfNeeded */,
+			logHttpMetrics,
 		);
 		await restWrapper.post(
 			`${this.endpoint}/api/tenants/${encodeURIComponent(tenantId)}/validate`,
@@ -269,6 +278,8 @@ export class TenantManager implements core.ITenantManager, core.ITenantConfigMan
 			undefined /* refreshDefaultHeaders */,
 			() => getGlobalTelemetryContext().getProperties().correlationId,
 			() => getGlobalTelemetryContext().getProperties(),
+			undefined /* refreshTokenIfNeeded */,
+			logHttpMetrics,
 		);
 		const result = await restWrapper.get<core.ITenantKeys>(
 			`${this.endpoint}/api/tenants/${encodeURIComponent(tenantId)}/keys`,
@@ -298,6 +309,8 @@ export class TenantManager implements core.ITenantManager, core.ITenantConfigMan
 			undefined /* refreshDefaultHeaders */,
 			() => getGlobalTelemetryContext().getProperties().correlationId,
 			() => getGlobalTelemetryContext().getProperties(),
+			undefined /* refreshTokenIfNeeded */,
+			logHttpMetrics,
 		);
 		const result = await restWrapper.post<core.IFluidAccessToken>(
 			`${this.endpoint}/api/tenants/${encodeURIComponent(tenantId)}/accesstoken`,
@@ -337,6 +350,8 @@ export class TenantManager implements core.ITenantManager, core.ITenantConfigMan
 			undefined /* refreshDefaultHeaders */,
 			() => getGlobalTelemetryContext().getProperties().correlationId,
 			() => getGlobalTelemetryContext().getProperties(),
+			undefined /* refreshTokenIfNeeded */,
+			logHttpMetrics,
 		);
 		return restWrapper.get<core.ITenantConfig>(`${this.endpoint}/api/tenants/${tenantId}`, {
 			includeDisabledTenant,