diff --git a/packages/runtime/container-runtime/src/containerRuntime.ts b/packages/runtime/container-runtime/src/containerRuntime.ts index f495c7681fff..230bbfd297d4 100644 --- a/packages/runtime/container-runtime/src/containerRuntime.ts +++ b/packages/runtime/container-runtime/src/containerRuntime.ts @@ -3931,6 +3931,10 @@ export class ContainerRuntime * True to run GC sweep phase after the mark phase */ runSweep?: boolean; + /** + * Telemetry context to populate during summarization. + */ + telemetryContext?: TelemetryContext; }): Promise { this.verifyNotClosed(); @@ -3941,9 +3945,10 @@ export class ContainerRuntime runGC = this.garbageCollector.shouldRunGC, runSweep, fullGC, + telemetryContext: providedTelemetryContext, } = options; - const telemetryContext = new TelemetryContext(); + const telemetryContext = providedTelemetryContext ?? new TelemetryContext(); // Add the options that are used to generate this summary to the telemetry context. telemetryContext.setMultiple("fluid_Summarize", "Options", { fullTree, @@ -4185,6 +4190,7 @@ export class ContainerRuntime summaryLogger, latestSummaryRefSeqNum, } = options; + const telemetryContext = options.telemetryContext ?? new TelemetryContext(); // The summary number for this summary. This will be updated during the summary process, so get it now and // use it for all events logged during this summary. const summaryNumber = this.nextSummaryNumber; @@ -4372,6 +4378,7 @@ export class ContainerRuntime trackState: true, summaryLogger: summaryNumberLogger, runGC: this.garbageCollector.shouldRunGC, + telemetryContext, }); } catch (error) { return { diff --git a/packages/runtime/container-runtime/src/summary/summarizerTypes.ts b/packages/runtime/container-runtime/src/summary/summarizerTypes.ts index 871653b7244a..afe2c056d4e5 100644 --- a/packages/runtime/container-runtime/src/summary/summarizerTypes.ts +++ b/packages/runtime/container-runtime/src/summary/summarizerTypes.ts @@ -26,6 +26,7 @@ import type { ITelemetryLoggerExt, ITelemetryLoggerPropertyBag, } from "@fluidframework/telemetry-utils/internal"; +import type { TelemetryContext } from "@fluidframework/runtime-utils/internal"; import type { SummarizeReason } from "./summarizerUtils.js"; import type { @@ -167,6 +168,10 @@ export interface ISubmitSummaryOptions extends ISummarizeOptions { * The sequence number of the latest summary used to validate if summary state is correct before summarizing */ readonly latestSummaryRefSeqNum: number; + /** + * Shared telemetry context for the current summarize attempt. + */ + telemetryContext?: TelemetryContext; } /** diff --git a/packages/runtime/container-runtime/src/summary/summaryDelayLoadedModule/summaryGenerator.ts b/packages/runtime/container-runtime/src/summary/summaryDelayLoadedModule/summaryGenerator.ts index 0c7f2f4ca6af..76b650b86e63 100644 --- a/packages/runtime/container-runtime/src/summary/summaryDelayLoadedModule/summaryGenerator.ts +++ b/packages/runtime/container-runtime/src/summary/summaryDelayLoadedModule/summaryGenerator.ts @@ -12,6 +12,7 @@ import { PerformanceEvent, wrapError, } from "@fluidframework/telemetry-utils/internal"; +import { TelemetryContext } from "@fluidframework/runtime-utils/internal"; import type { IRefreshSummaryAckOptions, @@ -42,6 +43,7 @@ const maxSummarizeTimeoutCount = 5; // Double and resend 5 times */ export class SummaryGenerator { private readonly summarizeTimer: Timer; + private activeTelemetryContext?: TelemetryContext; constructor( private readonly pendingAckTimer: IPromiseTimer, private readonly heuristicData: ISummarizeHeuristicData, @@ -85,7 +87,16 @@ export class SummaryGenerator { submitSummaryOptions: ISubmitSummaryOptions, resultsBuilder: SummarizeResultBuilder, ): Promise { - const { summaryLogger, cancellationToken, ...summarizeOptions } = submitSummaryOptions; + const { + summaryLogger, + cancellationToken, + telemetryContext = new TelemetryContext(), + ...summarizeOptions + } = submitSummaryOptions; + + telemetryContext.currentSummarizeStep = "submitSummary"; + const submitOptions = { ...submitSummaryOptions, telemetryContext }; + this.activeTelemetryContext = telemetryContext; // Note: timeSinceLastAttempt and timeSinceLastSummary for the // first summary are basically the time since the summarizer was loaded. @@ -148,10 +159,12 @@ export class SummaryGenerator { // Wait to generate and send summary this.summarizeTimer.start(); try { + telemetryContext.currentSummarizeStep = "generateSummary"; // Need to save refSeqNum before we record new attempt (happens as part of submitSummaryCallback) const lastAttemptRefSeqNum = this.heuristicData.lastAttempt.refSequenceNumber; - summaryData = await this.submitSummaryCallback(submitSummaryOptions); + summaryData = await this.submitSummaryCallback(submitOptions); + telemetryContext.currentSummarizeStep = "submitSummaryOp"; // Cumulatively add telemetry properties based on how far generateSummary went. const referenceSequenceNumber = summaryData.referenceSequenceNumber; @@ -189,6 +202,7 @@ export class SummaryGenerator { * exceed the number of ops since last summary + number of data store whose reference state changed. */ if (submitSummaryOptions.fullTree !== true) { + telemetryContext.currentSummarizeStep = "watchSummary"; const { summarizedDataStoreCount, gcStateUpdatedDataStoreCount = 0 } = summaryData.summaryStats; if ( @@ -227,6 +241,8 @@ export class SummaryGenerator { this.summarizeTimer.clear(); } + telemetryContext.currentSummarizeStep = "waitForSummaryAck"; + try { const pendingTimeoutP = this.pendingAckTimer.start(); const summary = this.summaryWatcher.watchSummary(summaryData.clientSequenceNumber); @@ -300,6 +316,7 @@ export class SummaryGenerator { ...summarizeTelemetryProps, }; if (ackNackOp.type === MessageType.SummaryAck) { + telemetryContext.currentSummarizeStep = "ackReceived"; this.heuristicData.markLastAttemptAsSuccessful(); this.successfulSummaryCallback(); summarizeEvent.end({ @@ -324,6 +341,7 @@ export class SummaryGenerator { } else { // Check for retryDelay in summaryNack response. assert(ackNackOp.type === MessageType.SummaryNack, 0x274 /* "type check" */); + telemetryContext.currentSummarizeStep = "nackReceived"; const summaryNack = ackNackOp.contents; const errorMessage = summaryNack?.message; const retryAfterSeconds = summaryNack?.retryAfter; @@ -350,6 +368,7 @@ export class SummaryGenerator { } } finally { this.pendingAckTimer.clear(); + this.activeTelemetryContext = undefined; } } @@ -408,6 +427,7 @@ export class SummaryGenerator { eventName: "SummarizeTimeout", timeoutTime: time, timeoutCount: count, + currentSummarizeStep: this.activeTelemetryContext?.currentSummarizeStep, }); if (count < maxSummarizeTimeoutCount) { // Double and start a new timer @@ -420,5 +440,6 @@ export class SummaryGenerator { public dispose(): void { this.summarizeTimer.clear(); + this.activeTelemetryContext = undefined; } } diff --git a/packages/runtime/datastore/api-report/datastore.legacy.beta.api.md b/packages/runtime/datastore/api-report/datastore.legacy.beta.api.md index 735d1cfe1173..bf6f48f3aa45 100644 --- a/packages/runtime/datastore/api-report/datastore.legacy.beta.api.md +++ b/packages/runtime/datastore/api-report/datastore.legacy.beta.api.md @@ -131,7 +131,7 @@ export interface ISharedObjectRegistry { export const mixinRequestHandler: (requestHandler: (request: IRequest, runtime: FluidDataStoreRuntime) => Promise, Base?: typeof FluidDataStoreRuntime) => typeof FluidDataStoreRuntime; // @beta @legacy -export const mixinSummaryHandler: (handler: (runtime: FluidDataStoreRuntime) => Promise<{ +export const mixinSummaryHandler: (handler: (runtime: FluidDataStoreRuntime, setCurrentSummarizeStep: (currentStep: string) => void) => Promise<{ path: string[]; content: string; } | undefined>, Base?: typeof FluidDataStoreRuntime) => typeof FluidDataStoreRuntime; diff --git a/packages/runtime/datastore/src/dataStoreRuntime.ts b/packages/runtime/datastore/src/dataStoreRuntime.ts index e44ee46114dc..4741c7e990f3 100644 --- a/packages/runtime/datastore/src/dataStoreRuntime.ts +++ b/packages/runtime/datastore/src/dataStoreRuntime.ts @@ -65,6 +65,8 @@ import { type IFluidDataStorePolicies, type MinimumVersionForCollab, asLegacyAlpha, + currentSummarizeStepPrefix, + currentSummarizeStepPropertyName, } from "@fluidframework/runtime-definitions/internal"; import { GCDataBuilder, @@ -1557,6 +1559,7 @@ export const mixinRequestHandler = ( export const mixinSummaryHandler = ( handler: ( runtime: FluidDataStoreRuntime, + setCurrentSummarizeStep: (currentStep: string) => void, ) => Promise<{ path: string[]; content: string } | undefined>, Base: typeof FluidDataStoreRuntime = FluidDataStoreRuntime, ): typeof FluidDataStoreRuntime => @@ -1584,12 +1587,21 @@ export const mixinSummaryHandler = ( summary.summary.tree[firstName] = blob; } - async summarize(...args: any[]): Promise { - // eslint-disable-next-line @typescript-eslint/no-unsafe-argument - const summary = await super.summarize(...args); + async summarize( + fullTree: boolean = false, + trackState: boolean = true, + telemetryContext?: ITelemetryContext, + ): Promise { + const summary = await super.summarize(fullTree, trackState, telemetryContext); try { - const content = await handler(this); + const content = await handler(this, (currentStep: string) => + telemetryContext?.set( + currentSummarizeStepPrefix, + currentSummarizeStepPropertyName, + `mixinSummaryHandler:${currentStep}`, + ), + ); if (content !== undefined) { this.addBlob(summary, content.path, content.content); } diff --git a/packages/runtime/runtime-definitions/src/index.ts b/packages/runtime/runtime-definitions/src/index.ts index 4a21e634679f..b2d0db03ad6a 100644 --- a/packages/runtime/runtime-definitions/src/index.ts +++ b/packages/runtime/runtime-definitions/src/index.ts @@ -89,6 +89,8 @@ export { channelsTreeName, CreateSummarizerNodeSource, totalBlobSizePropertyName, + currentSummarizeStepPrefix, + currentSummarizeStepPropertyName, } from "./summary.js"; export type { MinimumVersionForCollab } from "./compatibilityDefinitions.js"; diff --git a/packages/runtime/runtime-definitions/src/summary.ts b/packages/runtime/runtime-definitions/src/summary.ts index 838911172d9f..dc744cf4263d 100644 --- a/packages/runtime/runtime-definitions/src/summary.ts +++ b/packages/runtime/runtime-definitions/src/summary.ts @@ -387,3 +387,13 @@ export const blobCountPropertyName = "BlobCount"; * @internal */ export const totalBlobSizePropertyName = "TotalBlobSize"; + +/** + * @internal + */ +export const currentSummarizeStepPrefix = ""; + +/** + * @internal + */ +export const currentSummarizeStepPropertyName = "CurrentSummarizeStep"; diff --git a/packages/runtime/runtime-utils/src/summaryUtils.ts b/packages/runtime/runtime-utils/src/summaryUtils.ts index 4d29905d435c..2c2439a63612 100644 --- a/packages/runtime/runtime-utils/src/summaryUtils.ts +++ b/packages/runtime/runtime-utils/src/summaryUtils.ts @@ -32,7 +32,11 @@ import type { ISummarizeResult, ITelemetryContextExt, } from "@fluidframework/runtime-definitions/internal"; -import { gcDataBlobKey } from "@fluidframework/runtime-definitions/internal"; +import { + currentSummarizeStepPrefix, + currentSummarizeStepPropertyName, + gcDataBlobKey, +} from "@fluidframework/runtime-definitions/internal"; import type { TelemetryEventPropertyTypeExt } from "@fluidframework/telemetry-utils/internal"; /** @@ -520,14 +524,18 @@ export class TelemetryContext implements ITelemetryContext, ITelemetryContextExt } /** - * {@inheritDoc @fluidframework/runtime-definitions#ITelemetryContext.get} + * Get the telemetry data being tracked + * @param prefix - unique prefix to tag this data with (ex: "fluid:map:") + * @param property - property name of the telemetry data being tracked (ex: "DirectoryCount") + * @returns undefined if item not found */ public get(prefix: string, property: string): TelemetryEventPropertyTypeExt { return this.telemetry.get(`${prefix}${property}`); } /** - * {@inheritDoc @fluidframework/runtime-definitions#ITelemetryContext.serialize} + * Returns a serialized version of all the telemetry data. + * Should be used when logging in telemetry events. */ public serialize(): string { const jsonObject = {}; @@ -536,6 +544,14 @@ export class TelemetryContext implements ITelemetryContext, ITelemetryContextExt } return JSON.stringify(jsonObject); } + + public get currentSummarizeStep(): TelemetryEventPropertyTypeExt { + return this.get(currentSummarizeStepPrefix, currentSummarizeStepPropertyName); + } + + public set currentSummarizeStep(value: TelemetryEventPropertyTypeExt) { + this.set(currentSummarizeStepPrefix, currentSummarizeStepPropertyName, value); + } } /**