From f8319cf1435b17b89f8c4639239645912bec4fc9 Mon Sep 17 00:00:00 2001 From: Dominik Prokop Date: Tue, 23 Jul 2024 13:10:47 +0200 Subject: [PATCH 01/15] v1 --- .../src/behaviors/SceneQueryController.ts | 202 ++++++++++++++++++ .../src/components/SceneRefreshPicker.tsx | 20 +- packages/scenes/src/core/SceneTimeRange.tsx | 17 +- 3 files changed, 224 insertions(+), 15 deletions(-) diff --git a/packages/scenes/src/behaviors/SceneQueryController.ts b/packages/scenes/src/behaviors/SceneQueryController.ts index 36df469ad..12e945586 100644 --- a/packages/scenes/src/behaviors/SceneQueryController.ts +++ b/packages/scenes/src/behaviors/SceneQueryController.ts @@ -7,12 +7,15 @@ export interface SceneQueryStateControllerState extends SceneObjectState { isRunning: boolean; } +const POST_STORM_WINDOW = 1000; +const LEAD_RECORDING_TIME = 500; export interface SceneQueryControllerLike extends SceneObject { isQueryController: true; cancelAll(): void; queryStarted(entry: SceneQueryControllerEntry): void; queryCompleted(entry: SceneQueryControllerEntry): void; + startTransaction(source: SceneObject): void; } export function isQueryController(s: SceneObject | SceneStatelessBehavior): s is SceneQueryControllerLike { @@ -40,6 +43,22 @@ export class SceneQueryController #running = new Set(); + #transactionInProgress: { + origin: string; + crumbs: string[]; + } | null = null; + + #transactionStartTs: number | null = null; + #transactionEndTs: number | null = null; + #trailAnimationFrameId: number | null = null; + #leadAnimationFrameId: number | null = null; + + // Will keep measured lengths of leading and trailing frames + #recordedLeadingSpans: number[] = []; + #recordedTrailingSpans: number[] = []; + + lastFrameTime: number = 0; + public constructor() { super({ isRunning: false }); @@ -49,6 +68,56 @@ export class SceneQueryController }); } + public startTransaction(source: SceneObject) { + // cancel any running frame measurements + if (this.#trailAnimationFrameId) { + cancelAnimationFrame(this.#trailAnimationFrameId); + this.#trailAnimationFrameId = null; + console.log('\tNew transaction: Stopped recording frames'); + } + + // if there is anu running lead frame measurements, cancel them + if (this.#leadAnimationFrameId) { + console.log('\tNew transaction: Stopped recording lead frames'); + cancelAnimationFrame(this.#leadAnimationFrameId); + this.#leadAnimationFrameId = null; + } + + if (this.#transactionInProgress && this.#transactionStartTs) { + // continue transaction, capture what was the source of continuation + this.#transactionInProgress.crumbs.push(source.constructor.name); + console.log('\tMeasurement transaction continued:', this.#transactionInProgress); + } else { + // start new transaction + // capture transaction start time + this.#transactionInProgress = { origin: source.constructor.name, crumbs: [] }; + this.#transactionStartTs = performance.now(); + console.log('\tMeasurement transaction started:', this.#transactionInProgress, this.#transactionStartTs); + + // start recording leading frames + // this will capture LEAD_RECORDING_TIME frames after transaction start to detect network silence + // if there there will be no network requests, then transaction will be completed + this.recordTransactionLead(this.#transactionStartTs); + } + } + + private completeTransaction(end?: number): [number, number] | null { + console.log('\tCompleting transaction'); + if (this.#transactionInProgress && this.#transactionStartTs) { + this.#transactionEndTs = end || performance.now(); + const duration = this.#transactionEndTs - this.#transactionStartTs; + + console.log('\tTransaction completed:', this.#transactionInProgress, duration); + + this.#transactionInProgress = null; + // this.#transactionStartTs = null; + + return [duration, this.#transactionEndTs]; + } + + return null; + } + public queryStarted(entry: SceneQueryControllerEntry) { this.#running.add(entry); @@ -73,11 +142,134 @@ export class SceneQueryController } } + private recordTransactionTail(transactionDuration: number, measurementStartTime: number) { + // performance.mark('frames recording start'); + this.#trailAnimationFrameId = requestAnimationFrame(() => + this.measureTrailingFrames(transactionDuration, measurementStartTime) + ); + } + + private recordTransactionLead(transactionStart: number) { + console.log('\tRecording lead frames'); + this.#leadAnimationFrameId = requestAnimationFrame(() => + this.measureLeadingFrames(transactionStart, transactionStart) + ); + } + + // will capture leading frame lengths right after transaction start + private measureLeadingFrames = (transactionStart: number, lastFrameTime: number) => { + const currentFrameTime = performance.now(); + const frameLength = currentFrameTime - lastFrameTime; + this.#recordedLeadingSpans.push(frameLength); + + // still measuring + if (currentFrameTime - transactionStart < LEAD_RECORDING_TIME) { + this.#leadAnimationFrameId = requestAnimationFrame(() => + this.measureLeadingFrames(transactionStart, currentFrameTime) + ); + } else { + console.log('\tStoped recording lead frames'); + const networkEntries = Array.from(performance.getEntriesByType('resource')); + let i = networkEntries.length - 1; + let networkRequestCount = 0; + + // iterate back until transaction start time to count any network requests. + // if there were no network requests, then complete transaction + while (i > 0) { + const entry = networkEntries[i]; + // whitelist API requests we are interested in observing + const regex = /\b(api\/query|api\/annotations)\b/; + + const hasMatch = regex.test(entry.name); + if (hasMatch && entry.startTime >= this.#transactionStartTs!) { + networkRequestCount++; + } + i--; + } + + if (networkRequestCount === 0) { + const slowFrames = processRecordedSpans(this.#recordedLeadingSpans); + const slowFramesTime = slowFrames.reduce((acc, val) => acc + val, 0); + console.log('\tTransaction lead recorded, slow frames duration:', slowFramesTime, slowFrames); + this.completeTransaction(transactionStart + slowFramesTime); + } + + this.#recordedLeadingSpans = []; + this.#leadAnimationFrameId = null; + } + }; + + private measureTrailingFrames = (transactionDuration: number, lastFrameTime: number) => { + const currentFrameTime = performance.now(); + const frameLength = currentFrameTime - lastFrameTime; + this.#recordedTrailingSpans.push(frameLength); + + if (currentFrameTime - this.#transactionEndTs! < POST_STORM_WINDOW) { + this.#trailAnimationFrameId = requestAnimationFrame(() => + this.measureTrailingFrames(transactionDuration, currentFrameTime) + ); + } else { + performance.mark('frames recording end'); + const slowFrames = processRecordedSpans(this.#recordedTrailingSpans); + const slowFramesTime = slowFrames.reduce((acc, val) => acc + val, 0); + console.log('\tTransaction tail recorded, slow frames duration:', slowFramesTime, slowFrames); + this.#recordedTrailingSpans = []; + + // Using performance api to calculate sum of all network requests time starting at performance.now() -transactionDuration - slowFramesTime + const entries = performance.getEntriesByType('resource'); + + const n = performance.now(); + // iterate over all entries + for (let i = 0; i < entries.length; i++) { + const entry = entries[i]; + // check if entry is between the time span of transaction + if (entry.startTime >= this.#transactionStartTs! && entry.responseEnd <= n) { + // console.log('\t -> ', entry.name, entry.responseEnd - entry.startTime); + } + } + console.log('\tStoped recording, total measured time (network included):', transactionDuration + slowFramesTime); + this.#trailAnimationFrameId = null; + + if (window.__runs) { + window.__runs += `${Date.now()}, ${transactionDuration + slowFramesTime}\n`; + } else { + window.__runs = `${Date.now()}, ${transactionDuration + slowFramesTime}\n`; + } + } + }; + private changeRunningQueryCount(dir: 1 | -1) { /** * Used by grafana-image-renderer to know when all queries are completed. */ (window as any).__grafanaRunningQueryCount = ((window as any).__grafanaRunningQueryCount ?? 0) + dir; + + // console.log('\tRunning queries:', (window as any).__grafanaRunningQueryCount); + // Delegate to next frame to check if all queries are completed + // This is to account for scenarios when there's "yet another" query that's started + // I.e. when transaction is "continued", i.e. refresh clicked multiple times and queries cancelled + // the transaction is not completed as the cancelled queries are replaced with new refreshed queries + requestAnimationFrame(() => { + this.tryCompletingTransaction(); + }); + } + + private tryCompletingTransaction() { + if (this.#running.size === 0 && this.#transactionInProgress) { + // If "all" queries completed, wait for lead frames to complete just in case there was another request that was started + if (this.#leadAnimationFrameId) { + // console.log('\tAll queries completed, waiting for lead frames to complete', this.#leadAnimationFrameId); + requestAnimationFrame(() => { + this.tryCompletingTransaction(); + }); + } else { + console.log('\tAll queries completed, stopping transaction'); + const completedTransaction = this.completeTransaction(); + if (completedTransaction !== null) { + this.recordTransactionTail(completedTransaction[0], completedTransaction[1]); + } + } + } } public cancelAll() { @@ -86,3 +278,13 @@ export class SceneQueryController } } } + +function processRecordedSpans(spans: number[]) { + // identifie last span in spans that's bigger than 50 + for (let i = spans.length - 1; i >= 0; i--) { + if (spans[i] > 50) { + return spans.slice(0, i + 1); + } + } + return [spans[0]]; +} diff --git a/packages/scenes/src/components/SceneRefreshPicker.tsx b/packages/scenes/src/components/SceneRefreshPicker.tsx index ab9d6e97a..e4403df27 100644 --- a/packages/scenes/src/components/SceneRefreshPicker.tsx +++ b/packages/scenes/src/components/SceneRefreshPicker.tsx @@ -55,10 +55,12 @@ export class SceneRefreshPicker extends SceneObjectBase public onRefresh = () => { const queryController = sceneGraph.getQueryController(this); + if (queryController?.state.isRunning) { queryController.cancelAll(); return; } + queryController?.startTransaction(this); const timeRange = sceneGraph.getTimeRange(this); @@ -156,13 +158,13 @@ export function SceneRefreshPickerRenderer({ model }: SceneComponentProps { + model.onRefresh(); + }} primary={primary} onIntervalChanged={model.onIntervalChanged} - isLoading={isRunning} + // isLoading={isRunning} isOnCanvas={isOnCanvas ?? true} /> ); diff --git a/packages/scenes/src/core/SceneTimeRange.tsx b/packages/scenes/src/core/SceneTimeRange.tsx index 70456dc10..1ae3bd6a1 100644 --- a/packages/scenes/src/core/SceneTimeRange.tsx +++ b/packages/scenes/src/core/SceneTimeRange.tsx @@ -9,6 +9,7 @@ import { getClosest } from './sceneGraph/utils'; import { parseUrlParam } from '../utils/parseUrlParam'; import { evaluateTimeRange } from '../utils/evaluateTimeRange'; import { config, RefreshEvent } from '@grafana/runtime'; +import { sceneGraph } from './sceneGraph'; export class SceneTimeRange extends SceneObjectBase implements SceneTimeRangeLike { protected _urlSync = new SceneObjectUrlSyncConfig(this, { keys: ['from', 'to', 'timezone'] }); @@ -23,9 +24,8 @@ export class SceneTimeRange extends SceneObjectBase impleme timeZone || getTimeZone(), state.fiscalYearStartMonth, state.UNSAFE_nowDelay - ); - const refreshOnActivate = state.refreshOnActivate ?? {percent: 10} + const refreshOnActivate = state.refreshOnActivate ?? { percent: 10 }; super({ from, to, timeZone, value, refreshOnActivate, ...state }); this.addActivationHandler(this._onActivate.bind(this)); @@ -58,7 +58,7 @@ export class SceneTimeRange extends SceneObjectBase impleme setWeekStart(this.state.weekStart); } - if(rangeUtil.isRelativeTimeRange(this.state.value.raw)){ + if (rangeUtil.isRelativeTimeRange(this.state.value.raw)) { this.refreshIfStale(); } @@ -120,16 +120,16 @@ export class SceneTimeRange extends SceneObjectBase impleme ); const diff = value.to.diff(this.state.value.to, 'milliseconds'); - if(diff >= refreshAfterMs){ + if (diff >= refreshAfterMs) { this.setState({ - value - }) + value, + }); } } private calculatePercentOfInterval(percent: number): number { const intervalMs = this.state.value.to.diff(this.state.value.from, 'milliseconds'); - return Math.ceil(intervalMs / percent) + return Math.ceil(intervalMs / percent); } public getTimeZone(): TimeZone { @@ -150,6 +150,7 @@ export class SceneTimeRange extends SceneObjectBase impleme public onTimeRangeChange = (timeRange: TimeRange) => { const update: Partial = {}; + const updateToEval: Partial = {}; if (typeof timeRange.raw.from === 'string') { @@ -178,6 +179,8 @@ export class SceneTimeRange extends SceneObjectBase impleme // Only update if time range actually changed if (update.from !== this.state.from || update.to !== this.state.to) { + const queryController = sceneGraph.getQueryController(this); + queryController?.startTransaction(this); this.setState(update); } }; From 1a0c0ed78dab64a589de64e0c0f17629965d684c Mon Sep 17 00:00:00 2001 From: Dominik Prokop Date: Wed, 31 Jul 2024 09:48:48 +0200 Subject: [PATCH 02/15] update --- .../src/behaviors/SceneQueryController.ts | 339 +++++++++++------- .../src/components/SceneRefreshPicker.tsx | 2 +- 2 files changed, 202 insertions(+), 139 deletions(-) diff --git a/packages/scenes/src/behaviors/SceneQueryController.ts b/packages/scenes/src/behaviors/SceneQueryController.ts index 12e945586..d31ba3da6 100644 --- a/packages/scenes/src/behaviors/SceneQueryController.ts +++ b/packages/scenes/src/behaviors/SceneQueryController.ts @@ -7,8 +7,10 @@ export interface SceneQueryStateControllerState extends SceneObjectState { isRunning: boolean; } -const POST_STORM_WINDOW = 1000; +const POST_STORM_WINDOW = 2000; // Time after last query to observe slow frames const LEAD_RECORDING_TIME = 500; +const SPAN_THRESHOLD = 30; // Frames longer than this will be considered slow + export interface SceneQueryControllerLike extends SceneObject { isQueryController: true; cancelAll(): void; @@ -16,6 +18,7 @@ export interface SceneQueryControllerLike extends SceneObject(); + #tryCompleteProfileFrameId: number | null = null; + + // lastFrameTime: number = 0; + + public constructor() { + super({ isRunning: false }); + + // Clear running state on deactivate + this.addActivationHandler(() => { + return () => this.#running.clear(); + }); + } + + public runningQueriesCount = () => { + return this.#running.size; + }; + public startTransaction(source: SceneObject) { + this.profiler.startProfile(source.constructor.name); + } + + public queryStarted(entry: SceneQueryControllerEntry) { + this.#running.add(entry); + + this.changeRunningQueryCount(1); + + if (!this.state.isRunning) { + this.setState({ isRunning: true }); + } + } + + public queryCompleted(entry: SceneQueryControllerEntry) { + if (!this.#running.has(entry)) { + return; + } + + this.#running.delete(entry); + + this.changeRunningQueryCount(-1); + + if (this.#running.size === 0) { + this.setState({ isRunning: false }); + } + } + + private changeRunningQueryCount(dir: 1 | -1) { + /** + * Used by grafana-image-renderer to know when all queries are completed. + */ + (window as any).__grafanaRunningQueryCount = ((window as any).__grafanaRunningQueryCount ?? 0) + dir; + console.log('\tRunning queries:', (window as any).__grafanaRunningQueryCount); + + if (dir === 1) { + if (this.profiler.isTailRecording()) { + console.log('\tNew query started, cancelling tail recording'); + this.profiler.cancelTailRecording(); + } + } + // console.log('\tRunning queries:', (window as any).__grafanaRunningQueryCount); + // Delegate to next frame to check if all queries are completed + // This is to account for scenarios when there's "yet another" query that's started + // I.e. when transaction is "continued", i.e. refresh clicked multiple times and queries cancelled + // the transaction is not completed as the cancelled queries are replaced with new refreshed queries + + if (this.#tryCompleteProfileFrameId) { + cancelAnimationFrame(this.#tryCompleteProfileFrameId); + } + this.#tryCompleteProfileFrameId = requestAnimationFrame(() => { + this.profiler.tryCompletingProfile(); + }); + } + + public cancelAll() { + for (const entry of this.#running.values()) { + entry.cancel?.(); + } + } +} + +class SceneRenderProfiler { #transactionInProgress: { origin: string; crumbs: string[]; @@ -59,17 +142,9 @@ export class SceneQueryController lastFrameTime: number = 0; - public constructor() { - super({ isRunning: false }); - - // Clear running state on deactivate - this.addActivationHandler(() => { - return () => this.#running.clear(); - }); - } + public constructor(private queryController: SceneQueryControllerLike) {} - public startTransaction(source: SceneObject) { - // cancel any running frame measurements + public startProfile(name: string) { if (this.#trailAnimationFrameId) { cancelAnimationFrame(this.#trailAnimationFrameId); this.#trailAnimationFrameId = null; @@ -83,25 +158,17 @@ export class SceneQueryController this.#leadAnimationFrameId = null; } - if (this.#transactionInProgress && this.#transactionStartTs) { - // continue transaction, capture what was the source of continuation - this.#transactionInProgress.crumbs.push(source.constructor.name); - console.log('\tMeasurement transaction continued:', this.#transactionInProgress); - } else { - // start new transaction - // capture transaction start time - this.#transactionInProgress = { origin: source.constructor.name, crumbs: [] }; - this.#transactionStartTs = performance.now(); - console.log('\tMeasurement transaction started:', this.#transactionInProgress, this.#transactionStartTs); - - // start recording leading frames - // this will capture LEAD_RECORDING_TIME frames after transaction start to detect network silence - // if there there will be no network requests, then transaction will be completed - this.recordTransactionLead(this.#transactionStartTs); - } + this.#transactionInProgress = { origin: name, crumbs: [] }; + this.#transactionStartTs = performance.now(); + console.log('\tMeasurement transaction started:', this.#transactionInProgress, this.#transactionStartTs); + + // start recording leading frames + // this will capture LEAD_RECORDING_TIME frames after transaction start to detect network silence + // if there there will be no network requests, then transaction will be completed + // this.recordProfileLead(this.#transactionStartTs); } - private completeTransaction(end?: number): [number, number] | null { + private completeProfile(end?: number): [number, number] | null { console.log('\tCompleting transaction'); if (this.#transactionInProgress && this.#transactionStartTs) { this.#transactionEndTs = end || performance.now(); @@ -109,7 +176,7 @@ export class SceneQueryController console.log('\tTransaction completed:', this.#transactionInProgress, duration); - this.#transactionInProgress = null; + // this.#transactionInProgress = null; // this.#transactionStartTs = null; return [duration, this.#transactionEndTs]; @@ -118,48 +185,99 @@ export class SceneQueryController return null; } - public queryStarted(entry: SceneQueryControllerEntry) { - this.#running.add(entry); + private recordProfileTail(measurementStartTime: number, transactionStartTs: number) { + this.#trailAnimationFrameId = requestAnimationFrame(() => + this.measureTrailingFrames(measurementStartTime, measurementStartTime, transactionStartTs) + ); + } - this.changeRunningQueryCount(1); + // private recordProfileLead(transactionStart: number) { + // performance.mark('lead frames recording start'); + // this.#leadAnimationFrameId = requestAnimationFrame(() => + // this.measureLeadingFrames(transactionStart, transactionStart) + // ); + // } - if (!this.state.isRunning) { - this.setState({ isRunning: true }); - } - } + private measureTrailingFrames = (measurementStartTs: number, lastFrameTime: number, transactionStartTs: number) => { + const currentFrameTime = performance.now(); + const frameLength = currentFrameTime - lastFrameTime; + this.#recordedTrailingSpans.push(frameLength); - public queryCompleted(entry: SceneQueryControllerEntry) { - if (!this.#running.has(entry)) { - return; - } + if (currentFrameTime - measurementStartTs! < POST_STORM_WINDOW) { + this.#trailAnimationFrameId = requestAnimationFrame(() => + this.measureTrailingFrames(measurementStartTs, currentFrameTime, transactionStartTs) + ); + } else { + const slowFrames = processRecordedSpans(this.#recordedTrailingSpans); + const slowFramesTime = slowFrames.reduce((acc, val) => acc + val, 0); + console.log('\tTransaction tail recorded, slow frames duration:', slowFramesTime, slowFrames); + this.#recordedTrailingSpans = []; - this.#running.delete(entry); + // Using performance api to calculate sum of all network requests time starting at performance.now() -transactionDuration - slowFramesTime + // const entries = performance.getEntriesByType('resource'); - this.changeRunningQueryCount(-1); + const n = performance.now(); - if (this.#running.size === 0) { - this.setState({ isRunning: false }); + const transactionDuration = measurementStartTs - transactionStartTs; + console.log('\tStoped recording, total measured time (network included):', transactionDuration + slowFramesTime); + this.#trailAnimationFrameId = null; + performance.measure('DashboardInteraction tail', { + start: measurementStartTs, + end: measurementStartTs + n, + }); + console.log({ start: transactionStartTs, end: transactionStartTs + transactionDuration + slowFramesTime }); + performance.measure('DashboardInteraction', { + start: transactionStartTs, + end: transactionStartTs + transactionDuration + slowFramesTime, + }); + // @ts-ignore + if (window.__runs) { + // @ts-ignore + window.__runs += `${Date.now()}, ${transactionDuration + slowFramesTime}\n`; + } else { + // @ts-ignore + window.__runs = `${Date.now()}, ${transactionDuration + slowFramesTime}\n`; + } } - } + }; - private recordTransactionTail(transactionDuration: number, measurementStartTime: number) { - // performance.mark('frames recording start'); - this.#trailAnimationFrameId = requestAnimationFrame(() => - this.measureTrailingFrames(transactionDuration, measurementStartTime) - ); + public tryCompletingProfile() { + console.log('\tTrying to complete profile', this.#transactionInProgress); + if (this.queryController.runningQueriesCount() === 0 && this.#transactionInProgress) { + // If "all" queries completed, wait for lead frames to complete just in case there was another request that was started + // if (this.#leadAnimationFrameId) { + // // console.log('\tAll queries completed, waiting for lead frames to complete', this.#leadAnimationFrameId); + // requestAnimationFrame(() => { + // this.tryCompletingProfile(); + // }); + // } else { + + console.log('\tAll queries completed, stopping transaction'); + // const completedTransaction = this.completeProfile(); + // if (completedTransaction !== null) { + // const transactionStartTs = completedTransaction[1] - completedTransaction[0]; + this.recordProfileTail(performance.now(), this.#transactionStartTs!); + // } + // } + } } - private recordTransactionLead(transactionStart: number) { - console.log('\tRecording lead frames'); - this.#leadAnimationFrameId = requestAnimationFrame(() => - this.measureLeadingFrames(transactionStart, transactionStart) - ); + public isTailRecording() { + return Boolean(this.#trailAnimationFrameId); + } + public cancelTailRecording() { + if (this.#trailAnimationFrameId) { + cancelAnimationFrame(this.#trailAnimationFrameId); + this.#trailAnimationFrameId = null; + console.log('\tStopped recording frames, new transaction started'); + } } // will capture leading frame lengths right after transaction start private measureLeadingFrames = (transactionStart: number, lastFrameTime: number) => { const currentFrameTime = performance.now(); const frameLength = currentFrameTime - lastFrameTime; + // console.log('\tRecording lead frames', frameLength); this.#recordedLeadingSpans.push(frameLength); // still measuring @@ -169,6 +287,12 @@ export class SceneQueryController ); } else { console.log('\tStoped recording lead frames'); + // performance.mark('lead frames recording stop'); + performance.measure('Lead recording', { + start: transactionStart, + end: currentFrameTime, + }); + const networkEntries = Array.from(performance.getEntriesByType('resource')); let i = networkEntries.length - 1; let networkRequestCount = 0; @@ -187,102 +311,41 @@ export class SceneQueryController i--; } - if (networkRequestCount === 0) { + // if there were no network requests, and no new requests were issued during lead frames recording, complete + if (networkRequestCount === 0 && this.queryController.runningQueriesCount() === 0) { const slowFrames = processRecordedSpans(this.#recordedLeadingSpans); const slowFramesTime = slowFrames.reduce((acc, val) => acc + val, 0); - console.log('\tTransaction lead recorded, slow frames duration:', slowFramesTime, slowFrames); - this.completeTransaction(transactionStart + slowFramesTime); + // console.log('\tTransaction lead recorded, slow frames duration:', slowFramesTime, slowFrames); + + const profile = this.completeProfile(transactionStart + slowFramesTime); + + if (profile !== null) { + console.log('\tStoped recording, total measured time (network included):', profile[0]); + performance.measure('Lead Calculation', { + start: transactionStart, + end: transactionStart + profile[0], + }); + // @ts-ignore + if (window.__runs) { + // @ts-ignore + window.__runs += `${Date.now()}, ${profile[0]}\n`; + } else { + // @ts-ignore + window.__runs = `${Date.now()}, ${profile[0]}\n`; + } + } } this.#recordedLeadingSpans = []; this.#leadAnimationFrameId = null; } }; - - private measureTrailingFrames = (transactionDuration: number, lastFrameTime: number) => { - const currentFrameTime = performance.now(); - const frameLength = currentFrameTime - lastFrameTime; - this.#recordedTrailingSpans.push(frameLength); - - if (currentFrameTime - this.#transactionEndTs! < POST_STORM_WINDOW) { - this.#trailAnimationFrameId = requestAnimationFrame(() => - this.measureTrailingFrames(transactionDuration, currentFrameTime) - ); - } else { - performance.mark('frames recording end'); - const slowFrames = processRecordedSpans(this.#recordedTrailingSpans); - const slowFramesTime = slowFrames.reduce((acc, val) => acc + val, 0); - console.log('\tTransaction tail recorded, slow frames duration:', slowFramesTime, slowFrames); - this.#recordedTrailingSpans = []; - - // Using performance api to calculate sum of all network requests time starting at performance.now() -transactionDuration - slowFramesTime - const entries = performance.getEntriesByType('resource'); - - const n = performance.now(); - // iterate over all entries - for (let i = 0; i < entries.length; i++) { - const entry = entries[i]; - // check if entry is between the time span of transaction - if (entry.startTime >= this.#transactionStartTs! && entry.responseEnd <= n) { - // console.log('\t -> ', entry.name, entry.responseEnd - entry.startTime); - } - } - console.log('\tStoped recording, total measured time (network included):', transactionDuration + slowFramesTime); - this.#trailAnimationFrameId = null; - - if (window.__runs) { - window.__runs += `${Date.now()}, ${transactionDuration + slowFramesTime}\n`; - } else { - window.__runs = `${Date.now()}, ${transactionDuration + slowFramesTime}\n`; - } - } - }; - - private changeRunningQueryCount(dir: 1 | -1) { - /** - * Used by grafana-image-renderer to know when all queries are completed. - */ - (window as any).__grafanaRunningQueryCount = ((window as any).__grafanaRunningQueryCount ?? 0) + dir; - - // console.log('\tRunning queries:', (window as any).__grafanaRunningQueryCount); - // Delegate to next frame to check if all queries are completed - // This is to account for scenarios when there's "yet another" query that's started - // I.e. when transaction is "continued", i.e. refresh clicked multiple times and queries cancelled - // the transaction is not completed as the cancelled queries are replaced with new refreshed queries - requestAnimationFrame(() => { - this.tryCompletingTransaction(); - }); - } - - private tryCompletingTransaction() { - if (this.#running.size === 0 && this.#transactionInProgress) { - // If "all" queries completed, wait for lead frames to complete just in case there was another request that was started - if (this.#leadAnimationFrameId) { - // console.log('\tAll queries completed, waiting for lead frames to complete', this.#leadAnimationFrameId); - requestAnimationFrame(() => { - this.tryCompletingTransaction(); - }); - } else { - console.log('\tAll queries completed, stopping transaction'); - const completedTransaction = this.completeTransaction(); - if (completedTransaction !== null) { - this.recordTransactionTail(completedTransaction[0], completedTransaction[1]); - } - } - } - } - - public cancelAll() { - for (const entry of this.#running.values()) { - entry.cancel?.(); - } - } } function processRecordedSpans(spans: number[]) { // identifie last span in spans that's bigger than 50 for (let i = spans.length - 1; i >= 0; i--) { - if (spans[i] > 50) { + if (spans[i] > SPAN_THRESHOLD) { return spans.slice(0, i + 1); } } diff --git a/packages/scenes/src/components/SceneRefreshPicker.tsx b/packages/scenes/src/components/SceneRefreshPicker.tsx index e4403df27..69e1dd730 100644 --- a/packages/scenes/src/components/SceneRefreshPicker.tsx +++ b/packages/scenes/src/components/SceneRefreshPicker.tsx @@ -183,7 +183,7 @@ export function SceneRefreshPickerRenderer({ model }: SceneComponentProps ); From 5373da23b77b8519e6d329637f07432850286016 Mon Sep 17 00:00:00 2001 From: Dominik Prokop Date: Thu, 1 Aug 2024 15:05:54 +0200 Subject: [PATCH 03/15] Expose profile callback, instrument variables selects --- .../src/behaviors/SceneQueryController.ts | 99 ++++++++++++------- .../src/components/SceneRefreshPicker.tsx | 3 +- packages/scenes/src/core/SceneTimeRange.tsx | 2 +- packages/scenes/src/index.ts | 1 + .../components/VariableValueSelect.tsx | 6 +- 5 files changed, 70 insertions(+), 41 deletions(-) diff --git a/packages/scenes/src/behaviors/SceneQueryController.ts b/packages/scenes/src/behaviors/SceneQueryController.ts index d31ba3da6..a4e7f816e 100644 --- a/packages/scenes/src/behaviors/SceneQueryController.ts +++ b/packages/scenes/src/behaviors/SceneQueryController.ts @@ -2,9 +2,17 @@ import { SceneObjectBase } from '../core/SceneObjectBase'; import { SceneObject, SceneObjectState, SceneStatelessBehavior } from '../core/types'; import { DataQueryRequest } from '@grafana/data'; import { LoadingState } from '@grafana/schema'; +import { writeSceneLog } from '../utils/writeSceneLog'; +export interface SceneInteractionProfileEvent { + origin: string; + duration: number; + crumbs: string[]; + // add more granular data,i.e. network times? slow frames? +} export interface SceneQueryStateControllerState extends SceneObjectState { isRunning: boolean; + onProfileComplete?(event: SceneInteractionProfileEvent): void; } const POST_STORM_WINDOW = 2000; // Time after last query to observe slow frames @@ -17,7 +25,7 @@ export interface SceneQueryControllerLike extends SceneObject = {}) { + super({ ...state, isRunning: false }); // Clear running state on deactivate this.addActivationHandler(() => { @@ -63,14 +71,13 @@ export class SceneQueryController public runningQueriesCount = () => { return this.#running.size; }; - public startTransaction(source: SceneObject) { + public startProfile(source: SceneObject) { this.profiler.startProfile(source.constructor.name); } public queryStarted(entry: SceneQueryControllerEntry) { this.#running.add(entry); - - this.changeRunningQueryCount(1); + this.changeRunningQueryCount(1, entry); if (!this.state.isRunning) { this.setState({ isRunning: true }); @@ -91,16 +98,20 @@ export class SceneQueryController } } - private changeRunningQueryCount(dir: 1 | -1) { + private changeRunningQueryCount(dir: 1 | -1, entry?: SceneQueryControllerEntry) { /** * Used by grafana-image-renderer to know when all queries are completed. */ (window as any).__grafanaRunningQueryCount = ((window as any).__grafanaRunningQueryCount ?? 0) + dir; - console.log('\tRunning queries:', (window as any).__grafanaRunningQueryCount); + // console.log('\tRunning queries:', (window as any).__grafanaRunningQueryCount); if (dir === 1) { + if (entry) { + // Collect profile crumbs, variables, annotations and queries + this.profiler.addCrumb(entry.origin.constructor.name); + } if (this.profiler.isTailRecording()) { - console.log('\tNew query started, cancelling tail recording'); + writeSceneLog(this.constructor.name, 'New query started, cancelling tail recording'); this.profiler.cancelTailRecording(); } } @@ -127,6 +138,7 @@ export class SceneQueryController class SceneRenderProfiler { #transactionInProgress: { + // Transaction origin, i.e. scene refresh picker origin: string; crumbs: string[]; } | null = null; @@ -148,19 +160,18 @@ class SceneRenderProfiler { if (this.#trailAnimationFrameId) { cancelAnimationFrame(this.#trailAnimationFrameId); this.#trailAnimationFrameId = null; - console.log('\tNew transaction: Stopped recording frames'); - } - // if there is anu running lead frame measurements, cancel them - if (this.#leadAnimationFrameId) { - console.log('\tNew transaction: Stopped recording lead frames'); - cancelAnimationFrame(this.#leadAnimationFrameId); - this.#leadAnimationFrameId = null; + writeSceneLog(this.constructor.name, 'New transaction: Stopped recording frames'); } this.#transactionInProgress = { origin: name, crumbs: [] }; this.#transactionStartTs = performance.now(); - console.log('\tMeasurement transaction started:', this.#transactionInProgress, this.#transactionStartTs); + writeSceneLog( + this.constructor.name, + 'Measurement transaction started:', + this.#transactionInProgress, + this.#transactionStartTs + ); // start recording leading frames // this will capture LEAD_RECORDING_TIME frames after transaction start to detect network silence @@ -169,12 +180,12 @@ class SceneRenderProfiler { } private completeProfile(end?: number): [number, number] | null { - console.log('\tCompleting transaction'); + writeSceneLog(this.constructor.name, 'Completing transaction'); if (this.#transactionInProgress && this.#transactionStartTs) { this.#transactionEndTs = end || performance.now(); const duration = this.#transactionEndTs - this.#transactionStartTs; - console.log('\tTransaction completed:', this.#transactionInProgress, duration); + writeSceneLog(this.constructor.name, 'Transaction completed:', this.#transactionInProgress, duration); // this.#transactionInProgress = null; // this.#transactionStartTs = null; @@ -210,7 +221,14 @@ class SceneRenderProfiler { } else { const slowFrames = processRecordedSpans(this.#recordedTrailingSpans); const slowFramesTime = slowFrames.reduce((acc, val) => acc + val, 0); - console.log('\tTransaction tail recorded, slow frames duration:', slowFramesTime, slowFrames); + writeSceneLog( + this.constructor.name, + 'Transaction tail recorded, slow frames duration:', + slowFramesTime, + slowFrames, + this.#transactionInProgress + ); + this.#recordedTrailingSpans = []; // Using performance api to calculate sum of all network requests time starting at performance.now() -transactionDuration - slowFramesTime @@ -219,17 +237,29 @@ class SceneRenderProfiler { const n = performance.now(); const transactionDuration = measurementStartTs - transactionStartTs; - console.log('\tStoped recording, total measured time (network included):', transactionDuration + slowFramesTime); + writeSceneLog( + this.constructor.name, + 'Stoped recording, total measured time (network included):', + transactionDuration + slowFramesTime + ); this.#trailAnimationFrameId = null; performance.measure('DashboardInteraction tail', { start: measurementStartTs, end: measurementStartTs + n, }); - console.log({ start: transactionStartTs, end: transactionStartTs + transactionDuration + slowFramesTime }); + // console.log({ start: transactionStartTs, end: transactionStartTs + transactionDuration + slowFramesTime }); performance.measure('DashboardInteraction', { start: transactionStartTs, end: transactionStartTs + transactionDuration + slowFramesTime, }); + + if (this.queryController.state.onProfileComplete) { + this.queryController.state.onProfileComplete({ + origin: this.#transactionInProgress!.origin, + crumbs: this.#transactionInProgress!.crumbs, + duration: transactionDuration + slowFramesTime, + }); + } // @ts-ignore if (window.__runs) { // @ts-ignore @@ -242,23 +272,10 @@ class SceneRenderProfiler { }; public tryCompletingProfile() { - console.log('\tTrying to complete profile', this.#transactionInProgress); + writeSceneLog(this.constructor.name, 'Trying to complete profile', this.#transactionInProgress); if (this.queryController.runningQueriesCount() === 0 && this.#transactionInProgress) { - // If "all" queries completed, wait for lead frames to complete just in case there was another request that was started - // if (this.#leadAnimationFrameId) { - // // console.log('\tAll queries completed, waiting for lead frames to complete', this.#leadAnimationFrameId); - // requestAnimationFrame(() => { - // this.tryCompletingProfile(); - // }); - // } else { - - console.log('\tAll queries completed, stopping transaction'); - // const completedTransaction = this.completeProfile(); - // if (completedTransaction !== null) { - // const transactionStartTs = completedTransaction[1] - completedTransaction[0]; + writeSceneLog(this.constructor.name, 'All queries completed, stopping transaction'); this.recordProfileTail(performance.now(), this.#transactionStartTs!); - // } - // } } } @@ -269,7 +286,13 @@ class SceneRenderProfiler { if (this.#trailAnimationFrameId) { cancelAnimationFrame(this.#trailAnimationFrameId); this.#trailAnimationFrameId = null; - console.log('\tStopped recording frames, new transaction started'); + writeSceneLog(this.constructor.name, 'Cancelled recording frames, new transaction started'); + } + } + + public addCrumb(crumb: string) { + if (this.#transactionInProgress) { + this.#transactionInProgress.crumbs.push(crumb); } } diff --git a/packages/scenes/src/components/SceneRefreshPicker.tsx b/packages/scenes/src/components/SceneRefreshPicker.tsx index 69e1dd730..1f258b8e8 100644 --- a/packages/scenes/src/components/SceneRefreshPicker.tsx +++ b/packages/scenes/src/components/SceneRefreshPicker.tsx @@ -56,11 +56,12 @@ export class SceneRefreshPicker extends SceneObjectBase public onRefresh = () => { const queryController = sceneGraph.getQueryController(this); + queryController?.startProfile(this); + if (queryController?.state.isRunning) { queryController.cancelAll(); return; } - queryController?.startTransaction(this); const timeRange = sceneGraph.getTimeRange(this); diff --git a/packages/scenes/src/core/SceneTimeRange.tsx b/packages/scenes/src/core/SceneTimeRange.tsx index 1ae3bd6a1..4c9bf8dc9 100644 --- a/packages/scenes/src/core/SceneTimeRange.tsx +++ b/packages/scenes/src/core/SceneTimeRange.tsx @@ -180,7 +180,7 @@ export class SceneTimeRange extends SceneObjectBase impleme // Only update if time range actually changed if (update.from !== this.state.from || update.to !== this.state.to) { const queryController = sceneGraph.getQueryController(this); - queryController?.startTransaction(this); + queryController?.startProfile(this); this.setState(update); } }; diff --git a/packages/scenes/src/index.ts b/packages/scenes/src/index.ts index 0fd858704..2d5315722 100644 --- a/packages/scenes/src/index.ts +++ b/packages/scenes/src/index.ts @@ -44,6 +44,7 @@ export type { SceneQueryControllerLike, SceneQueryControllerEntryType, SceneQueryControllerEntry, + SceneInteractionProfileEvent, } from './behaviors/SceneQueryController'; export * from './variables/types'; diff --git a/packages/scenes/src/variables/components/VariableValueSelect.tsx b/packages/scenes/src/variables/components/VariableValueSelect.tsx index 2fbe55b64..1f47c6105 100644 --- a/packages/scenes/src/variables/components/VariableValueSelect.tsx +++ b/packages/scenes/src/variables/components/VariableValueSelect.tsx @@ -10,6 +10,7 @@ import { selectors } from '@grafana/e2e-selectors'; import { GrafanaTheme2, SelectableValue } from '@grafana/data'; import { css, cx } from '@emotion/css'; import { getOptionSearcher } from './getOptionSearcher'; +import { sceneGraph } from '../../core/sceneGraph'; const filterNoOp = () => true; @@ -25,7 +26,7 @@ export function VariableValueSelect({ model }: SceneComponentProps getOptionSearcher(options, includeAll), [options, includeAll]); const onInputChange = (value: string, { action }: InputActionMeta) => { @@ -72,6 +73,7 @@ export function VariableValueSelect({ model }: SceneComponentProps { model.changeValueTo(newValue.value!, newValue.label!); + queryController?.startProfile(model); if (hasCustomValue !== newValue.__isNew__) { setHasCustomValue(newValue.__isNew__); @@ -87,6 +89,7 @@ export function VariableValueSelectMulti({ model }: SceneComponentProps getOptionSearcher(options, includeAll), [options, includeAll]); @@ -136,6 +139,7 @@ export function VariableValueSelectMulti({ model }: SceneComponentProps { model.changeValueTo(uncommittedValue); + queryController?.startProfile(model); }} filterOption={filterNoOp} data-testid={selectors.pages.Dashboard.SubMenu.submenuItemValueDropDownValueLinkTexts(`${uncommittedValue}`)} From 031af1c278350fb8004170fbbf307e5a46ebaa77 Mon Sep 17 00:00:00 2001 From: Dominik Prokop Date: Thu, 1 Aug 2024 15:25:08 +0200 Subject: [PATCH 04/15] Reorg --- .../src/behaviors/SceneQueryController.ts | 289 +----------------- .../src/behaviors/SceneRenderProfiler.ts | 138 +++++++++ packages/scenes/src/behaviors/types.ts | 38 +++ .../scenes/src/core/sceneGraph/sceneGraph.ts | 3 +- packages/scenes/src/index.ts | 2 +- .../querying/registerQueryWithController.ts | 2 +- 6 files changed, 185 insertions(+), 287 deletions(-) create mode 100644 packages/scenes/src/behaviors/SceneRenderProfiler.ts create mode 100644 packages/scenes/src/behaviors/types.ts diff --git a/packages/scenes/src/behaviors/SceneQueryController.ts b/packages/scenes/src/behaviors/SceneQueryController.ts index a4e7f816e..4b3173f85 100644 --- a/packages/scenes/src/behaviors/SceneQueryController.ts +++ b/packages/scenes/src/behaviors/SceneQueryController.ts @@ -1,51 +1,13 @@ import { SceneObjectBase } from '../core/SceneObjectBase'; -import { SceneObject, SceneObjectState, SceneStatelessBehavior } from '../core/types'; -import { DataQueryRequest } from '@grafana/data'; -import { LoadingState } from '@grafana/schema'; +import { SceneObject, SceneStatelessBehavior } from '../core/types'; import { writeSceneLog } from '../utils/writeSceneLog'; - -export interface SceneInteractionProfileEvent { - origin: string; - duration: number; - crumbs: string[]; - // add more granular data,i.e. network times? slow frames? -} -export interface SceneQueryStateControllerState extends SceneObjectState { - isRunning: boolean; - onProfileComplete?(event: SceneInteractionProfileEvent): void; -} - -const POST_STORM_WINDOW = 2000; // Time after last query to observe slow frames -const LEAD_RECORDING_TIME = 500; -const SPAN_THRESHOLD = 30; // Frames longer than this will be considered slow - -export interface SceneQueryControllerLike extends SceneObject { - isQueryController: true; - cancelAll(): void; - - queryStarted(entry: SceneQueryControllerEntry): void; - queryCompleted(entry: SceneQueryControllerEntry): void; - startProfile(source: SceneObject): void; - runningQueriesCount(): number; -} +import { SceneRenderProfiler } from './SceneRenderProfiler'; +import { SceneQueryControllerEntry, SceneQueryControllerLike, SceneQueryStateControllerState } from './types'; export function isQueryController(s: SceneObject | SceneStatelessBehavior): s is SceneQueryControllerLike { return 'isQueryController' in s; } -export interface QueryResultWithState { - state: LoadingState; -} - -export interface SceneQueryControllerEntry { - request?: DataQueryRequest; - type: SceneQueryControllerEntryType; - origin: SceneObject; - cancel?: () => void; -} - -export type SceneQueryControllerEntryType = 'data' | 'annotations' | 'variable' | 'alerts'; - export class SceneQueryController extends SceneObjectBase implements SceneQueryControllerLike @@ -115,15 +77,13 @@ export class SceneQueryController this.profiler.cancelTailRecording(); } } - // console.log('\tRunning queries:', (window as any).__grafanaRunningQueryCount); + // Delegate to next frame to check if all queries are completed // This is to account for scenarios when there's "yet another" query that's started - // I.e. when transaction is "continued", i.e. refresh clicked multiple times and queries cancelled - // the transaction is not completed as the cancelled queries are replaced with new refreshed queries - if (this.#tryCompleteProfileFrameId) { cancelAnimationFrame(this.#tryCompleteProfileFrameId); } + this.#tryCompleteProfileFrameId = requestAnimationFrame(() => { this.profiler.tryCompletingProfile(); }); @@ -135,242 +95,3 @@ export class SceneQueryController } } } - -class SceneRenderProfiler { - #transactionInProgress: { - // Transaction origin, i.e. scene refresh picker - origin: string; - crumbs: string[]; - } | null = null; - - #transactionStartTs: number | null = null; - #transactionEndTs: number | null = null; - #trailAnimationFrameId: number | null = null; - #leadAnimationFrameId: number | null = null; - - // Will keep measured lengths of leading and trailing frames - #recordedLeadingSpans: number[] = []; - #recordedTrailingSpans: number[] = []; - - lastFrameTime: number = 0; - - public constructor(private queryController: SceneQueryControllerLike) {} - - public startProfile(name: string) { - if (this.#trailAnimationFrameId) { - cancelAnimationFrame(this.#trailAnimationFrameId); - this.#trailAnimationFrameId = null; - - writeSceneLog(this.constructor.name, 'New transaction: Stopped recording frames'); - } - - this.#transactionInProgress = { origin: name, crumbs: [] }; - this.#transactionStartTs = performance.now(); - writeSceneLog( - this.constructor.name, - 'Measurement transaction started:', - this.#transactionInProgress, - this.#transactionStartTs - ); - - // start recording leading frames - // this will capture LEAD_RECORDING_TIME frames after transaction start to detect network silence - // if there there will be no network requests, then transaction will be completed - // this.recordProfileLead(this.#transactionStartTs); - } - - private completeProfile(end?: number): [number, number] | null { - writeSceneLog(this.constructor.name, 'Completing transaction'); - if (this.#transactionInProgress && this.#transactionStartTs) { - this.#transactionEndTs = end || performance.now(); - const duration = this.#transactionEndTs - this.#transactionStartTs; - - writeSceneLog(this.constructor.name, 'Transaction completed:', this.#transactionInProgress, duration); - - // this.#transactionInProgress = null; - // this.#transactionStartTs = null; - - return [duration, this.#transactionEndTs]; - } - - return null; - } - - private recordProfileTail(measurementStartTime: number, transactionStartTs: number) { - this.#trailAnimationFrameId = requestAnimationFrame(() => - this.measureTrailingFrames(measurementStartTime, measurementStartTime, transactionStartTs) - ); - } - - // private recordProfileLead(transactionStart: number) { - // performance.mark('lead frames recording start'); - // this.#leadAnimationFrameId = requestAnimationFrame(() => - // this.measureLeadingFrames(transactionStart, transactionStart) - // ); - // } - - private measureTrailingFrames = (measurementStartTs: number, lastFrameTime: number, transactionStartTs: number) => { - const currentFrameTime = performance.now(); - const frameLength = currentFrameTime - lastFrameTime; - this.#recordedTrailingSpans.push(frameLength); - - if (currentFrameTime - measurementStartTs! < POST_STORM_WINDOW) { - this.#trailAnimationFrameId = requestAnimationFrame(() => - this.measureTrailingFrames(measurementStartTs, currentFrameTime, transactionStartTs) - ); - } else { - const slowFrames = processRecordedSpans(this.#recordedTrailingSpans); - const slowFramesTime = slowFrames.reduce((acc, val) => acc + val, 0); - writeSceneLog( - this.constructor.name, - 'Transaction tail recorded, slow frames duration:', - slowFramesTime, - slowFrames, - this.#transactionInProgress - ); - - this.#recordedTrailingSpans = []; - - // Using performance api to calculate sum of all network requests time starting at performance.now() -transactionDuration - slowFramesTime - // const entries = performance.getEntriesByType('resource'); - - const n = performance.now(); - - const transactionDuration = measurementStartTs - transactionStartTs; - writeSceneLog( - this.constructor.name, - 'Stoped recording, total measured time (network included):', - transactionDuration + slowFramesTime - ); - this.#trailAnimationFrameId = null; - performance.measure('DashboardInteraction tail', { - start: measurementStartTs, - end: measurementStartTs + n, - }); - // console.log({ start: transactionStartTs, end: transactionStartTs + transactionDuration + slowFramesTime }); - performance.measure('DashboardInteraction', { - start: transactionStartTs, - end: transactionStartTs + transactionDuration + slowFramesTime, - }); - - if (this.queryController.state.onProfileComplete) { - this.queryController.state.onProfileComplete({ - origin: this.#transactionInProgress!.origin, - crumbs: this.#transactionInProgress!.crumbs, - duration: transactionDuration + slowFramesTime, - }); - } - // @ts-ignore - if (window.__runs) { - // @ts-ignore - window.__runs += `${Date.now()}, ${transactionDuration + slowFramesTime}\n`; - } else { - // @ts-ignore - window.__runs = `${Date.now()}, ${transactionDuration + slowFramesTime}\n`; - } - } - }; - - public tryCompletingProfile() { - writeSceneLog(this.constructor.name, 'Trying to complete profile', this.#transactionInProgress); - if (this.queryController.runningQueriesCount() === 0 && this.#transactionInProgress) { - writeSceneLog(this.constructor.name, 'All queries completed, stopping transaction'); - this.recordProfileTail(performance.now(), this.#transactionStartTs!); - } - } - - public isTailRecording() { - return Boolean(this.#trailAnimationFrameId); - } - public cancelTailRecording() { - if (this.#trailAnimationFrameId) { - cancelAnimationFrame(this.#trailAnimationFrameId); - this.#trailAnimationFrameId = null; - writeSceneLog(this.constructor.name, 'Cancelled recording frames, new transaction started'); - } - } - - public addCrumb(crumb: string) { - if (this.#transactionInProgress) { - this.#transactionInProgress.crumbs.push(crumb); - } - } - - // will capture leading frame lengths right after transaction start - private measureLeadingFrames = (transactionStart: number, lastFrameTime: number) => { - const currentFrameTime = performance.now(); - const frameLength = currentFrameTime - lastFrameTime; - // console.log('\tRecording lead frames', frameLength); - this.#recordedLeadingSpans.push(frameLength); - - // still measuring - if (currentFrameTime - transactionStart < LEAD_RECORDING_TIME) { - this.#leadAnimationFrameId = requestAnimationFrame(() => - this.measureLeadingFrames(transactionStart, currentFrameTime) - ); - } else { - console.log('\tStoped recording lead frames'); - // performance.mark('lead frames recording stop'); - performance.measure('Lead recording', { - start: transactionStart, - end: currentFrameTime, - }); - - const networkEntries = Array.from(performance.getEntriesByType('resource')); - let i = networkEntries.length - 1; - let networkRequestCount = 0; - - // iterate back until transaction start time to count any network requests. - // if there were no network requests, then complete transaction - while (i > 0) { - const entry = networkEntries[i]; - // whitelist API requests we are interested in observing - const regex = /\b(api\/query|api\/annotations)\b/; - - const hasMatch = regex.test(entry.name); - if (hasMatch && entry.startTime >= this.#transactionStartTs!) { - networkRequestCount++; - } - i--; - } - - // if there were no network requests, and no new requests were issued during lead frames recording, complete - if (networkRequestCount === 0 && this.queryController.runningQueriesCount() === 0) { - const slowFrames = processRecordedSpans(this.#recordedLeadingSpans); - const slowFramesTime = slowFrames.reduce((acc, val) => acc + val, 0); - // console.log('\tTransaction lead recorded, slow frames duration:', slowFramesTime, slowFrames); - - const profile = this.completeProfile(transactionStart + slowFramesTime); - - if (profile !== null) { - console.log('\tStoped recording, total measured time (network included):', profile[0]); - performance.measure('Lead Calculation', { - start: transactionStart, - end: transactionStart + profile[0], - }); - // @ts-ignore - if (window.__runs) { - // @ts-ignore - window.__runs += `${Date.now()}, ${profile[0]}\n`; - } else { - // @ts-ignore - window.__runs = `${Date.now()}, ${profile[0]}\n`; - } - } - } - - this.#recordedLeadingSpans = []; - this.#leadAnimationFrameId = null; - } - }; -} - -function processRecordedSpans(spans: number[]) { - // identifie last span in spans that's bigger than 50 - for (let i = spans.length - 1; i >= 0; i--) { - if (spans[i] > SPAN_THRESHOLD) { - return spans.slice(0, i + 1); - } - } - return [spans[0]]; -} diff --git a/packages/scenes/src/behaviors/SceneRenderProfiler.ts b/packages/scenes/src/behaviors/SceneRenderProfiler.ts new file mode 100644 index 000000000..dde08de85 --- /dev/null +++ b/packages/scenes/src/behaviors/SceneRenderProfiler.ts @@ -0,0 +1,138 @@ +import { writeSceneLog } from '../utils/writeSceneLog'; +import { SceneQueryControllerLike } from './types'; + +const POST_STORM_WINDOW = 2000; // Time after last query to observe slow frames +const SPAN_THRESHOLD = 30; // Frames longer than this will be considered slow + +export class SceneRenderProfiler { + #profileInProgress: { + // Profile origin, i.e. scene refresh picker + origin: string; + crumbs: string[]; + } | null = null; + + #profileStartTs: number | null = null; + #trailAnimationFrameId: number | null = null; + + // Will keep measured lengths trailing frames + #recordedTrailingSpans: number[] = []; + + lastFrameTime: number = 0; + + public constructor(private queryController: SceneQueryControllerLike) {} + + public startProfile(name: string) { + if (this.#trailAnimationFrameId) { + cancelAnimationFrame(this.#trailAnimationFrameId); + this.#trailAnimationFrameId = null; + + writeSceneLog(this.constructor.name, 'New profile: Stopped recording frames'); + } + + this.#profileInProgress = { origin: name, crumbs: [] }; + this.#profileStartTs = performance.now(); + writeSceneLog(this.constructor.name, 'Profile started:', this.#profileInProgress, this.#profileStartTs); + } + + private recordProfileTail(measurementStartTime: number, profileStartTs: number) { + this.#trailAnimationFrameId = requestAnimationFrame(() => + this.measureTrailingFrames(measurementStartTime, measurementStartTime, profileStartTs) + ); + } + + private measureTrailingFrames = (measurementStartTs: number, lastFrameTime: number, profileStartTs: number) => { + const currentFrameTime = performance.now(); + const frameLength = currentFrameTime - lastFrameTime; + this.#recordedTrailingSpans.push(frameLength); + + if (currentFrameTime - measurementStartTs! < POST_STORM_WINDOW) { + this.#trailAnimationFrameId = requestAnimationFrame(() => + this.measureTrailingFrames(measurementStartTs, currentFrameTime, profileStartTs) + ); + } else { + const slowFrames = processRecordedSpans(this.#recordedTrailingSpans); + const slowFramesTime = slowFrames.reduce((acc, val) => acc + val, 0); + writeSceneLog( + this.constructor.name, + 'Profile tail recorded, slow frames duration:', + slowFramesTime, + slowFrames, + this.#profileInProgress + ); + + this.#recordedTrailingSpans = []; + + // Using performance api to calculate sum of all network requests time starting at performance.now() -profileDuration - slowFramesTime + // const entries = performance.getEntriesByType('resource'); + + const n = performance.now(); + + const profileDuration = measurementStartTs - profileStartTs; + writeSceneLog( + this.constructor.name, + 'Stoped recording, total measured time (network included):', + profileDuration + slowFramesTime + ); + this.#trailAnimationFrameId = null; + performance.measure('DashboardInteraction tail', { + start: measurementStartTs, + end: measurementStartTs + n, + }); + performance.measure('DashboardInteraction', { + start: profileStartTs, + end: profileStartTs + profileDuration + slowFramesTime, + }); + + if (this.queryController.state.onProfileComplete) { + this.queryController.state.onProfileComplete({ + origin: this.#profileInProgress!.origin, + crumbs: this.#profileInProgress!.crumbs, + duration: profileDuration + slowFramesTime, + }); + } + // @ts-ignore + if (window.__runs) { + // @ts-ignore + window.__runs += `${Date.now()}, ${profileDuration + slowFramesTime}\n`; + } else { + // @ts-ignore + window.__runs = `${Date.now()}, ${profileDuration + slowFramesTime}\n`; + } + } + }; + + public tryCompletingProfile() { + writeSceneLog(this.constructor.name, 'Trying to complete profile', this.#profileInProgress); + if (this.queryController.runningQueriesCount() === 0 && this.#profileInProgress) { + writeSceneLog(this.constructor.name, 'All queries completed, stopping profile'); + this.recordProfileTail(performance.now(), this.#profileStartTs!); + } + } + + public isTailRecording() { + return Boolean(this.#trailAnimationFrameId); + } + public cancelTailRecording() { + if (this.#trailAnimationFrameId) { + cancelAnimationFrame(this.#trailAnimationFrameId); + this.#trailAnimationFrameId = null; + writeSceneLog(this.constructor.name, 'Cancelled recording frames, new profile started'); + } + } + + public addCrumb(crumb: string) { + if (this.#profileInProgress) { + this.#profileInProgress.crumbs.push(crumb); + } + } +} + +function processRecordedSpans(spans: number[]) { + // identifie last span in spans that's bigger than 50 + for (let i = spans.length - 1; i >= 0; i--) { + if (spans[i] > SPAN_THRESHOLD) { + return spans.slice(0, i + 1); + } + } + return [spans[0]]; +} diff --git a/packages/scenes/src/behaviors/types.ts b/packages/scenes/src/behaviors/types.ts new file mode 100644 index 000000000..1492303b5 --- /dev/null +++ b/packages/scenes/src/behaviors/types.ts @@ -0,0 +1,38 @@ +import { LoadingState } from '@grafana/schema'; +import { SceneObject, SceneObjectState } from '../core/types'; +import { DataQueryRequest } from '@grafana/data'; + +export interface QueryResultWithState { + state: LoadingState; +} + +export interface SceneQueryControllerEntry { + request?: DataQueryRequest; + type: SceneQueryControllerEntryType; + origin: SceneObject; + cancel?: () => void; +} + +export type SceneQueryControllerEntryType = 'data' | 'annotations' | 'variable' | 'alerts'; + +export interface SceneInteractionProfileEvent { + origin: string; + duration: number; + crumbs: string[]; + // add more granular data,i.e. network times? slow frames? +} + +export interface SceneQueryStateControllerState extends SceneObjectState { + isRunning: boolean; + onProfileComplete?(event: SceneInteractionProfileEvent): void; +} + +export interface SceneQueryControllerLike extends SceneObject { + isQueryController: true; + cancelAll(): void; + + queryStarted(entry: SceneQueryControllerEntry): void; + queryCompleted(entry: SceneQueryControllerEntry): void; + startProfile(source: SceneObject): void; + runningQueriesCount(): number; +} diff --git a/packages/scenes/src/core/sceneGraph/sceneGraph.ts b/packages/scenes/src/core/sceneGraph/sceneGraph.ts index d631066b6..9ca6ad161 100644 --- a/packages/scenes/src/core/sceneGraph/sceneGraph.ts +++ b/packages/scenes/src/core/sceneGraph/sceneGraph.ts @@ -7,8 +7,9 @@ import { VariableCustomFormatterFn, SceneVariables } from '../../variables/types import { isDataLayer, SceneDataLayerProvider, SceneDataProvider, SceneLayout, SceneObject } from '../types'; import { lookupVariable } from '../../variables/lookupVariable'; import { getClosest } from './utils'; -import { SceneQueryControllerLike, isQueryController } from '../../behaviors/SceneQueryController'; +import { isQueryController } from '../../behaviors/SceneQueryController'; import { VariableInterpolation } from '@grafana/runtime'; +import { SceneQueryControllerLike } from '../../behaviors/types'; /** * Get the closest node with variables diff --git a/packages/scenes/src/index.ts b/packages/scenes/src/index.ts index 2d5315722..78bbad9da 100644 --- a/packages/scenes/src/index.ts +++ b/packages/scenes/src/index.ts @@ -45,7 +45,7 @@ export type { SceneQueryControllerEntryType, SceneQueryControllerEntry, SceneInteractionProfileEvent, -} from './behaviors/SceneQueryController'; +} from './behaviors/types'; export * from './variables/types'; export { VariableDependencyConfig } from './variables/VariableDependencyConfig'; diff --git a/packages/scenes/src/querying/registerQueryWithController.ts b/packages/scenes/src/querying/registerQueryWithController.ts index 72646faef..a9360f8c2 100644 --- a/packages/scenes/src/querying/registerQueryWithController.ts +++ b/packages/scenes/src/querying/registerQueryWithController.ts @@ -1,7 +1,7 @@ import { Observable } from 'rxjs'; import { LoadingState } from '@grafana/schema'; import { sceneGraph } from '../core/sceneGraph'; -import { QueryResultWithState, SceneQueryControllerEntry } from '../behaviors/SceneQueryController'; +import { QueryResultWithState, SceneQueryControllerEntry } from '../behaviors/types'; /** * Will look for a scene object with a behavior that is a SceneQueryController and register the query with it. From 60f68fe300529bb3c2b0bf322f7971b8d41f2b3a Mon Sep 17 00:00:00 2001 From: Dominik Prokop Date: Fri, 2 Aug 2024 10:47:53 +0200 Subject: [PATCH 05/15] Fix circular dependency --- packages/scenes/src/core/SceneTimeRange.tsx | 4 ++-- .../src/core/sceneGraph/getQueryController.ts | 23 +++++++++++++++++++ packages/scenes/src/core/sceneGraph/index.ts | 2 +- .../scenes/src/core/sceneGraph/sceneGraph.ts | 22 ------------------ 4 files changed, 26 insertions(+), 25 deletions(-) create mode 100644 packages/scenes/src/core/sceneGraph/getQueryController.ts diff --git a/packages/scenes/src/core/SceneTimeRange.tsx b/packages/scenes/src/core/SceneTimeRange.tsx index f9766d11b..e1d9fb015 100644 --- a/packages/scenes/src/core/SceneTimeRange.tsx +++ b/packages/scenes/src/core/SceneTimeRange.tsx @@ -9,7 +9,7 @@ import { getClosest } from './sceneGraph/utils'; import { parseUrlParam } from '../utils/parseUrlParam'; import { evaluateTimeRange } from '../utils/evaluateTimeRange'; import { config, RefreshEvent } from '@grafana/runtime'; -import { sceneGraph } from './sceneGraph'; +import { getQueryController } from './sceneGraph/getQueryController'; export class SceneTimeRange extends SceneObjectBase implements SceneTimeRangeLike { protected _urlSync = new SceneObjectUrlSyncConfig(this, { keys: ['from', 'to', 'timezone'] }); @@ -179,7 +179,7 @@ export class SceneTimeRange extends SceneObjectBase impleme // Only update if time range actually changed if (update.from !== this.state.from || update.to !== this.state.to) { - const queryController = sceneGraph.getQueryController(this); + const queryController = getQueryController(this); queryController?.startProfile(this); this.setState(update); } diff --git a/packages/scenes/src/core/sceneGraph/getQueryController.ts b/packages/scenes/src/core/sceneGraph/getQueryController.ts new file mode 100644 index 000000000..5afb5f2be --- /dev/null +++ b/packages/scenes/src/core/sceneGraph/getQueryController.ts @@ -0,0 +1,23 @@ +import { isQueryController } from '../../behaviors/SceneQueryController'; +import { SceneQueryControllerLike } from '../../behaviors/types'; +import { SceneObject } from '../types'; + +/** + * Returns the closest query controller undefined if none found + */ +export function getQueryController(sceneObject: SceneObject): SceneQueryControllerLike | undefined { + let parent: SceneObject | undefined = sceneObject; + + while (parent) { + if (parent.state.$behaviors) { + for (const behavior of parent.state.$behaviors) { + if (isQueryController(behavior)) { + return behavior; + } + } + } + parent = parent.parent; + } + + return undefined; +} diff --git a/packages/scenes/src/core/sceneGraph/index.ts b/packages/scenes/src/core/sceneGraph/index.ts index c22c4454b..13a88e83b 100644 --- a/packages/scenes/src/core/sceneGraph/index.ts +++ b/packages/scenes/src/core/sceneGraph/index.ts @@ -1,4 +1,5 @@ import { lookupVariable } from '../../variables/lookupVariable'; +import { getQueryController } from './getQueryController'; import { getTimeRange } from './getTimeRange'; import { findByKey, @@ -12,7 +13,6 @@ import { hasVariableDependencyInLoadingState, interpolate, getAncestor, - getQueryController, } from './sceneGraph'; export const sceneGraph = { diff --git a/packages/scenes/src/core/sceneGraph/sceneGraph.ts b/packages/scenes/src/core/sceneGraph/sceneGraph.ts index 9ca6ad161..02b9761ad 100644 --- a/packages/scenes/src/core/sceneGraph/sceneGraph.ts +++ b/packages/scenes/src/core/sceneGraph/sceneGraph.ts @@ -7,9 +7,7 @@ import { VariableCustomFormatterFn, SceneVariables } from '../../variables/types import { isDataLayer, SceneDataLayerProvider, SceneDataProvider, SceneLayout, SceneObject } from '../types'; import { lookupVariable } from '../../variables/lookupVariable'; import { getClosest } from './utils'; -import { isQueryController } from '../../behaviors/SceneQueryController'; import { VariableInterpolation } from '@grafana/runtime'; -import { SceneQueryControllerLike } from '../../behaviors/types'; /** * Get the closest node with variables @@ -243,23 +241,3 @@ export function getAncestor( return parent as ParentType; } - -/** - * Returns the closest query controller undefined if none found - */ -export function getQueryController(sceneObject: SceneObject): SceneQueryControllerLike | undefined { - let parent: SceneObject | undefined = sceneObject; - - while (parent) { - if (parent.state.$behaviors) { - for (const behavior of parent.state.$behaviors) { - if (isQueryController(behavior)) { - return behavior; - } - } - } - parent = parent.parent; - } - - return undefined; -} From ee57572e4d2734462cfbfc8ede0ef2a144429916 Mon Sep 17 00:00:00 2001 From: Dominik Prokop Date: Fri, 2 Aug 2024 10:57:42 +0200 Subject: [PATCH 06/15] typecheck --- .../behaviors/SceneQueryController.test.ts | 3 +- .../src/querying/SceneQueryRunner.test.ts | 56 ++++++------------- .../src/variables/variants/TestVariable.tsx | 2 +- 3 files changed, 20 insertions(+), 41 deletions(-) diff --git a/packages/scenes/src/behaviors/SceneQueryController.test.ts b/packages/scenes/src/behaviors/SceneQueryController.test.ts index 1973295d7..b3083b09f 100644 --- a/packages/scenes/src/behaviors/SceneQueryController.test.ts +++ b/packages/scenes/src/behaviors/SceneQueryController.test.ts @@ -2,8 +2,9 @@ import { LoadingState } from '@grafana/schema'; import { Observable } from 'rxjs'; import { SceneObject } from '../core/types'; import { TestScene } from '../variables/TestScene'; -import { QueryResultWithState, SceneQueryController } from './SceneQueryController'; +import { SceneQueryController } from './SceneQueryController'; import { registerQueryWithController } from '../querying/registerQueryWithController'; +import { QueryResultWithState } from './types'; describe('SceneQueryController', () => { let controller: SceneQueryController; diff --git a/packages/scenes/src/querying/SceneQueryRunner.test.ts b/packages/scenes/src/querying/SceneQueryRunner.test.ts index 11d614ac2..1677da7bc 100644 --- a/packages/scenes/src/querying/SceneQueryRunner.test.ts +++ b/packages/scenes/src/querying/SceneQueryRunner.test.ts @@ -19,7 +19,7 @@ import { SceneFlexItem, SceneFlexLayout } from '../components/layout/SceneFlexLa import { SceneVariableSet } from '../variables/sets/SceneVariableSet'; import { TestVariable } from '../variables/variants/TestVariable'; import { TestScene } from '../variables/TestScene'; -import { RuntimeDataSource, registerRuntimeDataSource } from './RuntimeDataSource'; +import { RuntimeDataSource, registerRuntimeDataSource, runtimeDataSources } from './RuntimeDataSource'; import { DataQuery } from '@grafana/schema'; import { EmbeddedScene } from '../components/EmbeddedScene'; import { SceneCanvasText } from '../components/SceneCanvasText'; @@ -30,13 +30,15 @@ import { TestSceneWithRequestEnricher } from '../utils/test/TestSceneWithRequest import { AdHocFiltersVariable } from '../variables/adhoc/AdHocFiltersVariable'; import { emptyPanelData } from '../core/SceneDataNode'; import { GroupByVariable } from '../variables/groupby/GroupByVariable'; -import { SceneQueryController, SceneQueryStateControllerState } from '../behaviors/SceneQueryController'; +import { SceneQueryController } from '../behaviors/SceneQueryController'; import { activateFullSceneTree } from '../utils/test/activateFullSceneTree'; import { SceneDeactivationHandler, SceneObjectState } from '../core/types'; import { LocalValueVariable } from '../variables/variants/LocalValueVariable'; import { SceneObjectBase } from '../core/SceneObjectBase'; import { ExtraQueryDescriptor, ExtraQueryProvider } from './ExtraQueryProvider'; import { SafeSerializableSceneObject } from '../utils/SafeSerializableSceneObject'; +import { config } from '@grafana/runtime'; +import { SceneQueryStateControllerState } from '../behaviors/types'; const getDataSourceMock = jest.fn().mockReturnValue({ uid: 'test-uid', @@ -132,6 +134,9 @@ jest.mock('@grafana/runtime', () => ({ getAdhocFilters: jest.fn(), }), config: { + buildInfo: { + version: '1.0.0', + }, theme: { palette: { gray60: '#666666', @@ -140,9 +145,13 @@ jest.mock('@grafana/runtime', () => ({ }, })); -describe('SceneQueryRunner', () => { +// 11.1.2 - will use SafeSerializableSceneObject +// 11.1.1 - will NOT use SafeSerializableSceneObject +describe.each(['11.1.2', '11.1.1'])('SceneQueryRunner', (v) => { let deactivationHandlers: SceneDeactivationHandler[] = []; - + beforeEach(() => { + config.buildInfo.version = v; + }); afterEach(() => { runRequestMock.mockClear(); getDataSourceMock.mockClear(); @@ -174,40 +183,7 @@ describe('SceneQueryRunner', () => { "__interval_ms", ] `); - expect(request).toMatchInlineSnapshot(` - { - "app": "scenes", - "cacheTimeout": "30", - "interval": "30s", - "intervalMs": 30000, - "liveStreaming": undefined, - "maxDataPoints": 500, - "queryCachingTTL": 300000, - "range": { - "from": "2023-07-11T02:18:08.000Z", - "raw": { - "from": "now-6h", - "to": "now", - }, - "to": "2023-07-11T08:18:08.000Z", - }, - "rangeRaw": { - "from": "now-6h", - "to": "now", - }, - "requestId": "SQR100", - "startTime": 1689063488000, - "targets": [ - { - "datasource": { - "uid": "test-uid", - }, - "refId": "A", - }, - ], - "timezone": "browser", - } - `); + expect(request).toMatchSnapshot(); }); }); @@ -490,7 +466,7 @@ describe('SceneQueryRunner', () => { expect(queryRunner.state.data).toBeUndefined(); - activateFullSceneTree(scene); + deactivationHandlers.push(activateFullSceneTree(scene)); await new Promise((r) => setTimeout(r, 1)); @@ -1089,6 +1065,8 @@ describe('SceneQueryRunner', () => { await new Promise((r) => setTimeout(r, 1)); expect(queryRunner.state.data?.series[0].fields[0].values.get(0)).toBe(123); + + runtimeDataSources.clear(); }); }); diff --git a/packages/scenes/src/variables/variants/TestVariable.tsx b/packages/scenes/src/variables/variants/TestVariable.tsx index bc9be8a32..753562961 100644 --- a/packages/scenes/src/variables/variants/TestVariable.tsx +++ b/packages/scenes/src/variables/variants/TestVariable.tsx @@ -11,7 +11,7 @@ import { MultiValueVariable, MultiValueVariableState, VariableGetOptionsArgs } f import { VariableRefresh } from '@grafana/data'; import { getClosest } from '../../core/sceneGraph/utils'; import { SceneVariableSet } from '../sets/SceneVariableSet'; -import { SceneQueryControllerEntry } from '../../behaviors/SceneQueryController'; +import { SceneQueryControllerEntry } from '../../behaviors/types'; export interface TestVariableState extends MultiValueVariableState { query: string; From eb89ae5c28b1d7f5dde5c3fe246d56a09c1dd55b Mon Sep 17 00:00:00 2001 From: Dominik Prokop Date: Fri, 2 Aug 2024 11:10:56 +0200 Subject: [PATCH 07/15] rever accidental change --- .../src/querying/SceneQueryRunner.test.ts | 53 +++++++++++++------ 1 file changed, 38 insertions(+), 15 deletions(-) diff --git a/packages/scenes/src/querying/SceneQueryRunner.test.ts b/packages/scenes/src/querying/SceneQueryRunner.test.ts index 1677da7bc..ae850e855 100644 --- a/packages/scenes/src/querying/SceneQueryRunner.test.ts +++ b/packages/scenes/src/querying/SceneQueryRunner.test.ts @@ -19,7 +19,7 @@ import { SceneFlexItem, SceneFlexLayout } from '../components/layout/SceneFlexLa import { SceneVariableSet } from '../variables/sets/SceneVariableSet'; import { TestVariable } from '../variables/variants/TestVariable'; import { TestScene } from '../variables/TestScene'; -import { RuntimeDataSource, registerRuntimeDataSource, runtimeDataSources } from './RuntimeDataSource'; +import { RuntimeDataSource, registerRuntimeDataSource } from './RuntimeDataSource'; import { DataQuery } from '@grafana/schema'; import { EmbeddedScene } from '../components/EmbeddedScene'; import { SceneCanvasText } from '../components/SceneCanvasText'; @@ -37,7 +37,6 @@ import { LocalValueVariable } from '../variables/variants/LocalValueVariable'; import { SceneObjectBase } from '../core/SceneObjectBase'; import { ExtraQueryDescriptor, ExtraQueryProvider } from './ExtraQueryProvider'; import { SafeSerializableSceneObject } from '../utils/SafeSerializableSceneObject'; -import { config } from '@grafana/runtime'; import { SceneQueryStateControllerState } from '../behaviors/types'; const getDataSourceMock = jest.fn().mockReturnValue({ @@ -134,9 +133,6 @@ jest.mock('@grafana/runtime', () => ({ getAdhocFilters: jest.fn(), }), config: { - buildInfo: { - version: '1.0.0', - }, theme: { palette: { gray60: '#666666', @@ -145,13 +141,9 @@ jest.mock('@grafana/runtime', () => ({ }, })); -// 11.1.2 - will use SafeSerializableSceneObject -// 11.1.1 - will NOT use SafeSerializableSceneObject -describe.each(['11.1.2', '11.1.1'])('SceneQueryRunner', (v) => { +describe('SceneQueryRunner', () => { let deactivationHandlers: SceneDeactivationHandler[] = []; - beforeEach(() => { - config.buildInfo.version = v; - }); + afterEach(() => { runRequestMock.mockClear(); getDataSourceMock.mockClear(); @@ -183,7 +175,40 @@ describe.each(['11.1.2', '11.1.1'])('SceneQueryRunner', (v) => { "__interval_ms", ] `); - expect(request).toMatchSnapshot(); + expect(request).toMatchInlineSnapshot(` + { + "app": "scenes", + "cacheTimeout": "30", + "interval": "30s", + "intervalMs": 30000, + "liveStreaming": undefined, + "maxDataPoints": 500, + "queryCachingTTL": 300000, + "range": { + "from": "2023-07-11T02:18:08.000Z", + "raw": { + "from": "now-6h", + "to": "now", + }, + "to": "2023-07-11T08:18:08.000Z", + }, + "rangeRaw": { + "from": "now-6h", + "to": "now", + }, + "requestId": "SQR100", + "startTime": 1689063488000, + "targets": [ + { + "datasource": { + "uid": "test-uid", + }, + "refId": "A", + }, + ], + "timezone": "browser", + } + `); }); }); @@ -466,7 +491,7 @@ describe.each(['11.1.2', '11.1.1'])('SceneQueryRunner', (v) => { expect(queryRunner.state.data).toBeUndefined(); - deactivationHandlers.push(activateFullSceneTree(scene)); + activateFullSceneTree(scene); await new Promise((r) => setTimeout(r, 1)); @@ -1065,8 +1090,6 @@ describe.each(['11.1.2', '11.1.1'])('SceneQueryRunner', (v) => { await new Promise((r) => setTimeout(r, 1)); expect(queryRunner.state.data?.series[0].fields[0].values.get(0)).toBe(123); - - runtimeDataSources.clear(); }); }); From f33ebeb4b7ea990e2d16fe03764404e772568b1a Mon Sep 17 00:00:00 2001 From: Dominik Prokop Date: Tue, 13 Aug 2024 13:59:37 +0200 Subject: [PATCH 08/15] Capture network time --- .../src/behaviors/SceneRenderProfiler.ts | 57 ++++++++++++++++++- packages/scenes/src/behaviors/types.ts | 1 + 2 files changed, 57 insertions(+), 1 deletion(-) diff --git a/packages/scenes/src/behaviors/SceneRenderProfiler.ts b/packages/scenes/src/behaviors/SceneRenderProfiler.ts index dde08de85..bd326f91c 100644 --- a/packages/scenes/src/behaviors/SceneRenderProfiler.ts +++ b/packages/scenes/src/behaviors/SceneRenderProfiler.ts @@ -78,16 +78,22 @@ export class SceneRenderProfiler { start: measurementStartTs, end: measurementStartTs + n, }); + + const profileEndTs = profileStartTs + profileDuration + slowFramesTime; + performance.measure('DashboardInteraction', { start: profileStartTs, - end: profileStartTs + profileDuration + slowFramesTime, + end: profileEndTs, }); + const networkDuration = captureNetwork(profileStartTs, profileEndTs); + if (this.queryController.state.onProfileComplete) { this.queryController.state.onProfileComplete({ origin: this.#profileInProgress!.origin, crumbs: this.#profileInProgress!.crumbs, duration: profileDuration + slowFramesTime, + networkDuration, }); } // @ts-ignore @@ -136,3 +142,52 @@ function processRecordedSpans(spans: number[]) { } return [spans[0]]; } + +function captureNetwork(startTs: number, endTs: number) { + const entries = performance.getEntriesByType('resource'); + performance.clearResourceTimings(); + const networkEntries = entries.filter((entry) => entry.startTime >= startTs && entry.startTime <= endTs); + for (const entry of networkEntries) { + performance.measure('Network entry ' + entry.name, { + start: entry.startTime, + end: entry.responseEnd, + }); + } + + return calculateNetworkTime(networkEntries); +} + +// Will calculate total time spent on Network +function calculateNetworkTime(requests: PerformanceResourceTiming[]): number { + if (requests.length === 0) { + return 0; + } + + // Step 1: Sort the requests by startTs + requests.sort((a, b) => a.startTime - b.startTime); + + // Step 2: Initialize variables + let totalNetworkTime = 0; + let currentStart = requests[0].startTime; + let currentEnd = requests[0].responseEnd; + + // Step 3: Iterate through the sorted list and merge overlapping intervals + for (let i = 1; i < requests.length; i++) { + if (requests[i].startTime <= currentEnd) { + // Overlapping intervals, merge them + currentEnd = Math.max(currentEnd, requests[i].responseEnd); + } else { + // Non-overlapping interval, add the duration to total time + totalNetworkTime += currentEnd - currentStart; + + // Update current interval + currentStart = requests[i].startTime; + currentEnd = requests[i].responseEnd; + } + } + + // Step 4: Add the last interval + totalNetworkTime += currentEnd - currentStart; + + return totalNetworkTime; +} diff --git a/packages/scenes/src/behaviors/types.ts b/packages/scenes/src/behaviors/types.ts index 1492303b5..1a13768b8 100644 --- a/packages/scenes/src/behaviors/types.ts +++ b/packages/scenes/src/behaviors/types.ts @@ -18,6 +18,7 @@ export type SceneQueryControllerEntryType = 'data' | 'annotations' | 'variable' export interface SceneInteractionProfileEvent { origin: string; duration: number; + networkDuration: number; crumbs: string[]; // add more granular data,i.e. network times? slow frames? } From 10e3f630dcc02f29c1e142be8d9555f5733964da Mon Sep 17 00:00:00 2001 From: Dominik Prokop Date: Tue, 3 Sep 2024 10:31:37 +0200 Subject: [PATCH 09/15] Instrument plugins loading --- .../src/behaviors/SceneQueryController.ts | 27 ++++++++------ .../src/behaviors/SceneRenderProfiler.ts | 25 +++++++------ packages/scenes/src/behaviors/types.ts | 6 +++- .../src/components/SceneRefreshPicker.tsx | 12 +++---- .../src/components/VizPanel/VizPanel.tsx | 36 +++++++++++++------ .../annotations/AnnotationsDataLayer.test.ts | 2 -- .../querying/registerQueryWithController.ts | 29 ++++++++++++++- packages/scenes/src/utils/getDataSource.ts | 22 +++++++++++- 8 files changed, 117 insertions(+), 42 deletions(-) diff --git a/packages/scenes/src/behaviors/SceneQueryController.ts b/packages/scenes/src/behaviors/SceneQueryController.ts index 4b3173f85..7af82d2ad 100644 --- a/packages/scenes/src/behaviors/SceneQueryController.ts +++ b/packages/scenes/src/behaviors/SceneQueryController.ts @@ -34,6 +34,9 @@ export class SceneQueryController return this.#running.size; }; public startProfile(source: SceneObject) { + if (!this.state.enableProfiling) { + return; + } this.profiler.startProfile(source.constructor.name); } @@ -67,10 +70,10 @@ export class SceneQueryController (window as any).__grafanaRunningQueryCount = ((window as any).__grafanaRunningQueryCount ?? 0) + dir; // console.log('\tRunning queries:', (window as any).__grafanaRunningQueryCount); - if (dir === 1) { + if (dir === 1 && this.state.enableProfiling) { if (entry) { - // Collect profile crumbs, variables, annotations and queries - this.profiler.addCrumb(entry.origin.constructor.name); + // Collect profile crumbs, variables, annotations, queries and plugins + this.profiler.addCrumb(`${entry.origin.constructor.name}/${entry.type}`); } if (this.profiler.isTailRecording()) { writeSceneLog(this.constructor.name, 'New query started, cancelling tail recording'); @@ -78,15 +81,17 @@ export class SceneQueryController } } - // Delegate to next frame to check if all queries are completed - // This is to account for scenarios when there's "yet another" query that's started - if (this.#tryCompleteProfileFrameId) { - cancelAnimationFrame(this.#tryCompleteProfileFrameId); - } + if (this.state.enableProfiling) { + // Delegate to next frame to check if all queries are completed + // This is to account for scenarios when there's "yet another" query that's started + if (this.#tryCompleteProfileFrameId) { + cancelAnimationFrame(this.#tryCompleteProfileFrameId); + } - this.#tryCompleteProfileFrameId = requestAnimationFrame(() => { - this.profiler.tryCompletingProfile(); - }); + this.#tryCompleteProfileFrameId = requestAnimationFrame(() => { + this.profiler.tryCompletingProfile(); + }); + } } public cancelAll() { diff --git a/packages/scenes/src/behaviors/SceneRenderProfiler.ts b/packages/scenes/src/behaviors/SceneRenderProfiler.ts index bd326f91c..686eab9d1 100644 --- a/packages/scenes/src/behaviors/SceneRenderProfiler.ts +++ b/packages/scenes/src/behaviors/SceneRenderProfiler.ts @@ -52,6 +52,7 @@ export class SceneRenderProfiler { } else { const slowFrames = processRecordedSpans(this.#recordedTrailingSpans); const slowFramesTime = slowFrames.reduce((acc, val) => acc + val, 0); + writeSceneLog( this.constructor.name, 'Profile tail recorded, slow frames duration:', @@ -62,22 +63,19 @@ export class SceneRenderProfiler { this.#recordedTrailingSpans = []; - // Using performance api to calculate sum of all network requests time starting at performance.now() -profileDuration - slowFramesTime - // const entries = performance.getEntriesByType('resource'); - - const n = performance.now(); - const profileDuration = measurementStartTs - profileStartTs; + writeSceneLog( this.constructor.name, 'Stoped recording, total measured time (network included):', profileDuration + slowFramesTime ); this.#trailAnimationFrameId = null; - performance.measure('DashboardInteraction tail', { - start: measurementStartTs, - end: measurementStartTs + n, - }); + + // performance.measure('DashboardInteraction tail', { + // start: measurementStartTs, + // end: measurementStartTs + n, + // }); const profileEndTs = profileStartTs + profileDuration + slowFramesTime; @@ -94,6 +92,12 @@ export class SceneRenderProfiler { crumbs: this.#profileInProgress!.crumbs, duration: profileDuration + slowFramesTime, networkDuration, + // @ts-ignore + jsHeapSizeLimit: performance.memory ? performance.memory.jsHeapSizeLimit : 0, + // @ts-ignore + usedJSHeapSize: performance.memory ? performance.memory.usedJSHeapSize : 0, + // @ts-ignore + totalJSHeapSize: performance.memory ? performance.memory.totalJSHeapSize : 0, }); } // @ts-ignore @@ -109,6 +113,7 @@ export class SceneRenderProfiler { public tryCompletingProfile() { writeSceneLog(this.constructor.name, 'Trying to complete profile', this.#profileInProgress); + if (this.queryController.runningQueriesCount() === 0 && this.#profileInProgress) { writeSceneLog(this.constructor.name, 'All queries completed, stopping profile'); this.recordProfileTail(performance.now(), this.#profileStartTs!); @@ -145,7 +150,7 @@ function processRecordedSpans(spans: number[]) { function captureNetwork(startTs: number, endTs: number) { const entries = performance.getEntriesByType('resource'); - performance.clearResourceTimings(); + // performance.clearResourceTimings(); const networkEntries = entries.filter((entry) => entry.startTime >= startTs && entry.startTime <= endTs); for (const entry of networkEntries) { performance.measure('Network entry ' + entry.name, { diff --git a/packages/scenes/src/behaviors/types.ts b/packages/scenes/src/behaviors/types.ts index 1a13768b8..8d1ce301d 100644 --- a/packages/scenes/src/behaviors/types.ts +++ b/packages/scenes/src/behaviors/types.ts @@ -13,18 +13,22 @@ export interface SceneQueryControllerEntry { cancel?: () => void; } -export type SceneQueryControllerEntryType = 'data' | 'annotations' | 'variable' | 'alerts'; +export type SceneQueryControllerEntryType = 'data' | 'annotations' | 'variable' | 'alerts' | 'plugin'; export interface SceneInteractionProfileEvent { origin: string; duration: number; networkDuration: number; + jsHeapSizeLimit: number; + usedJSHeapSize: number; + totalJSHeapSize: number; crumbs: string[]; // add more granular data,i.e. network times? slow frames? } export interface SceneQueryStateControllerState extends SceneObjectState { isRunning: boolean; + enableProfiling?: boolean; onProfileComplete?(event: SceneInteractionProfileEvent): void; } diff --git a/packages/scenes/src/components/SceneRefreshPicker.tsx b/packages/scenes/src/components/SceneRefreshPicker.tsx index 1f258b8e8..e8d16506d 100644 --- a/packages/scenes/src/components/SceneRefreshPicker.tsx +++ b/packages/scenes/src/components/SceneRefreshPicker.tsx @@ -159,13 +159,13 @@ export function SceneRefreshPickerRenderer({ model }: SceneComponentProps extends SceneObjectState { /** @@ -125,7 +126,12 @@ export class VizPanel extends Scene } } - private async _loadPlugin(pluginId: string, overwriteOptions?: DeepPartial<{}>, overwriteFieldConfig?: FieldConfigSource, isAfterPluginChange?: boolean) { + private async _loadPlugin( + pluginId: string, + overwriteOptions?: DeepPartial<{}>, + overwriteFieldConfig?: FieldConfigSource, + isAfterPluginChange?: boolean + ) { const plugin = loadPanelPluginSync(pluginId); if (plugin) { @@ -134,7 +140,16 @@ export class VizPanel extends Scene const { importPanelPlugin } = getPluginImportUtils(); try { - const result = await importPanelPlugin(pluginId); + const panelPromise = importPanelPlugin(pluginId); + + const queryControler = sceneGraph.getQueryController(this); + if (queryControler && queryControler.state.enableProfiling) { + wrapPromiseInStateObservable(panelPromise) + .pipe(registerQueryWithController({ type: 'plugin', origin: this })) + .subscribe(() => {}); + } + + const result = await panelPromise; this._pluginLoaded(result, overwriteOptions, overwriteFieldConfig, isAfterPluginChange); } catch (err: unknown) { this._pluginLoaded(getPanelPluginNotFound(pluginId)); @@ -155,7 +170,12 @@ export class VizPanel extends Scene return panelId; } - private async _pluginLoaded(plugin: PanelPlugin, overwriteOptions?: DeepPartial<{}>, overwriteFieldConfig?: FieldConfigSource, isAfterPluginChange?: boolean) { + private async _pluginLoaded( + plugin: PanelPlugin, + overwriteOptions?: DeepPartial<{}>, + overwriteFieldConfig?: FieldConfigSource, + isAfterPluginChange?: boolean + ) { const { options, fieldConfig, title, pluginVersion, _UNSAFE_customMigrationHandler } = this.state; const panel: PanelModel = { @@ -255,11 +275,7 @@ export class VizPanel extends Scene }; public async changePluginType(pluginId: string, newOptions?: DeepPartial<{}>, newFieldConfig?: FieldConfigSource) { - const { - options: prevOptions, - fieldConfig: prevFieldConfig, - pluginId: prevPluginId, - } = this.state; + const { options: prevOptions, fieldConfig: prevFieldConfig, pluginId: prevPluginId } = this.state; //clear field config cache to update it later this._dataWithFieldConfig = undefined; @@ -274,8 +290,8 @@ export class VizPanel extends Scene type: pluginId, }; - // onPanelTypeChanged is mainly used by plugins to migrate from Angular to React. - // For example, this will migrate options from 'graph' to 'timeseries' if the previous and new plugin ID matches. + // onPanelTypeChanged is mainly used by plugins to migrate from Angular to React. + // For example, this will migrate options from 'graph' to 'timeseries' if the previous and new plugin ID matches. const updatedOptions = this._plugin?.onPanelTypeChanged?.(panel, prevPluginId, prevOptions, prevFieldConfig); if (updatedOptions && !isEmpty(updatedOptions)) { diff --git a/packages/scenes/src/querying/layers/annotations/AnnotationsDataLayer.test.ts b/packages/scenes/src/querying/layers/annotations/AnnotationsDataLayer.test.ts index 27017a05c..67e18f488 100644 --- a/packages/scenes/src/querying/layers/annotations/AnnotationsDataLayer.test.ts +++ b/packages/scenes/src/querying/layers/annotations/AnnotationsDataLayer.test.ts @@ -15,7 +15,6 @@ import { config } from '@grafana/runtime'; let mockedEvents: Array> = []; const getDataSourceMock = jest.fn().mockReturnValue({ - // getRef: () => ({ uid: 'test' }), annotations: { prepareAnnotation: (q: AnnotationQuery) => q, prepareQuery: (q: AnnotationQuery) => q, @@ -130,7 +129,6 @@ describe.each(['11.1.2', '11.1.1'])('AnnotationsDataLayer', (v) => { }); describe('variables support', () => { - beforeEach(() => {}); describe('When query is using variable that is still loading', () => { it('Should not executed query on activate', async () => { const variable = new TestVariable({ name: 'A', value: '1' }); diff --git a/packages/scenes/src/querying/registerQueryWithController.ts b/packages/scenes/src/querying/registerQueryWithController.ts index a9360f8c2..cd0587669 100644 --- a/packages/scenes/src/querying/registerQueryWithController.ts +++ b/packages/scenes/src/querying/registerQueryWithController.ts @@ -1,4 +1,4 @@ -import { Observable } from 'rxjs'; +import { Observable, catchError, from, map } from 'rxjs'; import { LoadingState } from '@grafana/schema'; import { sceneGraph } from '../core/sceneGraph'; import { QueryResultWithState, SceneQueryControllerEntry } from '../behaviors/types'; @@ -46,3 +46,30 @@ export function registerQueryWithController(entr }); }; } + +// Wraps an arbitrary Promise in an observble that emits Promise state +export function wrapPromiseInStateObservable(promise: Promise): Observable { + console.log('wrapPromiseInStateObservable', promise); + return new Observable((observer) => { + // Emit 'loading' state initially + observer.next({ state: LoadingState.Loading }); + + // Convert the promise to an observable + const promiseObservable = from(promise); + + // Subscribe to the promise observable + promiseObservable + .pipe( + map(() => ({ state: LoadingState.Done })), + + catchError(() => { + observer.next({ state: LoadingState.Error }); + return []; + }) + ) + .subscribe({ + next: (result) => observer.next(result), + complete: () => observer.complete(), + }); + }); +} diff --git a/packages/scenes/src/utils/getDataSource.ts b/packages/scenes/src/utils/getDataSource.ts index 7c6d5b821..285c0b2a2 100644 --- a/packages/scenes/src/utils/getDataSource.ts +++ b/packages/scenes/src/utils/getDataSource.ts @@ -2,6 +2,9 @@ import { DataSourceApi, ScopedVars } from '@grafana/data'; import { getDataSourceSrv } from '@grafana/runtime'; import { DataSourceRef } from '@grafana/schema'; import { runtimeDataSources } from '../querying/RuntimeDataSource'; +import { registerQueryWithController, wrapPromiseInStateObservable } from '../querying/registerQueryWithController'; +import { SceneObject } from '../core/types'; +import { sceneGraph } from '../core/sceneGraph'; export async function getDataSource( datasource: DataSourceRef | undefined | null, @@ -18,5 +21,22 @@ export async function getDataSource( return datasource as DataSourceApi; } - return await getDataSourceSrv().get(datasource as string, scopedVars); + const dsPromise = getDataSourceSrv().get(datasource as string, scopedVars); + + if (scopedVars.__sceneObject && scopedVars.__sceneObject.value.valueOf()) { + const queryControler = sceneGraph.getQueryController(scopedVars.__sceneObject.value.valueOf() as SceneObject); + if (queryControler && queryControler.state.enableProfiling) { + wrapPromiseInStateObservable(dsPromise) + .pipe( + registerQueryWithController({ + type: 'plugin', + origin: scopedVars.__sceneObject.value.valueOf() as SceneObject, + }) + ) + .subscribe(() => {}); + } + } + + const result = await dsPromise; + return result; } From e8b0c4f0d1bd3b2e0b7a115458c1e17c89b6d5cd Mon Sep 17 00:00:00 2001 From: Dominik Prokop Date: Tue, 10 Sep 2024 09:24:27 +0200 Subject: [PATCH 10/15] uncomment code --- packages/scenes/src/behaviors/SceneRenderProfiler.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/scenes/src/behaviors/SceneRenderProfiler.ts b/packages/scenes/src/behaviors/SceneRenderProfiler.ts index 686eab9d1..b32c88c99 100644 --- a/packages/scenes/src/behaviors/SceneRenderProfiler.ts +++ b/packages/scenes/src/behaviors/SceneRenderProfiler.ts @@ -150,7 +150,7 @@ function processRecordedSpans(spans: number[]) { function captureNetwork(startTs: number, endTs: number) { const entries = performance.getEntriesByType('resource'); - // performance.clearResourceTimings(); + performance.clearResourceTimings(); const networkEntries = entries.filter((entry) => entry.startTime >= startTs && entry.startTime <= endTs); for (const entry of networkEntries) { performance.measure('Network entry ' + entry.name, { From aacfdd2873098c2409515f195a66d101f6c8c0f2 Mon Sep 17 00:00:00 2001 From: Dominik Prokop Date: Fri, 13 Sep 2024 15:19:19 +0200 Subject: [PATCH 11/15] merge fix --- packages/scenes/src/variables/adhoc/AdHocFilterRenderer.tsx | 2 +- .../scenes/src/variables/components/VariableValueSelect.tsx | 3 +-- 2 files changed, 2 insertions(+), 3 deletions(-) diff --git a/packages/scenes/src/variables/adhoc/AdHocFilterRenderer.tsx b/packages/scenes/src/variables/adhoc/AdHocFilterRenderer.tsx index 2d1f70981..b466e41de 100644 --- a/packages/scenes/src/variables/adhoc/AdHocFilterRenderer.tsx +++ b/packages/scenes/src/variables/adhoc/AdHocFilterRenderer.tsx @@ -39,8 +39,8 @@ export function AdHocFilterRenderer({ filter, model }: Props) { const [valueHasCustomValue, setValueHasCustomValue] = useState(false); // To not trigger queries on every selection we store this state locally here and only update the variable onBlur // TODO remove expect-error when we're on the latest version of @grafana/data - // @ts-expect-error const [uncommittedValue, setUncommittedValue] = useState( + // @ts-expect-error filter.values ? filter.values.map((value, index) => keyLabelToOption(value, filter.valueLabels?.[index])) : [] ); const isMultiValue = isMultiValueOperator(filter.operator); diff --git a/packages/scenes/src/variables/components/VariableValueSelect.tsx b/packages/scenes/src/variables/components/VariableValueSelect.tsx index 43e6a4506..30fca9a7a 100644 --- a/packages/scenes/src/variables/components/VariableValueSelect.tsx +++ b/packages/scenes/src/variables/components/VariableValueSelect.tsx @@ -1,12 +1,11 @@ import { isArray } from 'lodash'; import React, { RefCallback, useEffect, useMemo, useState } from 'react'; - -//@ts-ignore import { Checkbox, InputActionMeta, MultiSelect, Select, + //@ts-ignore ToggleAllState, getSelectStyles, useStyles2, From 7abffd014b63cdc95ce8960332ec131d6ceecf3f Mon Sep 17 00:00:00 2001 From: Dominik Prokop Date: Fri, 13 Sep 2024 15:26:13 +0200 Subject: [PATCH 12/15] merge fix --- packages/scenes/src/core/sceneGraph/index.ts | 2 ++ 1 file changed, 2 insertions(+) diff --git a/packages/scenes/src/core/sceneGraph/index.ts b/packages/scenes/src/core/sceneGraph/index.ts index 13a88e83b..a65e0d7b5 100644 --- a/packages/scenes/src/core/sceneGraph/index.ts +++ b/packages/scenes/src/core/sceneGraph/index.ts @@ -13,6 +13,7 @@ import { hasVariableDependencyInLoadingState, interpolate, getAncestor, + findDescendents, } from './sceneGraph'; export const sceneGraph = { @@ -30,4 +31,5 @@ export const sceneGraph = { findAllObjects, getAncestor, getQueryController, + findDescendents, }; From f888b12ceaf00b346932ec4589d149951dcbe79f Mon Sep 17 00:00:00 2001 From: oscarkilhed Date: Tue, 19 Nov 2024 16:14:09 +0100 Subject: [PATCH 13/15] start profiling on auto refresh --- packages/scenes/src/components/SceneRefreshPicker.tsx | 2 ++ packages/scenes/src/querying/registerQueryWithController.ts | 2 +- 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/packages/scenes/src/components/SceneRefreshPicker.tsx b/packages/scenes/src/components/SceneRefreshPicker.tsx index 5bf497ac9..a4124b307 100644 --- a/packages/scenes/src/components/SceneRefreshPicker.tsx +++ b/packages/scenes/src/components/SceneRefreshPicker.tsx @@ -190,6 +190,8 @@ export class SceneRefreshPicker extends SceneObjectBase this._intervalTimer = setInterval(() => { if (this.isTabVisible()) { + const queryController = sceneGraph.getQueryController(this); + queryController?.startProfile(this); timeRange.onRefresh(); } else { this._autoRefreshBlocked = true; diff --git a/packages/scenes/src/querying/registerQueryWithController.ts b/packages/scenes/src/querying/registerQueryWithController.ts index cd0587669..050b106e1 100644 --- a/packages/scenes/src/querying/registerQueryWithController.ts +++ b/packages/scenes/src/querying/registerQueryWithController.ts @@ -2,6 +2,7 @@ import { Observable, catchError, from, map } from 'rxjs'; import { LoadingState } from '@grafana/schema'; import { sceneGraph } from '../core/sceneGraph'; import { QueryResultWithState, SceneQueryControllerEntry } from '../behaviors/types'; +import { writeSceneLog } from '../utils/writeSceneLog'; /** * Will look for a scene object with a behavior that is a SceneQueryController and register the query with it. @@ -49,7 +50,6 @@ export function registerQueryWithController(entr // Wraps an arbitrary Promise in an observble that emits Promise state export function wrapPromiseInStateObservable(promise: Promise): Observable { - console.log('wrapPromiseInStateObservable', promise); return new Observable((observer) => { // Emit 'loading' state initially observer.next({ state: LoadingState.Loading }); From e81de412b6619252903df05a23323570706c3553 Mon Sep 17 00:00:00 2001 From: oscarkilhed Date: Wed, 20 Nov 2024 10:38:11 +0100 Subject: [PATCH 14/15] add tests for SceneRenderProfiler --- .../src/behaviors/SceneRenderProfiler.test.ts | 71 +++++++++++++++++++ .../src/behaviors/SceneRenderProfiler.ts | 6 +- .../querying/registerQueryWithController.ts | 1 - 3 files changed, 74 insertions(+), 4 deletions(-) create mode 100644 packages/scenes/src/behaviors/SceneRenderProfiler.test.ts diff --git a/packages/scenes/src/behaviors/SceneRenderProfiler.test.ts b/packages/scenes/src/behaviors/SceneRenderProfiler.test.ts new file mode 100644 index 000000000..34e7fae4c --- /dev/null +++ b/packages/scenes/src/behaviors/SceneRenderProfiler.test.ts @@ -0,0 +1,71 @@ +import { calculateNetworkTime, processRecordedSpans } from "./SceneRenderProfiler"; + +describe('calculateNetworkTime', () => { + it('should return the duration of a single request', () => { + const requests: PerformanceResourceTiming[] = [ + { startTime: 0, responseEnd: 100 } as PerformanceResourceTiming, + ]; + expect(calculateNetworkTime(requests)).toBe(100); + }); + + it('should return the total time for non-overlapping requests', () => { + const requests: PerformanceResourceTiming[] = [ + { startTime: 0, responseEnd: 100 } as PerformanceResourceTiming, + { startTime: 200, responseEnd: 300 } as PerformanceResourceTiming, + ]; + expect(calculateNetworkTime(requests)).toBe(200); + }); + + it('should merge overlapping requests and return the correct total time', () => { + const requests: PerformanceResourceTiming[] = [ + { startTime: 0, responseEnd: 100 } as PerformanceResourceTiming, + { startTime: 50, responseEnd: 150 } as PerformanceResourceTiming, + { startTime: 200, responseEnd: 300 } as PerformanceResourceTiming, + ]; + expect(calculateNetworkTime(requests)).toBe(250); + }); + + it('should handle multiple overlapping intervals', () => { + const requests: PerformanceResourceTiming[] = [ + { startTime: 0, responseEnd: 200 } as PerformanceResourceTiming, + { startTime: 100, responseEnd: 300 } as PerformanceResourceTiming, + { startTime: 250, responseEnd: 350 } as PerformanceResourceTiming, + ]; + expect(calculateNetworkTime(requests)).toBe(350); + }); + + it('should handle multiple overlapping intervals in wrong order', () => { + const requests: PerformanceResourceTiming[] = [ + { startTime: 100, responseEnd: 300 } as PerformanceResourceTiming, + { startTime: 0, responseEnd: 200 } as PerformanceResourceTiming, + { startTime: 250, responseEnd: 350 } as PerformanceResourceTiming, + ]; + expect(calculateNetworkTime(requests)).toBe(350); + }); + + it('should correctly calculate time with gaps between requests', () => { + const requests: PerformanceResourceTiming[] = [ + { startTime: 0, responseEnd: 100 } as PerformanceResourceTiming, + { startTime: 150, responseEnd: 250 } as PerformanceResourceTiming, + { startTime: 300, responseEnd: 400 } as PerformanceResourceTiming, + ]; + expect(calculateNetworkTime(requests)).toBe(300); + }); +}); + +describe('processRecordedSpans', () => { + it('should return the whole array if the last element is greater than 30', () => { + const spans = [10, 10, 40]; + expect(processRecordedSpans(spans)).toEqual([10, 10, 40]); + }); + + it('should return up to the last element greater than 30', () => { + const spans = [10, 20, 30, 40, 60, 10]; + expect(processRecordedSpans(spans)).toEqual([10, 20, 30, 40, 60]); + }); + + it('should return only the first element if all are below or equal to 30', () => { + const spans = [10, 20, 15, 5]; + expect(processRecordedSpans(spans)).toEqual([10]); + }); + }); diff --git a/packages/scenes/src/behaviors/SceneRenderProfiler.ts b/packages/scenes/src/behaviors/SceneRenderProfiler.ts index b32c88c99..208ed8d46 100644 --- a/packages/scenes/src/behaviors/SceneRenderProfiler.ts +++ b/packages/scenes/src/behaviors/SceneRenderProfiler.ts @@ -138,8 +138,8 @@ export class SceneRenderProfiler { } } -function processRecordedSpans(spans: number[]) { - // identifie last span in spans that's bigger than 50 +export function processRecordedSpans(spans: number[]) { + // identify last span in spans that's bigger than SPAN_THRESHOLD for (let i = spans.length - 1; i >= 0; i--) { if (spans[i] > SPAN_THRESHOLD) { return spans.slice(0, i + 1); @@ -163,7 +163,7 @@ function captureNetwork(startTs: number, endTs: number) { } // Will calculate total time spent on Network -function calculateNetworkTime(requests: PerformanceResourceTiming[]): number { +export function calculateNetworkTime(requests: PerformanceResourceTiming[]): number { if (requests.length === 0) { return 0; } diff --git a/packages/scenes/src/querying/registerQueryWithController.ts b/packages/scenes/src/querying/registerQueryWithController.ts index 050b106e1..ab7a4cbac 100644 --- a/packages/scenes/src/querying/registerQueryWithController.ts +++ b/packages/scenes/src/querying/registerQueryWithController.ts @@ -2,7 +2,6 @@ import { Observable, catchError, from, map } from 'rxjs'; import { LoadingState } from '@grafana/schema'; import { sceneGraph } from '../core/sceneGraph'; import { QueryResultWithState, SceneQueryControllerEntry } from '../behaviors/types'; -import { writeSceneLog } from '../utils/writeSceneLog'; /** * Will look for a scene object with a behavior that is a SceneQueryController and register the query with it. From ee245e12e30578e03afdaa378e8871bdfd9e2555 Mon Sep 17 00:00:00 2001 From: oscarkilhed Date: Thu, 2 Jan 2025 12:30:24 +0100 Subject: [PATCH 15/15] fix prettier --- .../src/behaviors/SceneRenderProfiler.test.ts | 34 +++++++++---------- 1 file changed, 16 insertions(+), 18 deletions(-) diff --git a/packages/scenes/src/behaviors/SceneRenderProfiler.test.ts b/packages/scenes/src/behaviors/SceneRenderProfiler.test.ts index 34e7fae4c..0276558d1 100644 --- a/packages/scenes/src/behaviors/SceneRenderProfiler.test.ts +++ b/packages/scenes/src/behaviors/SceneRenderProfiler.test.ts @@ -1,10 +1,8 @@ -import { calculateNetworkTime, processRecordedSpans } from "./SceneRenderProfiler"; +import { calculateNetworkTime, processRecordedSpans } from './SceneRenderProfiler'; describe('calculateNetworkTime', () => { it('should return the duration of a single request', () => { - const requests: PerformanceResourceTiming[] = [ - { startTime: 0, responseEnd: 100 } as PerformanceResourceTiming, - ]; + const requests: PerformanceResourceTiming[] = [{ startTime: 0, responseEnd: 100 } as PerformanceResourceTiming]; expect(calculateNetworkTime(requests)).toBe(100); }); @@ -54,18 +52,18 @@ describe('calculateNetworkTime', () => { }); describe('processRecordedSpans', () => { - it('should return the whole array if the last element is greater than 30', () => { - const spans = [10, 10, 40]; - expect(processRecordedSpans(spans)).toEqual([10, 10, 40]); - }); - - it('should return up to the last element greater than 30', () => { - const spans = [10, 20, 30, 40, 60, 10]; - expect(processRecordedSpans(spans)).toEqual([10, 20, 30, 40, 60]); - }); - - it('should return only the first element if all are below or equal to 30', () => { - const spans = [10, 20, 15, 5]; - expect(processRecordedSpans(spans)).toEqual([10]); - }); + it('should return the whole array if the last element is greater than 30', () => { + const spans = [10, 10, 40]; + expect(processRecordedSpans(spans)).toEqual([10, 10, 40]); + }); + + it('should return up to the last element greater than 30', () => { + const spans = [10, 20, 30, 40, 60, 10]; + expect(processRecordedSpans(spans)).toEqual([10, 20, 30, 40, 60]); + }); + + it('should return only the first element if all are below or equal to 30', () => { + const spans = [10, 20, 15, 5]; + expect(processRecordedSpans(spans)).toEqual([10]); }); +});