feat: enhance stacktraces #916

KuznetsovRoman · 2024-04-24T01:07:44Z

What is done

First part of HERMIONE-1517
It only does two things:

adds prettier stacktrace to WebdriverIO.Browser and WebdriverIO.Element calls
removes some underlying wdio frames

Example

// test.testplane.ts
describe('section', () => {
    it('test', async ({browser}) => {
        await browser.url("https://www.npmjs.com/");
        await browser.customWaitForDisplayed("#not-existing");
    });
});

// .testplane.conf.ts
export default {
    ...
    prepareBrowser: browser => {
        browser.addCommand("customWaitForDisplayed", async (selector) => {
            return browser.$(selector).waitForDisplayed();
        });
    }
}

Before

✘ Error: element ("#not-existing") still not displayed after 1000ms
    at file:///Users/kroman512/gemini-testing/testplane/node_modules/webdriverio/build/commands/browser/waitUntil.js:39:23
    at async Element.wrapCommandFn (file:///Users/kroman512/gemini-testing/testplane/node_modules/webdriverio/node_modules/@wdio/utils/build/shim.js:81:29)
    at async Element.elementErrorHandlerCallbackFn (file:///Users/kroman512/gemini-testing/testplane/node_modules/webdriverio/build/middlewares.js:18:32)
    at async Element.wrapCommandFn (file:///Users/kroman512/gemini-testing/testplane/node_modules/webdriverio/node_modules/@wdio/utils/build/shim.js:81:29)
    at async Element.wrapCommandFn (file:///Users/kroman512/gemini-testing/testplane/node_modules/webdriverio/node_modules/@wdio/utils/build/shim.js:81:29)
    at async Element.wrapCommandFn (file:///Users/kroman512/gemini-testing/testplane/node_modules/webdriverio/node_modules/@wdio/utils/build/shim.js:81:29)
    at async Element.elementErrorHandlerCallbackFn (file:///Users/kroman512/gemini-testing/testplane/node_modules/webdriverio/build/middlewares.js:18:32)
    at async Element.wrapCommandFn (file:///Users/kroman512/gemini-testing/testplane/node_modules/webdriverio/node_modules/@wdio/utils/build/shim.js:81:29)
    at async Element.wrapCommandFn (file:///Users/kroman512/gemini-testing/testplane/node_modules/webdriverio/node_modules/@wdio/utils/build/shim.js:81:29)
    at async Browser.wrapCommandFn (file:///Users/kroman512/gemini-testing/testplane/node_modules/webdriverio/node_modules/@wdio/utils/build/shim.js:81:29)

After

✘ Error: element ("#not-existing") still not displayed after 1000ms
    at Browser.customWaitForDisplayed (file:///Users/kroman512/gemini-testing/testplane/node_modules/webdriverio/node_modules/@wdio/utils/build/shim.js:233:24)
    at Browser.customWaitForDisplayed (file:///Users/kroman512/gemini-testing/testplane/node_modules/devtools/node_modules/@wdio/utils/build/monad.js:146:33)
    at Object.<anonymous> (/Users/kroman512/gemini-testing/testing-project/tests/example.hermione.js:8:23)

KuznetsovRoman · 2024-04-24T07:33:21Z

src/browser/stacktrace.ts

+
+type AnyFunc = (...args: any[]) => unknown; // eslint-disable-line @typescript-eslint/no-explicit-any
+
+export const runWithStacktraceHooks = ({


The only function, which is different with history/index.js. The rest is taken from history/index.js with removing shouldNotWrapCommand

KuznetsovRoman · 2024-04-24T07:35:43Z

src/utils/stacktrace.ts

+const getErrorTitle = (e: Error): string => `${e.name || "Error"}: ${e.message}`;
+const getErrorStackFrames = (e: Error): string | undefined => e.stack?.replace(getErrorTitle(e) + "\n", "");


CT could lose e.name due to serialization

Reference: https://nodejs.org/docs/latest-v16.x/api/errors.html#errorcapturestacktracetargetobject-constructoropt

The first line of the trace will be prefixed with ${myObject.name}: ${myObject.message}.

CT could lose e.name due to serialization

Hm, looks like problem in this helper - https://github.com/gemini-testing/testplane/blob/master/src/runner/browser-env/vite/browser-modules/errors/index.ts#L42-L45. Object.getOwnPropertyNames(error) doesn't return name field. I will fix it.

Heh, first time i see JSON.stringify with array being used as the second argument.

KuznetsovRoman · 2024-04-24T07:36:15Z

src/utils/stacktrace.ts

+    Error.captureStackTrace(targetObj, filterFunc || captureRawStackFrames);
+    Error.stackTraceLimit = savedStackTraceLimit;
+
+    const rawFramesPosition = targetObj.stack.indexOf("\n") + 1; // crop out error message


The first line of the trace will be prefixed with ${myObject.name}: ${myObject.message}.

KuznetsovRoman · 2024-04-24T07:39:43Z

src/utils/stacktrace.ts

+    if (rawFramesArr.length !== framesParsed.length) {
+        return error;
+    }


We assume "each line of rawFramesArr is equal to framesParsed"
Because we filter "rawFramesArr" using "framesParsed" and we can't build parsed frames back to stacktrace.
I dont know if rawFramesArr.length !== framesParsed.length even could be true, but just in case

KuznetsovRoman · 2024-04-24T07:40:39Z

src/utils/stacktrace.ts

+
+    isNested(childFrames: RawStackFrames): boolean {
+        for (const parentFrames of this._framesMap.values()) {
+            if (childFrames.length !== parentFrames.length && childFrames.endsWith(parentFrames)) {


childFrames.length !== parentFrames.length

Because user might have a loop.

childFrames.endsWith(parentFrames)

If true, then we already wrapped parent call

KuznetsovRoman · 2024-04-24T07:46:45Z

src/browser/stacktrace.ts

+    const frames = captureRawStackFrames(stackFilterFunc || runWithStacktraceHooks);
+
+    if (stackFrames.isNested(frames)) {
+        return fn();
+    }


We dont want to save all of the frames, because with nested calls it would use some memory

KuznetsovRoman · 2024-04-24T19:55:02Z

src/worker/runner/test-runner/index.js

@@ -119,6 +120,8 @@ module.exports = class TestRunner extends Runner {
        this._browserAgent.freeBrowser(browser);

        if (error) {
+            filterExtraWdioFrames(error);


Moved filter to here, because stacktrace hooks are not executed in browser runner.
That way we can filter wdio frames in only one place

DudaGod

🔥

DudaGod · 2024-04-25T08:55:20Z

src/browser/commands/clearSession.ts

@@ -1,7 +1,7 @@
 import type { Browser } from "../types";
 import logger from "../../utils/logger";

-export default async (browser: Browser): Promise<void> => {
+export default (browser: Browser): void => {


src/browser/stacktrace.ts

DudaGod · 2024-04-25T09:46:03Z

src/utils/stacktrace.ts

+const getErrorTitle = (e: Error): string => `${e.name || "Error"}: ${e.message}`;
+const getErrorStackFrames = (e: Error): string | undefined => e.stack?.replace(getErrorTitle(e) + "\n", "");


CT could lose e.name due to serialization

Hm, looks like problem in this helper - https://github.com/gemini-testing/testplane/blob/master/src/runner/browser-env/vite/browser-modules/errors/index.ts#L42-L45. Object.getOwnPropertyNames(error) doesn't return name field. I will fix it.

src/utils/stacktrace.ts

DudaGod · 2024-04-25T10:04:35Z

src/utils/stacktrace.ts

+        return error;
+    }
+
+    const frames = getErrorStackFrames(error)!;


Why doesn't getErrorStackFrames method return array with frames? By its name, I would expect this behavior.

Because it is located near the captureRawStackFrames and captureRawStackFrames returns string. Replaced it with:

type ErrorWithStack = SetRequired<Error, "stack">; const getErrorRawStackFrames = (e: ErrorWithStack): RawStackFrames => e.stack.replace(getErrorTitle(e) + "\n", "");

so it would be more clear

src/utils/stacktrace.ts

DudaGod · 2024-04-25T10:08:15Z

src/utils/stacktrace.ts

+        "Element.wrapCommandFn",
+        "Element.<anonymous>",
+        "Element.newCommand",
+        "Element.elementErrorHandlerCallbackFn",


How did you search for all the meaningless frames? Just run few different tests?

Yes. Those are present in stacktrace of error, produced by any command. So these give us no information.

KuznetsovRoman commented Apr 24, 2024

View reviewed changes

KuznetsovRoman force-pushed the HERMIONE-1517.stacktrace branch 3 times, most recently from b700da5 to da9b2ad Compare April 24, 2024 19:51

KuznetsovRoman commented Apr 24, 2024

View reviewed changes

DudaGod approved these changes Apr 25, 2024

View reviewed changes

KuznetsovRoman force-pushed the HERMIONE-1517.stacktrace branch from da9b2ad to 69ce211 Compare April 25, 2024 11:48

feat: enhance stacktraces

36bb693

KuznetsovRoman force-pushed the HERMIONE-1517.stacktrace branch from 69ce211 to 36bb693 Compare April 25, 2024 12:18

KuznetsovRoman merged commit 04c2c2a into master Apr 25, 2024
2 checks passed

KuznetsovRoman deleted the HERMIONE-1517.stacktrace branch April 25, 2024 12:21

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat: enhance stacktraces #916

feat: enhance stacktraces #916

KuznetsovRoman commented Apr 24, 2024 •

edited

Loading

KuznetsovRoman Apr 24, 2024 •

edited

Loading

KuznetsovRoman Apr 24, 2024

DudaGod Apr 25, 2024

KuznetsovRoman Apr 25, 2024

KuznetsovRoman Apr 24, 2024

KuznetsovRoman Apr 24, 2024 •

edited

Loading

KuznetsovRoman Apr 24, 2024

KuznetsovRoman Apr 24, 2024

KuznetsovRoman Apr 24, 2024

DudaGod left a comment

DudaGod Apr 25, 2024

DudaGod Apr 25, 2024

DudaGod Apr 25, 2024

KuznetsovRoman Apr 25, 2024

DudaGod Apr 25, 2024

KuznetsovRoman Apr 25, 2024


		type AnyFunc = (...args: any[]) => unknown; // eslint-disable-line @typescript-eslint/no-explicit-any

		export const runWithStacktraceHooks = ({

		const getErrorTitle = (e: Error): string => `${e.name \|\| "Error"}: ${e.message}`;
		const getErrorStackFrames = (e: Error): string \| undefined => e.stack?.replace(getErrorTitle(e) + "\n", "");

feat: enhance stacktraces #916

feat: enhance stacktraces #916

Conversation

KuznetsovRoman commented Apr 24, 2024 • edited Loading

What is done

Example

Before

After

KuznetsovRoman Apr 24, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

KuznetsovRoman Apr 24, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

DudaGod left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

KuznetsovRoman commented Apr 24, 2024 •

edited

Loading

KuznetsovRoman Apr 24, 2024 •

edited

Loading

KuznetsovRoman Apr 24, 2024 •

edited

Loading