Performance instrumentation

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"
-
     }
   }
 }

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<Props & ReduxStateProps> {
 }
 
 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,

app/client/src/configs/dev.config.ts

@@ -15,6 +15,7 @@ const devConfig = (baseUrl: string): AppsmithUIConfigs => ({
   },
   apiUrl: "/api/",
   baseUrl,
+  logLevel: "debug",
 });
 
 export default devConfig;

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;

app/client/src/configs/stage.config.ts

@@ -15,6 +15,7 @@ const stageConfig = (baseUrl: string): AppsmithUIConfigs => ({
   },
   apiUrl: "/api/",
   baseUrl,
+  logLevel: "info",
 });
 
 export default stageConfig;

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;
 };

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,

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 = <Canvas dsl={props.widgets} />;
   }
+  log.debug("Canvas rendered");
   return (
     <EditorContextProvider>
       <EditorWrapper onClick={handleWrapperClick}>

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<ExecuteActionPayload>) {
   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<PageAction[][]>) {
   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)));
   }
 }

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<string, any> = {};
     if (actions && actions.length) {
       actions.forEach(action => {

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<WidgetProps> => {
+    log.debug("Evaluating data tree to get canvas widgets");
     const widgets = { ...entities.canvasWidgets };
     Object.keys(widgets).forEach(widgetKey => {
       const evaluatedWidget = _.find(evaluatedDataTree, {

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,

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()

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<string, Array<string>>;
 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;

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"