From 6acaa8d2739a683b213e0c498c08981fe7ec9fec 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 affbff3ea9b2cb..4684a160881b8f 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 ab70211361e466..95856d1bae485d 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 209608c260ecaa..6e96c2ab06cdfd 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 f0aa3c3e1dede3..cb352fe883152e 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 a321aaf181e2d2..c151741158ac1f 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 7fe65370693d58..adfc3df81f97fa 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 0c19cc72d691c7..e1ad4fa19d1c08 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 36d8b4104e64c3..11f50252b993ed 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 f4767124afb81a..3f92236c99e5d7 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"