Triple the speed of E2E tests and stop them exploding if a circular datastructure is logged (#8095)

* stop e2e tests exploding if a circular datastructure is logged

it's valid for the webapp to log datastructures to the console which happen to be circular
but the e2e test running explodes badly with a runtime exception and bombs out before
logging anything or providing a sensible stacktrace. you can trap the exception though and
get a sensible error however.

* don't barf on circular refs in return vals either

and log timestamps

* log timestamps

* speed up roomDir & E2EE tests by 3x

use timeouts correctly, so the first set
of scenarios take 42s to run rather than 2m21s

* speed up space test by 20s

test/end-to-end-tests/README.md

@@ -32,6 +32,12 @@ start.js accepts these parameters (and more, see `node start.js --help`) that ca
  - `--windowed` run the tests in an actual browser window Try to limit interacting with the windows while the tests are running. Hovering over the window tends to fail the tests, dragging the title bar should be fine though.
  - `--dev-tools` open the devtools in the browser window, only applies if `--windowed` is set as well.
 
+For god level debug (e.g. for debugging slow tests):
+
+`env DEBUG="puppeteer:*" ./test/end-to-end-tests/run.sh --app-url http://localhost:8080 --log-directory `pwd`/logs --dev-tools --windowed` 2>&1 | cat
+
+(piping everything through cat means you get proper timestamps on the debugging, and the chromiums hang around at the end)
+
 Developer Guide
 ===============
 
@@ -40,3 +46,4 @@ https://github.com/matrix-org/synapse/tree/master/CONTRIBUTING.rst
 
 Please follow the Matrix JS/React code style as per:
 https://github.com/matrix-org/matrix-react-sdk/blob/master/code_style.md
+

test/end-to-end-tests/src/logger.ts

@@ -24,7 +24,7 @@ export class Logger {
     public startGroup(description: string): Logger {
         if (!this.muted) {
             const indent = " ".repeat(this.indent * 2);
-            console.log(`${indent} * ${this.username} ${description}:`);
+            console.log(`${new Date().toISOString()} ${indent} * ${this.username} ${description}:`);
         }
         this.indent += 1;
         return this;
@@ -38,7 +38,7 @@ export class Logger {
     public step(description: string): Logger {
         if (!this.muted) {
             const indent = " ".repeat(this.indent * 2);
-            process.stdout.write(`${indent} * ${this.username} ${description} ... `);
+            process.stdout.write(`${new Date().toISOString()} ${indent} * ${this.username} ${description} ... `);
         }
         return this;
     }

test/end-to-end-tests/src/session.ts

@@ -40,7 +40,8 @@ export class ElementSession {
             "requestfinished", async (req: puppeteer.HTTPRequest) => {
                 const type = req.resourceType();
                 const response = await req.response();
-                return `${type} ${response?.status() ?? '<no response>'} ${req.method()} ${req.url()} \n`;
+                return new Date().toISOString() +
+                       ` ${type} ${response?.status() ?? '<no response>'} ${req.method()} ${req.url()} \n`;
             });
         this.log = new Logger(this.username);
     }
@@ -135,6 +136,10 @@ export class ElementSession {
         return this.page.waitForSelector(selector, { visible: true, timeout, hidden });
     }
 
+    public queryWithoutWaiting(selector: string): Promise<puppeteer.ElementHandle> {
+        return this.page.$(selector);
+    }
+
     public async queryAll(selector: string): Promise<puppeteer.ElementHandle[]> {
         const timeout = DEFAULT_TIMEOUT;
         await this.query(selector, timeout);

test/end-to-end-tests/src/usecases/create-space.ts

@@ -64,7 +64,9 @@ export async function inviteSpace(session: ElementSession, spaceName: string, us
     await inviteButton.click();
 
     try {
-        const button = await session.query('.mx_SpacePublicShare_inviteButton');
+        // You only get this interstitial if it's a public space, so give up after 200ms
+        // if it hasn't appeared
+        const button = await session.query('.mx_SpacePublicShare_inviteButton', 200);
         await button.click();
     } catch (e) {
         // ignore

test/end-to-end-tests/src/usecases/rightpanel.ts

@@ -17,11 +17,14 @@ limitations under the License.
 import { ElementSession } from "../session";
 
 export async function openRoomRightPanel(session: ElementSession): Promise<void> {
-    try {
-        await session.query('.mx_RoomHeader .mx_RightPanel_headerButton_highlight[aria-label="Room Info"]');
-    } catch (e) {
+    // block until we have a roomSummaryButton
+    const roomSummaryButton = await session.query('.mx_RoomHeader .mx_AccessibleButton[aria-label="Room Info"]');
+    // check if it's highlighted
+    const highlightedRoomSummaryButton = await session.queryWithoutWaiting(
+        '.mx_RoomHeader .mx_RightPanel_headerButton_highlight[aria-label="Room Info"]',
+    );
+    if (!highlightedRoomSummaryButton) {
         // If the room summary is not yet open, open it
-        const roomSummaryButton = await session.query('.mx_RoomHeader .mx_AccessibleButton[aria-label="Room Info"]');
         await roomSummaryButton.click();
     }
 }

test/end-to-end-tests/src/usecases/room-settings.ts

@@ -156,7 +156,8 @@ export async function checkRoomSettings(session: ElementSession, expectedSetting
 
 async function getValidationError(session: ElementSession): Promise<string | undefined> {
     try {
-        const validationDetail = await session.query(".mx_Validation_detail");
+        // give it 500ms to fail to produce a validation error
+        const validationDetail = await session.query(".mx_Validation_detail", 500);
         return session.innerText(validationDetail);
     } catch (e) {
         // no validation tooltips

test/end-to-end-tests/src/util.ts

@@ -57,11 +57,17 @@ export async function applyConfigChange(session: ElementSession, config: any): P
 
 export async function serializeLog(msg: ConsoleMessage): Promise<string> {
     // 9 characters padding is somewhat arbitrary ("warning".length + some)
-    let s = `${padEnd(msg.type(), 9, ' ')}| ${msg.text()} `; // trailing space is intentional
+    let s = `${new Date().toISOString()} | ${ padEnd(msg.type(), 9, ' ')}| ${msg.text()} `; // trailing space is intentional
     const args = msg.args();
     for (let i = 0; i < args.length; i++) {
         const arg = args[i];
-        const val = await arg.jsonValue();
+
+        let val;
+        try {
+            val = await arg.jsonValue();
+        } catch (error) {
+            val = `<error: ${error}>`;
+        }
 
         // We handle strings a bit differently because the `jsonValue` will be in a weird-looking
         // shape ("JSHandle:words are here"). Weirdly, `msg.text()` also catches text nodes that
@@ -96,7 +102,13 @@ export async function serializeLog(msg: ConsoleMessage): Promise<string> {
             }
 
             // not an error, as far as we're concerned - return it as human-readable JSON
-            return JSON.stringify(argInContext, null, 4);
+            let ret;
+            try {
+                ret = JSON.stringify(argInContext, null, 4);
+            } catch (error) {
+                ret = `<error: ${error}>`;
+            }
+            return ret;
         });
         s += `${stringyArg} `; // trailing space is intentional
     }