fix: updating trigger meta to get the source of console logs (#16520)

For nested functions, the trigger meta is not available for subsequent functions. So in cases where the dynamic trigger has the relevant info, we can use that to update the trigger meta and then use that meta to display the source of the logs. Fixes #16515 Fixes #16483 Fixes #16514 Co-authored-by: Aishwarya UR <aishwarya@appsmith.com>
2022-09-07 11:53:47 +05:30 · 2022-09-07 11:53:47 +05:30 · e53045de5a
commit e53045de5a
parent 8a7ec8560e
7 changed files with 157 additions and 68 deletions
--- a/app/client/cypress/integration/Smoke_TestSuite/ClientSideTests/OtherUIFeatures/Logs_spec.js
+++ b/app/client/cypress/integration/Smoke_TestSuite/ClientSideTests/OtherUIFeatures/Logs_spec.js
@ -118,7 +118,25 @@ describe("Debugger logs", function() {
    agHelper.GetNAssertContains(locator._debuggerLogMessage, logStringChild);
  });

-  it("8. Console log in sync function", function() {
+  it("8. Console log on text widget with normal moustache binding", function() {
+    ee.DragDropWidgetNVerify("textwidget", 400, 400);
+    propPane.UpdatePropertyFieldValue(
+      "Text",
+      `{{(function(){
+  	const temp = "Hello!"
+
+  	console.log("${logString}");
+  	return temp;
+  })()}}`,
+    );
+    agHelper.RefreshPage();
+    // Wait for the debugger icon to be visible
+    agHelper.AssertElementVisible(".t--debugger");
+    agHelper.GetNClick(locator._debuggerIcon);
+    agHelper.GetNAssertContains(locator._debuggerLogMessage, logString);
+  });
+
+  it("9. Console log in sync function", function() {
    ee.NavigateToSwitcher("explorer");
    jsEditor.CreateJSObject(
      `export default {
@ -142,7 +160,7 @@ describe("Debugger logs", function() {
    agHelper.GetNAssertContains(locator._debuggerLogMessage, logString);
  });

-  it("9. Console log in async function", function() {
+  it("10. Console log in async function", function() {
    ee.NavigateToSwitcher("explorer");
    jsEditor.CreateJSObject(
      `export default {
@ -168,13 +186,67 @@ describe("Debugger logs", function() {
    agHelper.GetNAssertContains(locator._debuggerLogMessage, logString);
  });

-  it("10. Console log after API succedes", function() {
+  it("11. Console log after API succedes", function() {
    ee.NavigateToSwitcher("explorer");
-    apiPage.CreateAndFillApi(dataSet.baseUrl + dataSet.methods, "Test1");
+    apiPage.CreateAndFillApi(dataSet.baseUrl + dataSet.methods, "Api1");
+    const returnText = "success";
    jsEditor.CreateJSObject(
      `export default {
        myFun1: async () => {
-          return Test1.run().then(()=>{
+          return storeValue("test", "test").then(() => {
+            console.log("${logString} Started");
+            return Api1.run().then(()=>{
+              console.log("${logString} Success");
+              return "${returnText}";
+            }).catch(()=>{
+              console.log("${logString} Failed");
+              return "fail";
+            });
+          });
+        },
+        myFun2: () => {
+          return 1;
+        }
+      }`,
+      {
+        paste: true,
+        completeReplace: true,
+        toRun: false,
+        shouldCreateNewJSObj: true,
+      },
+    );
+    agHelper.WaitUntilAllToastsDisappear();
+
+    cy.get("@jsObjName").then((jsObjName) => {
+      agHelper.GetNClick(jsEditor._runButton);
+      agHelper.GetNClick(jsEditor._logsTab);
+      agHelper.GetNAssertContains(
+        locator._debuggerLogMessage,
+        `${logString} Started`,
+      );
+      agHelper.GetNAssertContains(
+        locator._debuggerLogMessage,
+        `${logString} Success`,
+      );
+      ee.DragDropWidgetNVerify("textwidget", 200, 600);
+      propPane.UpdatePropertyFieldValue("Text", `{{${jsObjName}.myFun1.data}}`);
+      agHelper.GetNAssertElementText(
+        commonlocators.textWidgetContainer,
+        returnText,
+        "have.text",
+        1,
+      );
+    });
+  });
+
+  it("12. Console log after API execution fails", function() {
+    ee.NavigateToSwitcher("explorer");
+    apiPage.CreateAndFillApi(dataSet.baseUrl + dataSet.methods + "xyz", "Api2");
+    jsEditor.CreateJSObject(
+      `export default {
+        myFun1: async () => {
+          console.log("${logString} Started");
+          return Api2.run().then(()=>{
            console.log("${logString} Success");
            return "success";
          }).catch(()=>{
@ -198,47 +270,45 @@ describe("Debugger logs", function() {
    agHelper.GetNClick(jsEditor._logsTab);
    agHelper.GetNAssertContains(
      locator._debuggerLogMessage,
-      `${logString} Success`,
+      `${logString} Started`,
    );
-  });
-
-  it("11. Console log after API execution fails", function() {
-    ee.NavigateToSwitcher("explorer");
-    apiPage.CreateAndFillApi(
-      dataSet.baseUrl + dataSet.methods + "xyz",
-      "Test2",
-    );
-    jsEditor.CreateJSObject(
-      `export default {
-        myFun1: async () => {
-          return Test2.run().then(()=>{
-            console.log("${logString} Success");
-            return "success";
-          }).catch(()=>{
-            console.log("${logString} Failed");
-            return "fail";
-          });
-        },
-        myFun2: () => {
-          return 1;
-        }
-      }`,
-      {
-        paste: true,
-        completeReplace: true,
-        toRun: false,
-        shouldCreateNewJSObj: true,
-      },
-    );
-    agHelper.WaitUntilAllToastsDisappear();
-    agHelper.GetNClick(jsEditor._runButton);
-    agHelper.GetNClick(jsEditor._logsTab);
    agHelper.GetNAssertContains(
      locator._debuggerLogMessage,
      `${logString} Failed`,
    );
  });

+  it("13. Console log source inside nested function", function() {
+    jsEditor.CreateJSObject(
+      `export default {
+        myFun1: async () => {
+          console.log("Parent ${logString}");
+          return Api1.run(()=>{console.log("Child ${logString}");});
+        },
+        myFun2: () => {
+          return 1;
+        }
+      }`,
+      {
+        paste: true,
+        completeReplace: true,
+        toRun: false,
+        shouldCreateNewJSObj: false,
+      },
+    );
+    agHelper.WaitUntilAllToastsDisappear();
+    agHelper.GetNClick(jsEditor._runButton);
+    agHelper.GetNClick(jsEditor._logsTab);
+    agHelper.GetNAssertContains(
+      locator._debuggerLogMessage,
+      `Parent ${logString}`,
+    );
+    agHelper.GetNAssertContains(
+      locator._debuggerLogMessage,
+      `Child ${logString}`,
+    );
+  });
+
  // it("Api headers need to be shown as headers in logs", function() {
  //   // TODO
  // });
--- a/app/client/src/sagas/DebuggerSagas.ts
+++ b/app/client/src/sagas/DebuggerSagas.ts
@ -53,7 +53,6 @@ import { getCurrentPageId } from "selectors/editorSelectors";
 import { WidgetProps } from "widgets/BaseWidget";
 import * as log from "loglevel";
 import { DependencyMap } from "utils/DynamicBindingUtils";
-import { EventType } from "constants/AppsmithActionConstants/ActionConstants";
 import { LogObject, createLogTitleString } from "workers/UserLog";
 import { TriggerMeta } from "./ActionExecution/ActionExecutionSagas";

@ -506,32 +505,27 @@ export function* storeLogs(
  });
 }

-// takes a log object array alognwith its source data and passes it on to the storeLogs saga
-export function* processAndStoreLogs(
+export function* updateTriggerMeta(
  triggerMeta: TriggerMeta,
-  logs: LogObject[],
  dynamicTrigger: string,
-  eventType: EventType,
 ) {
  let name = "";

-  if (!!triggerMeta.source && "name" in triggerMeta.source) {
+  if (!!triggerMeta.source && triggerMeta.source.hasOwnProperty("name")) {
    name = triggerMeta.source.name;
-  } else if (
-    !(dynamicTrigger.includes("{{") || dynamicTrigger.includes("}}"))
+  } else if (!!triggerMeta.triggerPropertyName) {
+    name = triggerMeta.triggerPropertyName;
+  }
+
+  if (
+    name.length === 0 &&
+    !!dynamicTrigger &&
+    !(dynamicTrigger.includes("{") || dynamicTrigger.includes("}"))
  ) {
    // We use the dynamic trigger as the name if it is not a binding
    name = dynamicTrigger.replace("()", "");
+    triggerMeta["triggerPropertyName"] = name;
  }
-  yield call(
-    storeLogs,
-    logs,
-    name,
-    eventType === EventType.ON_JS_FUNCTION_EXECUTE
-      ? ENTITY_TYPE.JSACTION
-      : ENTITY_TYPE.WIDGET,
-    triggerMeta.source?.id || "",
-  );
 }

 export default function* debuggerSagasListeners() {
--- a/app/client/src/sagas/EvaluationsSaga.ts
+++ b/app/client/src/sagas/EvaluationsSaga.ts
@ -99,7 +99,7 @@ import { CanvasWidgetsReduxState } from "reducers/entityReducers/canvasWidgetsRe
 import { AppTheme } from "entities/AppTheming";
 import { ActionValidationConfigMap } from "constants/PropertyControlConstants";
 import { LogObject, UserLogObject } from "workers/UserLog";
-import { processAndStoreLogs, storeLogs } from "./DebuggerSagas";
+import { storeLogs, updateTriggerMeta } from "./DebuggerSagas";

 let widgetTypeConfigMap: WidgetTypeConfigMap;

@ -181,10 +181,14 @@ function* evaluateTreeSaga(
  log.debug({ evalMetaUpdatesLength: evalMetaUpdates.length });

  const updatedDataTree: DataTree = yield select(getDataTree);
-  if (!!userLogs && userLogs.length > 0) {
+  if (
+    !(!isCreateFirstTree && Object.keys(jsUpdates).length > 0) &&
+    !!userLogs &&
+    userLogs.length > 0
+  ) {
    yield all(
      userLogs.map((log: UserLogObject) => {
-        call(
+        return call(
          storeLogs,
          log.logObject,
          log.source.name,
@ -271,6 +275,7 @@ export function* evaluateAndExecuteDynamicTrigger(
      keepAlive = false;

      const { result } = requestData;
+      yield call(updateTriggerMeta, triggerMeta, dynamicTrigger);

      // Check for any logs in the response and store them in the redux store
      if (
@ -280,11 +285,13 @@ export function* evaluateAndExecuteDynamicTrigger(
        result.logs.length
      ) {
        yield call(
-          processAndStoreLogs,
-          triggerMeta,
+          storeLogs,
          result.logs,
-          dynamicTrigger,
-          eventType,
+          triggerMeta.source?.name || triggerMeta.triggerPropertyName || "",
+          eventType === EventType.ON_JS_FUNCTION_EXECUTE
+            ? ENTITY_TYPE.JSACTION
+            : ENTITY_TYPE.WIDGET,
+          triggerMeta.source?.id || "",
        );
      }

--- a/app/client/src/workers/DataTreeEvaluator/index.ts
+++ b/app/client/src/workers/DataTreeEvaluator/index.ts
@ -882,12 +882,19 @@ export default class DataTreeEvaluator {
            !!entity && isJSAction(entity),
            contextData,
            callBackData,
+            fullPropertyPath?.includes("body") ||
+              !toBeSentForEval.includes("console."),
          );
          if (fullPropertyPath && result.errors.length) {
            addErrorToEntityProperty(result.errors, data, fullPropertyPath);
          }
          // if there are any console outputs found from the evaluation, extract them and add them to the logs array
-          if (!!entity && !!result.logs && result.logs.length > 0) {
+          if (
+            !!entity &&
+            !!result.logs &&
+            result.logs.length > 0 &&
+            !propertyPath.includes("body")
+          ) {
            let type = CONSOLE_ENTITY_TYPE.WIDGET;
            let id = "";

@ -985,6 +992,7 @@ export default class DataTreeEvaluator {
    createGlobalData: boolean,
    contextData?: EvaluateContext,
    callbackData?: Array<any>,
+    skipUserLogsOperations = false,
  ): EvalResult {
    try {
      return evaluateSync(
@ -994,6 +1002,7 @@ export default class DataTreeEvaluator {
        createGlobalData,
        contextData,
        callbackData,
+        skipUserLogsOperations,
      );
    } catch (error) {
      return {
--- a/app/client/src/workers/JSObject/index.ts
+++ b/app/client/src/workers/JSObject/index.ts
@ -99,6 +99,9 @@ export function saveResolvedFunctionsAndJSUpdates(
                unEvalDataTree,
                {},
                true,
+                undefined,
+                undefined,
+                true,
              );
              if (!!result) {
                let params: Array<{ key: string; value: unknown }> = [];
--- a/app/client/src/workers/UserLog.ts
+++ b/app/client/src/workers/UserLog.ts
@ -177,9 +177,9 @@ class UserLog {
    return returnData;
  }
  // returns the logs from the function execution after sanitising them and resets the logs object after that
-  public flushLogs(): LogObject[] {
+  public flushLogs(softFlush = false): LogObject[] {
    const userLogs = this.logs;
-    this.resetLogs();
+    if (!softFlush) this.resetLogs();
    // sanitise the data key of the user logs
    const sanitisedLogs = userLogs.map((log) => {
      return {
--- a/app/client/src/workers/evaluate.ts
+++ b/app/client/src/workers/evaluate.ts
@ -229,13 +229,18 @@ export default function evaluateSync(
  isJSCollection: boolean,
  context?: EvaluateContext,
  evalArguments?: Array<any>,
+  skipLogsOperations = false,
 ): EvalResult {
  return (function() {
    const errors: EvaluationError[] = [];
    let logs: LogObject[] = [];
    let result;
+    // skipping log reset if the js collection is being evaluated without run
+    // Doing this because the promise execution is losing logs in the process due to resets
+    if (!skipLogsOperations) {
+      userLogs.resetLogs();
+    }
    /**** Setting the eval context ****/
-    userLogs.resetLogs();
    const GLOBAL_DATA: Record<string, any> = createGlobalData({
      dataTree,
      resolvedFunctions,
@ -280,7 +285,7 @@ export default function evaluateSync(
        originalBinding: userScript,
      });
    } finally {
-      logs = userLogs.flushLogs();
+      logs = userLogs.flushLogs(skipLogsOperations);
      for (const entity in GLOBAL_DATA) {
        // @ts-expect-error: Types are not available
        delete self[entity];
@ -352,6 +357,7 @@ export async function evaluateAsync(
        completePromise(requestId, {
          result,
          errors,
+          logs: [userLogs.parseLogs("log", ["failed to parse logs"])],
          triggers: Array.from(self.TRIGGER_COLLECTOR),
        });
      } finally {