From fddeb7a628cc61a249861136d0dc01892502a6d1 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 affbff3ea9b2cbf..4684a160881b8f8 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 ab70211361e4669..95856d1bae485d2 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 209608c260ecaa7..6e96c2ab06cdfd8 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 f0aa3c3e1dede39..cb352fe883152eb 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 a321aaf181e2d26..c151741158ac1fe 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 7fe65370693d58c..adfc3df81f97fa7 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 0c19cc72d691c77..e1ad4fa19d1c085 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 36d8b4104e64c33..11f50252b993edc 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 f4767124afb81a1..3f92236c99e5d72 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"