From e53045de5abecd369ecc47e65311190b8a234beb Mon Sep 17 00:00:00 2001 From: Ayush Pahwa Date: Wed, 7 Sep 2022 11:53:47 +0530 Subject: [PATCH] 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 --- .../OtherUIFeatures/Logs_spec.js | 148 +++++++++++++----- app/client/src/sagas/DebuggerSagas.ts | 28 ++-- app/client/src/sagas/EvaluationsSaga.ts | 21 ++- .../src/workers/DataTreeEvaluator/index.ts | 11 +- app/client/src/workers/JSObject/index.ts | 3 + app/client/src/workers/UserLog.ts | 4 +- app/client/src/workers/evaluate.ts | 10 +- 7 files changed, 157 insertions(+), 68 deletions(-) diff --git a/app/client/cypress/integration/Smoke_TestSuite/ClientSideTests/OtherUIFeatures/Logs_spec.js b/app/client/cypress/integration/Smoke_TestSuite/ClientSideTests/OtherUIFeatures/Logs_spec.js index c9a7b3d689..ff76d6f46f 100644 --- 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 // }); diff --git a/app/client/src/sagas/DebuggerSagas.ts b/app/client/src/sagas/DebuggerSagas.ts index 0ed2e5e440..4fbbff6e14 100644 --- 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() { diff --git a/app/client/src/sagas/EvaluationsSaga.ts b/app/client/src/sagas/EvaluationsSaga.ts index 918de57816..99ed238605 100644 --- 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 || "", ); } diff --git a/app/client/src/workers/DataTreeEvaluator/index.ts b/app/client/src/workers/DataTreeEvaluator/index.ts index 32b50eaafa..265846a1e5 100644 --- 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, + skipUserLogsOperations = false, ): EvalResult { try { return evaluateSync( @@ -994,6 +1002,7 @@ export default class DataTreeEvaluator { createGlobalData, contextData, callbackData, + skipUserLogsOperations, ); } catch (error) { return { diff --git a/app/client/src/workers/JSObject/index.ts b/app/client/src/workers/JSObject/index.ts index 104166f178..dec8698dfc 100644 --- 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 }> = []; diff --git a/app/client/src/workers/UserLog.ts b/app/client/src/workers/UserLog.ts index f3ea3df54f..b017b3f690 100644 --- 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 { diff --git a/app/client/src/workers/evaluate.ts b/app/client/src/workers/evaluate.ts index 8f0630efcf..3284bf5679 100644 --- 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, + 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 = 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 {