From 80db9eb030ca5422df284dde55ec28539a35eb46 Mon Sep 17 00:00:00 2001 From: Hetu Nandu Date: Mon, 23 Mar 2020 12:40:17 +0000 Subject: [PATCH] Performance instrumentation --- app/client/package.json | 2 +- .../editorComponents/DynamicActionCreator.tsx | 3 +- app/client/src/configs/dev.config.ts | 1 + app/client/src/configs/prod.config.ts | 1 + app/client/src/configs/stage.config.ts | 1 + app/client/src/configs/types.ts | 3 + .../src/pages/Editor/PropertyPane/index.tsx | 2 + app/client/src/pages/Editor/WidgetsEditor.tsx | 2 + app/client/src/sagas/ActionSagas.ts | 6 +- app/client/src/selectors/dataTreeSelectors.ts | 2 + app/client/src/selectors/editorSelectors.tsx | 2 + .../src/selectors/propertyPaneSelectors.tsx | 2 + app/client/src/utils/AppsmithUtils.tsx | 3 + app/client/src/utils/DynamicBindingUtils.ts | 139 ++++++++++++------ app/client/yarn.lock | 5 + 15 files changed, 128 insertions(+), 46 deletions(-) diff --git a/app/client/package.json b/app/client/package.json index c4646a43a0..9eaf2e58a4 100644 --- a/app/client/package.json +++ b/app/client/package.json @@ -55,6 +55,7 @@ "lint-staged": "^9.2.5", "localforage": "^1.7.3", "lodash": "^4.17.11", + "loglevel": "^1.6.7", "moment": "^2.24.0", "moment-timezone": "^0.5.27", "nanoid": "^2.0.4", @@ -161,7 +162,6 @@ "husky": { "hooks": { "pre-commit": "lint-staged" - } } } diff --git a/app/client/src/components/editorComponents/DynamicActionCreator.tsx b/app/client/src/components/editorComponents/DynamicActionCreator.tsx index 92d121d5e6..b2238fd72f 100644 --- a/app/client/src/components/editorComponents/DynamicActionCreator.tsx +++ b/app/client/src/components/editorComponents/DynamicActionCreator.tsx @@ -7,6 +7,7 @@ import { ControlWrapper } from "components/propertyControls/StyledControls"; import { InputText } from "components/propertyControls/InputTextControl"; import StyledDropdown from "components/editorComponents/StyledDropdown"; import { ActionDataState } from "reducers/entityReducers/actionsReducer"; +import { getActionsForCurrentPage } from "selectors/entitiesSelector"; const ACTION_TRIGGER_REGEX = /^{{([\s\S]*?)\(([\s\S]*?)\)}}$/g; const ACTION_ANONYMOUS_FUNC_REGEX = /\(\) => ([\s\S]*?)(\([\s\S]*?\))/g; @@ -442,7 +443,7 @@ class DynamicActionCreator extends React.Component { } const mapStateToProps = (state: AppState): ReduxStateProps => ({ - actions: state.entities.actions, + actions: getActionsForCurrentPage(state), pageNameDropdown: state.entities.pageList.pages.map(p => ({ label: p.pageName, id: p.pageId, diff --git a/app/client/src/configs/dev.config.ts b/app/client/src/configs/dev.config.ts index a15219523a..824cb166bb 100644 --- a/app/client/src/configs/dev.config.ts +++ b/app/client/src/configs/dev.config.ts @@ -15,6 +15,7 @@ const devConfig = (baseUrl: string): AppsmithUIConfigs => ({ }, apiUrl: "/api/", baseUrl, + logLevel: "debug", }); export default devConfig; diff --git a/app/client/src/configs/prod.config.ts b/app/client/src/configs/prod.config.ts index 51846cea2c..be76c0e227 100644 --- a/app/client/src/configs/prod.config.ts +++ b/app/client/src/configs/prod.config.ts @@ -23,6 +23,7 @@ export const prodConfig = (baseUrl: string): AppsmithUIConfigs => ({ }, apiUrl: "/api/", baseUrl, + logLevel: "error", }); export default prodConfig; diff --git a/app/client/src/configs/stage.config.ts b/app/client/src/configs/stage.config.ts index fd16a33307..584f772bce 100644 --- a/app/client/src/configs/stage.config.ts +++ b/app/client/src/configs/stage.config.ts @@ -15,6 +15,7 @@ const stageConfig = (baseUrl: string): AppsmithUIConfigs => ({ }, apiUrl: "/api/", baseUrl, + logLevel: "info", }); export default stageConfig; diff --git a/app/client/src/configs/types.ts b/app/client/src/configs/types.ts index 40a0fa6b4b..4bff0fd7ad 100644 --- a/app/client/src/configs/types.ts +++ b/app/client/src/configs/types.ts @@ -1,3 +1,5 @@ +import { LogLevelDesc } from "loglevel"; + export type SentryConfig = { dsn: string; environment: string; @@ -23,4 +25,5 @@ export type AppsmithUIConfigs = { }; apiUrl: string; baseUrl: string; + logLevel: LogLevelDesc; }; diff --git a/app/client/src/pages/Editor/PropertyPane/index.tsx b/app/client/src/pages/Editor/PropertyPane/index.tsx index fa414160e8..7cfa21b961 100644 --- a/app/client/src/pages/Editor/PropertyPane/index.tsx +++ b/app/client/src/pages/Editor/PropertyPane/index.tsx @@ -29,6 +29,7 @@ import { WidgetProps } from "widgets/BaseWidget"; import PropertyPaneTitle from "pages/Editor/PropertyPaneTitle"; import PropertyControl from "pages/Editor/PropertyPane/PropertyControl"; import AnalyticsUtil from "utils/AnalyticsUtil"; +import * as log from "loglevel"; const PropertySectionLabel = styled.div` text-transform: uppercase; @@ -55,6 +56,7 @@ class PropertyPane extends Component< render() { if (this.props.isVisible) { + log.debug("Property pane rendered"); const content = this.renderPropertyPane(this.props.propertySections); const el = document.getElementsByClassName( WIDGET_CLASSNAME_PREFIX + this.props.widgetId, diff --git a/app/client/src/pages/Editor/WidgetsEditor.tsx b/app/client/src/pages/Editor/WidgetsEditor.tsx index fc749629d8..3f51b766f1 100644 --- a/app/client/src/pages/Editor/WidgetsEditor.tsx +++ b/app/client/src/pages/Editor/WidgetsEditor.tsx @@ -19,6 +19,7 @@ import EditorContextProvider from "components/editorComponents/EditorContextProv import { Spinner } from "@blueprintjs/core"; import { useWidgetSelection } from "utils/hooks/dragResizeHooks"; import AnalyticsUtil from "utils/AnalyticsUtil"; +import * as log from "loglevel"; const EditorWrapper = styled.div` display: flex; @@ -94,6 +95,7 @@ const WidgetsEditor = (props: EditorProps) => { if (!props.isFetchingPage && props.widgets) { node = ; } + log.debug("Canvas rendered"); return ( diff --git a/app/client/src/sagas/ActionSagas.ts b/app/client/src/sagas/ActionSagas.ts index b02a3999e4..f25e60e2ac 100644 --- a/app/client/src/sagas/ActionSagas.ts +++ b/app/client/src/sagas/ActionSagas.ts @@ -57,7 +57,6 @@ import { API_EDITOR_FORM_NAME } from "constants/forms"; import { executeAction, executeActionError } from "actions/widgetActions"; import { evaluateDataTree } from "selectors/dataTreeSelectors"; import { transformRestAction } from "transformers/RestActionTransformer"; -import { getActionResponses } from "selectors/entitiesSelector"; import { ActionDescription, RunActionPayload, @@ -73,6 +72,7 @@ import { } from "constants/routes"; import { ToastType } from "react-toastify"; import AnalyticsUtil from "utils/AnalyticsUtil"; +import * as log from "loglevel"; export const getAction = ( state: AppState, @@ -127,6 +127,7 @@ const createActionErrorResponse = ( }); export function* evaluateDynamicBoundValueSaga(path: string): any { + log.debug("Evaluating data tree to get action binding value"); const tree = yield select(evaluateDataTree); const dynamicResult = getDynamicValue(`{{${path}}}`, tree); return dynamicResult.result; @@ -331,6 +332,7 @@ export function* executeActionTriggers( export function* executeAppAction(action: ReduxAction) { const { dynamicString, event, responseData } = action.payload; + log.debug("Evaluating data tree to get action trigger"); const tree = yield select(evaluateDataTree); const { triggers } = getDynamicValue(dynamicString, tree, responseData, true); if (triggers && triggers.length) { @@ -590,7 +592,7 @@ function* executePageLoadAction(pageAction: PageAction) { function* executePageLoadActionsSaga(action: ReduxAction) { const pageActions = action.payload; for (const actionSet of pageActions) { - const apiResponses = yield select(getActionResponses); + // Load all sets in parallel yield* yield all(actionSet.map(a => call(executePageLoadAction, a))); } } diff --git a/app/client/src/selectors/dataTreeSelectors.ts b/app/client/src/selectors/dataTreeSelectors.ts index 793414b8ca..adeb0d4678 100644 --- a/app/client/src/selectors/dataTreeSelectors.ts +++ b/app/client/src/selectors/dataTreeSelectors.ts @@ -6,6 +6,7 @@ import { extraLibraries } from "jsExecution/JSExecutionManagerSingleton"; import { DataTree, DataTreeFactory } from "entities/DataTree/dataTreeFactory"; import _ from "lodash"; import { getWidgets, getWidgetsMeta } from "sagas/selectors"; +import * as log from "loglevel"; export const getUnevaluatedDataTree = createSelector( getActionsForCurrentPage, @@ -29,6 +30,7 @@ export const getDataTreeForAutocomplete = createSelector( evaluateDataTree, getActionsForCurrentPage, (tree: DataTree, actions: ActionDataState) => { + log.debug("Evaluating data tree to get autocomplete values"); const cachedResponses: Record = {}; if (actions && actions.length) { actions.forEach(action => { diff --git a/app/client/src/selectors/editorSelectors.tsx b/app/client/src/selectors/editorSelectors.tsx index 7bce32a0c3..e7f45c7eb9 100644 --- a/app/client/src/selectors/editorSelectors.tsx +++ b/app/client/src/selectors/editorSelectors.tsx @@ -19,6 +19,7 @@ import { evaluateDataTree } from "selectors/dataTreeSelectors"; import _ from "lodash"; import { ContainerWidgetProps } from "widgets/ContainerWidget"; import { DataTreeWidget } from "entities/DataTree/dataTreeFactory"; +import * as log from "loglevel"; const getEditorState = (state: AppState) => state.ui.editor; const getWidgetConfigs = (state: AppState) => state.entities.widgetConfig; @@ -125,6 +126,7 @@ export const getCanvasWidgetDsl = createSelector( entities: AppState["entities"], evaluatedDataTree, ): ContainerWidgetProps => { + log.debug("Evaluating data tree to get canvas widgets"); const widgets = { ...entities.canvasWidgets }; Object.keys(widgets).forEach(widgetKey => { const evaluatedWidget = _.find(evaluatedDataTree, { diff --git a/app/client/src/selectors/propertyPaneSelectors.tsx b/app/client/src/selectors/propertyPaneSelectors.tsx index 80eeb997b7..5ab44bf24c 100644 --- a/app/client/src/selectors/propertyPaneSelectors.tsx +++ b/app/client/src/selectors/propertyPaneSelectors.tsx @@ -8,6 +8,7 @@ import { WidgetProps } from "widgets/BaseWidget"; import { DataTree, DataTreeWidget } from "entities/DataTree/dataTreeFactory"; import _ from "lodash"; import { evaluateDataTree } from "selectors/dataTreeSelectors"; +import * as log from "loglevel"; const getPropertyPaneState = (state: AppState): PropertyPaneReduxState => state.ui.propertyPane; @@ -41,6 +42,7 @@ export const getWidgetPropsForPropertyPane = createSelector( widget: WidgetProps | undefined, evaluatedTree: DataTree, ): WidgetProps | undefined => { + log.debug("Evaluating data tree to get property pane validations"); if (!widget) return undefined; const evaluatedWidget = _.find(evaluatedTree, { widgetId: widget.widgetId, diff --git a/app/client/src/utils/AppsmithUtils.tsx b/app/client/src/utils/AppsmithUtils.tsx index cb43078d18..ffe4427c3d 100644 --- a/app/client/src/utils/AppsmithUtils.tsx +++ b/app/client/src/utils/AppsmithUtils.tsx @@ -9,6 +9,7 @@ import { Property } from "api/ActionAPI"; import _ from "lodash"; import moment from "moment-timezone"; import ValidationRegistry from "./ValidationRegistry"; +import * as log from "loglevel"; export const createReducer = ( initialState: any, @@ -40,6 +41,8 @@ export const appInitializer = () => { AnalyticsUtil.initializeSegment(appsmithConfigs.segment.key); } + log.setLevel(appsmithConfigs.logLevel); + const textFont = new FontFaceObserver("DM Sans"); textFont .load() diff --git a/app/client/src/utils/DynamicBindingUtils.ts b/app/client/src/utils/DynamicBindingUtils.ts index c2f678522d..d0ac1cc93c 100644 --- a/app/client/src/utils/DynamicBindingUtils.ts +++ b/app/client/src/utils/DynamicBindingUtils.ts @@ -14,6 +14,7 @@ import { DataTreeWidget, ENTITY_TYPE, } from "entities/DataTree/dataTreeFactory"; +import * as log from "loglevel"; export const removeBindingsFromObject = (obj: object) => { const string = JSON.stringify(obj); @@ -209,15 +210,54 @@ export const getValidatedTree = (tree: any) => { }, tree); }; -export const getEvaluatedDataTree = (dataTree: DataTree): DataTree => { - const dynamicDependencyMap = createDependencyTree(dataTree); - const evaluatedTree = dependencySortedEvaluateDataTree( - dataTree, - dynamicDependencyMap, - ); - const treeWithLoading = setTreeLoading(evaluatedTree, dynamicDependencyMap); - return getValidatedTree(treeWithLoading); -}; +function instrumentedGetEvaluatedDataTree(): (dataTree: DataTree) => DataTree { + let count = 0; + return (dataTree: DataTree) => { + // increase count + count++; + // count total time taken + const totalStart = performance.now(); + + // Create Dependencies DAG + const createDepsStart = performance.now(); + const dynamicDependencyMap = createDependencyTree(dataTree); + const createDepsEnd = performance.now(); + + // Evaluate Tree + const evaluatedTreeStart = performance.now(); + const evaluatedTree = dependencySortedEvaluateDataTree( + dataTree, + dynamicDependencyMap, + ); + const evaluatedTreeEnd = performance.now(); + + // Set Loading Widgets + const loadingTreeStart = performance.now(); + const treeWithLoading = setTreeLoading(evaluatedTree, dynamicDependencyMap); + const loadingTreeEnd = performance.now(); + + // Validate Widgets + const validated = getValidatedTree(treeWithLoading); + + // End counting total time + const endStart = performance.now(); + + // Log time taken and count + const timeTaken = { + total: (endStart - totalStart).toFixed(2), + createDeps: (createDepsEnd - createDepsStart).toFixed(2), + evaluate: (evaluatedTreeEnd - evaluatedTreeStart).toFixed(2), + loading: (loadingTreeEnd - loadingTreeStart).toFixed(2), + }; + log.debug("data tree evaluated", { + timeTaken, + count, + }); + return validated; + }; +} + +export const getEvaluatedDataTree = instrumentedGetEvaluatedDataTree(); type DynamicDependencyMap = Record>; export const createDependencyTree = ( @@ -341,45 +381,60 @@ export function dependencySortedEvaluateDataTree( const tree = _.cloneDeep(dataTree); try { // sort dependencies and remove empty dependencies + const sortStart = performance.now(); const sortedDependencies = toposort(dependencyTree) .reverse() .filter(d => !!d); + const sortEnd = performance.now(); // evaluate and replace values - return sortedDependencies.reduce((currentTree: DataTree, path: string) => { - const entityName = path.split(".")[0]; - const entity: DataTreeEntity = currentTree[entityName]; - let result = _.get(currentTree as any, path); - if (isDynamicValue(result)) { - try { - const dynamicResult = getDynamicValue(result, currentTree); - result = dynamicResult.result; - } catch (e) { - console.error(e); - result = undefined; + const evalStart = performance.now(); + const final = sortedDependencies.reduce( + (currentTree: DataTree, path: string) => { + const entityName = path.split(".")[0]; + const entity: DataTreeEntity = currentTree[entityName]; + let result = _.get(currentTree as any, path); + if (isDynamicValue(result)) { + try { + const dynamicResult = getDynamicValue(result, currentTree); + result = dynamicResult.result; + } catch (e) { + console.error(e); + result = undefined; + } } - } - if ( - "ENTITY_TYPE" in entity && - entity.ENTITY_TYPE === ENTITY_TYPE.WIDGET - ) { - const propertyPath = path.split(".")[1]; - const { - parsed, - isValid, - message, - } = ValidationFactory.validateWidgetProperty( - entity.type, - propertyPath, - result, - ); - result = parsed; - if (!isValid) { - _.set(entity, `invalidProps.${propertyPath}`, true); - _.set(entity, `validationMessages.${propertyPath}`, message); + if ( + "ENTITY_TYPE" in entity && + entity.ENTITY_TYPE === ENTITY_TYPE.WIDGET + ) { + const propertyPath = path.split(".")[1]; + const { + parsed, + isValid, + message, + } = ValidationFactory.validateWidgetProperty( + entity.type, + propertyPath, + result, + ); + result = parsed; + if (!isValid) { + _.set(entity, `invalidProps.${propertyPath}`, true); + _.set(entity, `validationMessages.${propertyPath}`, message); + } } - } - return _.set(currentTree, path, result); - }, tree); + return _.set(currentTree, path, result); + }, + tree, + ); + const evalEnd = performance.now(); + + log.debug({ + depLength: sortedDependencies.length, + sort: (sortEnd - sortStart).toFixed(2), + eval: (evalEnd - evalStart).toFixed(2), + }); + + return final; } catch (e) { console.error(e); return tree; diff --git a/app/client/yarn.lock b/app/client/yarn.lock index 361acd7028..67644b482b 100644 --- a/app/client/yarn.lock +++ b/app/client/yarn.lock @@ -8745,6 +8745,11 @@ loglevel@^1.6.6: version "1.6.6" resolved "https://registry.yarnpkg.com/loglevel/-/loglevel-1.6.6.tgz#0ee6300cc058db6b3551fa1c4bf73b83bb771312" +loglevel@^1.6.7: + version "1.6.7" + resolved "https://registry.yarnpkg.com/loglevel/-/loglevel-1.6.7.tgz#b3e034233188c68b889f5b862415306f565e2c56" + integrity sha512-cY2eLFrQSAfVPhCgH1s7JI73tMbg9YC3v3+ZHVW67sBS7UxWzNEk/ZBbSfLykBWHp33dqqtOv82gjhKEi81T/A== + loglevelnext@^1.0.1: version "1.0.5" resolved "https://registry.yarnpkg.com/loglevelnext/-/loglevelnext-1.0.5.tgz#36fc4f5996d6640f539ff203ba819641680d75a2"