From c6df737a7b3faedaf836243d8850872dff5369da Mon Sep 17 00:00:00 2001 From: Drew Tate Date: Mon, 7 Aug 2023 11:45:51 -0600 Subject: [PATCH] [Lens] Add lens editor performance metrics (#163089) ## Summary This PR instruments the code to track a few key editor performance metrics. This is to prepare for adding a Lens editor performance journey. Metrics - initial load of main chart - time to load data - time to render - time to initially load and render all suggestions For this PR, each metric is reported to the console (commented out to pass the linter). When the journey is added, the console statements will be converted to analytics service calls so that they show up as metrics in the journey dashboard. I made a few changes to increase the accuracy of the metrics. - wrapping render-complete callbacks in `requestAnimationFrame` calls as a temporary solution to https://github.com/elastic/elastic-charts/issues/2124 - fixing a multiple-subscription issue in the workspace panel --------- Co-authored-by: Stratoula Kalafateli --- .../public/components/gauge_component.tsx | 5 +- .../public/components/heatmap_component.tsx | 5 +- .../public/components/metric_vis.test.tsx | 7 + .../public/components/metric_vis.tsx | 5 +- .../components/partition_vis_component.tsx | 7 +- .../public/components/tagcloud_component.tsx | 5 +- .../public/components/xy_chart.tsx | 5 +- .../editor_frame/suggestion_panel.tsx | 137 +++++++++++------- .../workspace_panel/workspace_panel.tsx | 64 ++++++-- 9 files changed, 164 insertions(+), 76 deletions(-) diff --git a/src/plugins/chart_expressions/expression_gauge/public/components/gauge_component.tsx b/src/plugins/chart_expressions/expression_gauge/public/components/gauge_component.tsx index affbff3ea9b2c..4684a160881b8 100644 --- a/src/plugins/chart_expressions/expression_gauge/public/components/gauge_component.tsx +++ b/src/plugins/chart_expressions/expression_gauge/public/components/gauge_component.tsx @@ -246,7 +246,10 @@ export const GaugeComponent: FC = memo( const onRenderChange = useCallback( (isRendered: boolean = true) => { if (isRendered) { - renderComplete(); + // this requestAnimationFrame call is a temporary fix for https://github.com/elastic/elastic-charts/issues/2124 + window.requestAnimationFrame(() => { + renderComplete(); + }); } }, [renderComplete] diff --git a/src/plugins/chart_expressions/expression_heatmap/public/components/heatmap_component.tsx b/src/plugins/chart_expressions/expression_heatmap/public/components/heatmap_component.tsx index ab70211361e46..95856d1bae485 100644 --- a/src/plugins/chart_expressions/expression_heatmap/public/components/heatmap_component.tsx +++ b/src/plugins/chart_expressions/expression_heatmap/public/components/heatmap_component.tsx @@ -196,7 +196,10 @@ export const HeatmapComponent: FC = memo( const onRenderChange = useCallback( (isRendered: boolean = true) => { if (isRendered) { - renderComplete(); + // this requestAnimationFrame call is a temporary fix for https://github.com/elastic/elastic-charts/issues/2124 + window.requestAnimationFrame(() => { + renderComplete(); + }); } }, [renderComplete] diff --git a/src/plugins/chart_expressions/expression_metric/public/components/metric_vis.test.tsx b/src/plugins/chart_expressions/expression_metric/public/components/metric_vis.test.tsx index 209608c260eca..6e96c2ab06cdf 100644 --- a/src/plugins/chart_expressions/expression_metric/public/components/metric_vis.test.tsx +++ b/src/plugins/chart_expressions/expression_metric/public/components/metric_vis.test.tsx @@ -971,6 +971,11 @@ describe('MetricVisComponent', function () { }); it('should report render complete', () => { + jest.spyOn(window, 'requestAnimationFrame').mockImplementation((cb) => { + cb(0); + return 0; + }); + const renderCompleteSpy = jest.fn(); const component = shallow( { diff --git a/src/plugins/chart_expressions/expression_metric/public/components/metric_vis.tsx b/src/plugins/chart_expressions/expression_metric/public/components/metric_vis.tsx index f0aa3c3e1dede..cb352fe883152 100644 --- a/src/plugins/chart_expressions/expression_metric/public/components/metric_vis.tsx +++ b/src/plugins/chart_expressions/expression_metric/public/components/metric_vis.tsx @@ -134,7 +134,10 @@ export const MetricVis = ({ const onRenderChange = useCallback( (isRendered) => { if (isRendered) { - renderComplete(); + // this requestAnimationFrame call is a temporary fix for https://github.com/elastic/elastic-charts/issues/2124 + window.requestAnimationFrame(() => { + renderComplete(); + }); } }, [renderComplete] diff --git a/src/plugins/chart_expressions/expression_partition_vis/public/components/partition_vis_component.tsx b/src/plugins/chart_expressions/expression_partition_vis/public/components/partition_vis_component.tsx index a321aaf181e2d..c151741158ac1 100644 --- a/src/plugins/chart_expressions/expression_partition_vis/public/components/partition_vis_component.tsx +++ b/src/plugins/chart_expressions/expression_partition_vis/public/components/partition_vis_component.tsx @@ -176,8 +176,11 @@ const PartitionVisComponent = (props: PartitionVisComponentProps) => { const onRenderChange = useCallback( (isRendered: boolean = true) => { if (isRendered) { - props.renderComplete(); - setChartIsLoaded(true); + // this requestAnimationFrame call is a temporary fix for https://github.com/elastic/elastic-charts/issues/2124 + window.requestAnimationFrame(() => { + props.renderComplete(); + setChartIsLoaded(true); + }); } }, [props] diff --git a/src/plugins/chart_expressions/expression_tagcloud/public/components/tagcloud_component.tsx b/src/plugins/chart_expressions/expression_tagcloud/public/components/tagcloud_component.tsx index 7fe65370693d5..adfc3df81f97f 100644 --- a/src/plugins/chart_expressions/expression_tagcloud/public/components/tagcloud_component.tsx +++ b/src/plugins/chart_expressions/expression_tagcloud/public/components/tagcloud_component.tsx @@ -145,7 +145,10 @@ export const TagCloudChart = ({ const onRenderChange = useCallback( (isRendered) => { if (isRendered) { - renderComplete(); + // this requestAnimationFrame call is a temporary fix for https://github.com/elastic/elastic-charts/issues/2124 + window.requestAnimationFrame(() => { + renderComplete(); + }); } }, [renderComplete] diff --git a/src/plugins/chart_expressions/expression_xy/public/components/xy_chart.tsx b/src/plugins/chart_expressions/expression_xy/public/components/xy_chart.tsx index 0c19cc72d691c..e1ad4fa19d1c0 100644 --- a/src/plugins/chart_expressions/expression_xy/public/components/xy_chart.tsx +++ b/src/plugins/chart_expressions/expression_xy/public/components/xy_chart.tsx @@ -309,7 +309,10 @@ export function XYChart({ const onRenderChange = useCallback( (isRendered: boolean = true) => { if (isRendered) { - renderComplete(); + // this requestAnimationFrame call is a temporary fix for https://github.com/elastic/elastic-charts/issues/2124 + window.requestAnimationFrame(() => { + renderComplete(); + }); } }, [renderComplete] diff --git a/x-pack/plugins/lens/public/editor_frame_service/editor_frame/suggestion_panel.tsx b/x-pack/plugins/lens/public/editor_frame_service/editor_frame/suggestion_panel.tsx index 36d8b4104e64c..11f50252b993e 100644 --- a/x-pack/plugins/lens/public/editor_frame_service/editor_frame/suggestion_panel.tsx +++ b/x-pack/plugins/lens/public/editor_frame_service/editor_frame/suggestion_panel.tsx @@ -64,7 +64,6 @@ import { selectFrameDatasourceAPI, } from '../../state_management'; import { filterAndSortUserMessages } from '../../app_plugin/get_application_user_messages'; - const MAX_SUGGESTIONS_DISPLAYED = 5; const LOCAL_STORAGE_SUGGESTIONS_PANEL = 'LENS_SUGGESTIONS_PANEL_HIDDEN'; @@ -108,11 +107,13 @@ const PreviewRenderer = ({ ExpressionRendererComponent, expression, hasError, + onRender, }: { withLabel: boolean; expression: string | null | undefined; ExpressionRendererComponent: ReactExpressionRendererType; hasError: boolean; + onRender: () => void; }) => { const onErrorMessage = (
@@ -143,6 +144,7 @@ const PreviewRenderer = ({ padding="s" renderMode="preview" expression={expression} + onRender$={onRender} debounce={2000} renderError={() => { return onErrorMessage; @@ -159,6 +161,7 @@ const SuggestionPreview = ({ selected, onSelect, showTitleAsLabel, + onRender, }: { onSelect: () => void; preview: { @@ -170,6 +173,7 @@ const SuggestionPreview = ({ ExpressionRenderer: ReactExpressionRendererType; selected: boolean; showTitleAsLabel?: boolean; + onRender: () => void; }) => { return ( @@ -194,6 +198,7 @@ const SuggestionPreview = ({ expression={preview.expression && toExpression(preview.expression)} withLabel={Boolean(showTitleAsLabel)} hasError={Boolean(preview.error)} + onRender={onRender} /> ) : ( @@ -358,20 +363,36 @@ export function SuggestionPanel({ // eslint-disable-next-line react-hooks/exhaustive-deps }, [existsStagedPreview]); - if (!activeDatasourceId) { - return null; - } - - if (suggestions.length === 0) { - return null; - } + const startTime = useRef(0); + const initialRenderComplete = useRef(false); + const suggestionsRendered = useRef([]); + const totalSuggestions = suggestions.length + 1; + + const onSuggestionRender = useCallback((suggestionIndex: number) => { + suggestionsRendered.current[suggestionIndex] = true; + if (initialRenderComplete.current === false && suggestionsRendered.current.every(Boolean)) { + initialRenderComplete.current = true; + // console.log( + // 'time to fetch data and perform initial render for all suggestions', + // performance.now() - startTime.current + // ); + } + }, []); - function rollbackToCurrentVisualization() { + const rollbackToCurrentVisualization = useCallback(() => { if (lastSelectedSuggestion !== -1) { setLastSelectedSuggestion(-1); dispatchLens(rollbackSuggestion()); dispatchLens(applyChanges()); } + }, [dispatchLens, lastSelectedSuggestion]); + + if (!activeDatasourceId) { + return null; + } + + if (suggestions.length === 0) { + return null; } const renderApplyChangesPrompt = () => ( @@ -400,52 +421,58 @@ export function SuggestionPanel({ ); - const renderSuggestionsUI = () => ( - <> - {currentVisualization.activeId && !hideSuggestions && ( - - )} - {!hideSuggestions && - suggestions.map((suggestion, index) => { - return ( - { - if (lastSelectedSuggestion === index) { - rollbackToCurrentVisualization(); - } else { - setLastSelectedSuggestion(index); - switchToSuggestion(dispatchLens, suggestion, { applyImmediately: true }); - } - }} - selected={index === lastSelectedSuggestion} - /> - ); - })} - - ); + const renderSuggestionsUI = () => { + suggestionsRendered.current = new Array(totalSuggestions).fill(false); + startTime.current = performance.now(); + return ( + <> + {currentVisualization.activeId && !hideSuggestions && ( + onSuggestionRender(0)} + /> + )} + {!hideSuggestions && + suggestions.map((suggestion, index) => { + return ( + { + if (lastSelectedSuggestion === index) { + rollbackToCurrentVisualization(); + } else { + setLastSelectedSuggestion(index); + switchToSuggestion(dispatchLens, suggestion, { applyImmediately: true }); + } + }} + selected={index === lastSelectedSuggestion} + onRender={() => onSuggestionRender(index + 1)} + /> + ); + })} + + ); + }; return (
diff --git a/x-pack/plugins/lens/public/editor_frame_service/editor_frame/workspace_panel/workspace_panel.tsx b/x-pack/plugins/lens/public/editor_frame_service/editor_frame/workspace_panel/workspace_panel.tsx index f4767124afb81..3f92236c99e5d 100644 --- a/x-pack/plugins/lens/public/editor_frame_service/editor_frame/workspace_panel/workspace_panel.tsx +++ b/x-pack/plugins/lens/public/editor_frame_service/editor_frame/workspace_panel/workspace_panel.tsx @@ -138,6 +138,10 @@ export const WorkspacePanel = React.memo(function WorkspacePanel(props: Workspac ); }); +const log = (...messages: Array) => { + // console.log(...messages); +}; + // Exported for testing purposes only. export const InnerWorkspacePanel = React.memo(function InnerWorkspacePanel({ framePublicAPI, @@ -170,7 +174,10 @@ export const InnerWorkspacePanel = React.memo(function InnerWorkspacePanel({ errors: [], }); - const initialRenderComplete = useRef(); + const initialVisualizationRenderComplete = useRef(false); + + // NOTE: This does not reflect the actual visualization render + const initialWorkspaceRenderComplete = useRef(); const renderDeps = useRef<{ datasourceMap: DatasourceMap; @@ -192,8 +199,20 @@ export const InnerWorkspacePanel = React.memo(function InnerWorkspacePanel({ dataViews, }; + // NOTE: initialRenderTime is only set once when the component mounts + const visualizationRenderStartTime = useRef(NaN); + const dataReceivedTime = useRef(NaN); + const onRender$ = useCallback(() => { if (renderDeps.current) { + if (!initialVisualizationRenderComplete.current) { + initialVisualizationRenderComplete.current = true; + // NOTE: this metric is only reported for an initial editor load of a pre-existing visualization + log( + 'initial visualization took to render after data received', + performance.now() - dataReceivedTime.current + ); + } const datasourceEvents = Object.values(renderDeps.current.datasourceMap).reduce( (acc, datasource) => { if (!renderDeps.current!.datasourceStates[datasource.id]) return []; @@ -232,6 +251,15 @@ export const InnerWorkspacePanel = React.memo(function InnerWorkspacePanel({ const onData$ = useCallback( (_data: unknown, adapters?: Partial) => { if (renderDeps.current) { + dataReceivedTime.current = performance.now(); + if (!initialVisualizationRenderComplete.current) { + // NOTE: this metric is only reported for an initial editor load of a pre-existing visualization + log( + 'initial data took to arrive', + dataReceivedTime.current - visualizationRenderStartTime.current + ); + } + const [defaultLayerId] = Object.keys(renderDeps.current.datasourceLayers); const datasource = Object.values(renderDeps.current.datasourceMap)[0]; const datasourceState = Object.values(renderDeps.current.datasourceStates)[0].state; @@ -276,7 +304,8 @@ export const InnerWorkspacePanel = React.memo(function InnerWorkspacePanel({ [addUserMessages, dispatchLens, plugins.data.search] ); - const shouldApplyExpression = autoApplyEnabled || !initialRenderComplete.current || triggerApply; + const shouldApplyExpression = + autoApplyEnabled || !initialWorkspaceRenderComplete.current || triggerApply; const activeVisualization = visualization.activeId ? visualizationMap[visualization.activeId] : null; @@ -389,9 +418,9 @@ export const InnerWorkspacePanel = React.memo(function InnerWorkspacePanel({ // null signals an empty workspace which should count as an initial render if ( (expressionExists || localState.expressionToRender === null) && - !initialRenderComplete.current + !initialWorkspaceRenderComplete.current ) { - initialRenderComplete.current = true; + initialWorkspaceRenderComplete.current = true; } }, [expressionExists, localState.expressionToRender]); @@ -559,7 +588,6 @@ export const InnerWorkspacePanel = React.memo(function InnerWorkspacePanel({ return ( { + visualizationRenderStartTime.current = performance.now(); + }} /> ); }; @@ -656,7 +686,6 @@ function useReportingState(errors: UserMessage[]): { export const VisualizationWrapper = ({ expression, - framePublicAPI, lensInspector, onEvent, hasCompatibleActions, @@ -665,12 +694,11 @@ export const VisualizationWrapper = ({ errors, ExpressionRendererComponent, core, - activeDatasourceId, onRender$, onData$, + onComponentRendered, }: { expression: string | null | undefined; - framePublicAPI: FramePublicAPI; lensInspector: LensInspector; onEvent: (event: ExpressionRendererEvent) => void; hasCompatibleActions: (event: ExpressionRendererEvent) => Promise; @@ -679,14 +707,25 @@ export const VisualizationWrapper = ({ errors: UserMessage[]; ExpressionRendererComponent: ReactExpressionRendererType; core: CoreStart; - activeDatasourceId: string | null; onRender$: () => void; onData$: (data: unknown, adapters?: Partial) => void; + onComponentRendered: () => void; }) => { + useEffect(() => { + onComponentRendered(); + // eslint-disable-next-line react-hooks/exhaustive-deps + }, []); + const context = useLensSelector(selectExecutionContext); // Used for reporting const { isRenderComplete, hasDynamicError, setIsRenderComplete, setDynamicError, nodeRef } = useReportingState(errors); + + const onRenderHandler = useCallback(() => { + setIsRenderComplete(true); + onRender$(); + }, [setIsRenderComplete, onRender$]); + const searchContext: ExecutionContextSearch = useMemo( () => ({ query: context.query, @@ -782,10 +821,7 @@ export const VisualizationWrapper = ({ onEvent={onEvent} hasCompatibleActions={hasCompatibleActions} onData$={onData$} - onRender$={() => { - setIsRenderComplete(true); - onRender$(); - }} + onRender$={onRenderHandler} inspectorAdapters={lensInspector.adapters} executionContext={executionContext} renderMode="edit"