fix: ci and e2e test (#383)

* fix: Display proper error content in e2e test - use chrome as being done in CI - Narrow down Selector to div with alert class else larger vue app dialog will be matched * Update nodejs.yml * fix: check errors after taking screenshot * fix: Display proper error content in e2e test (#6) * fix: Display proper error content in e2e test - use chrome as being done in CI - Narrow down Selector to div with alert class else larger vue app dialog will be matched * Update nodejs.yml * fix: check errors after taking screenshot * add timeline initial load screenshot - add contents of loading elements if found to log since >95% of CI errors are on timeouts as of now * increase loading time for timeline view test - github runners genuinely takes more time to load timeline view (as can be confirmed from previous ci-runs (logs and screenshots) of this pr * Implement an indefinite wait for timeline view test - since 40s is also not enough sometimes for loading timeline * Restore general 20 seconds timeout for other tests * fix: Selector element missing after initial lookup * rewrite waiting functions to get Selection elements instantly * Added HTTP request logger and console errors logger - it seems like the indefinite wait is not working, pointing to some other issues - went bank to 20s wait time + Extra logging of browser console and dumping HTTP requests of non js css font image requests * remove implemented indefinite wait and attach loggers to all fixtures * fix fakedate ENDDATE * Update screenshot.test.js * Update screenshot.test.js * Bump activitywatch version * Update nodejs.yml * try to test with master * Update nodejs.yml * Print server logs to github actions console * Update nodejs.yml * test with Logs * Update nodejs.yml * Update nodejs.yml * implement a refresh after 10s * implement refresh time and max times * cleanup workflow file * Update nodejs.yml * add master branch of aw-server-rust to ci
ActivityWatch · Nov 4, 2022 · cbb555d · cbb555d · github-actions · Nov 4, 2022
1 parent d96471c
commit cbb555d
Show file tree

Hide file tree

Showing 3 changed files with 105 additions and 39 deletions.
diff --git a/.github/workflows/nodejs.yml b/.github/workflows/nodejs.yml
@@ -47,12 +47,12 @@ jobs:
         node-version: [16]
         python-version: ['3.9']
         aw-server: ["aw-server", "aw-server-rust"]
-        aw-version: ["v0.12.0"]
-        #include:
-        #- node-version: '16'
-        #  python-version: '3.9'
-        #  aw-server: "aw-server-rust"
-        #  aw-version: "master"
+        aw-version: ["v0.12.1"]
+        include:
+        - node-version: '16'
+          python-version: '3.9'
+          aw-server: "aw-server-rust"
+          aw-version: "master"
 
     steps:
     - uses: actions/checkout@v2
@@ -103,15 +103,16 @@ jobs:
       if: ${{ matrix.aw-server == 'aw-server-rust' && matrix.aw-version == 'master' }}
       run: |
         chmod +x ./aw-server-rust/debug/aw-server
-        ./aw-server-rust/debug/aw-server --testing &
+        LOG_LEVEL=debug ./aw-server-rust/debug/aw-server --testing &
 
     - name: Insert fake data into aw-server
       run: |
         pip install click git+https://github.com/ActivityWatch/aw-client.git
         wget --no-verbose -O fakedata.py https://raw.githubusercontent.com/ActivityWatch/aw-fakedata/master/aw_fakedata.py
         GITDATE=$(git show -s --format=%ci HEAD | sed -r 's/ .+//g')
         STARTDATE=$(date --date="${GITDATE} -30 day" +%Y-%m-%d)
-        python3 fakedata.py --since $STARTDATE --until $GITDATE
+        ENDDATE=$(date --date="${GITDATE} +1 day" +%Y-%m-%d)
+        python3 fakedata.py --since $STARTDATE --until $ENDDATE
 
     - name: Install
       run: npm ci
@@ -124,19 +125,43 @@ jobs:
           npm run serve &
           sleep 3  # give a few seconds
     - name: Run e2e tests with testcafe
+      id: e2e
       uses: DevExpress/testcafe-action@latest
       with:
         # NOTE: --skip-js-errors should be removed when things work properly
         args: "--skip-js-errors chrome test/e2e/"
     - name: Move screenshots to subdir
+      # Run this step even if e2e tests flag failure
+      if: ${{ success() || steps.e2e.conclusion == 'failure'}}
       env:
         aw_server: ${{ matrix.aw-server }}
         aw_version: ${{ matrix.aw-version }}
       run: |
         mkdir -p screenshots/dist/$aw_server/$aw_version
         mv screenshots/*.png screenshots/dist/$aw_server/$aw_version
     - name: Upload screenshots
+      if: ${{ success() || steps.e2e.conclusion == 'failure'}}
       uses: actions/upload-artifact@v2-preview
       with:
         name: screenshots
         path: screenshots/dist/*
+    - name: Print server logs to console
+      if: ${{ always() }}
+      shell: bash
+      run:
+        for file in ~/.cache/activitywatch/log/*/*.log; do echo $file; cat $file; echo; done
+    - name: Move logs to subdir
+      # Run this step even if e2e tests flag failure
+      if: ${{ always() }}
+      env:
+        aw_server: ${{ matrix.aw-server }}
+        aw_version: ${{ matrix.aw-version }}
+      run: |
+        mkdir -p logs/dist/$aw_server/$aw_version
+        mv ~/.cache/activitywatch/log/*/*.log logs/dist/$aw_server/$aw_version
+    - name: Upload logs
+      if: ${{ always() }}
+      uses: actions/upload-artifact@v2-preview
+      with:
+        name: logs
+        path: logs/dist/*
diff --git a/Makefile b/Makefile
@@ -31,7 +31,7 @@ test:
 	npm test
 
 test-e2e:
-	npx testcafe firefox test/e2e/ -s takeOnFails=true
+	npx testcafe chrome test/e2e/ -s takeOnFails=true
 
 typing-coverage:
 	npx typescript-coverage-report

diff --git a/test/e2e/screenshot.test.js b/test/e2e/screenshot.test.js
@@ -3,8 +3,21 @@
 /* eslint jest/expect-expect: "off" */
 
 import { Selector } from 'testcafe';
+import { RequestLogger } from 'testcafe';
+
+const MAX_REFRESH = 2; // the max number of times to refresh if "Loading..." dosent go away
+const REFRESH_TIMEPERIOD = 5000; //ms - refresh page after waiting for this amount of ms for "Loading..." to dissapear
+const MAX_WAIT_TIME = 20000; //ms - max time to wait for "Loading..." to dissapear after all refreshes
 
 const baseURL = 'http://127.0.0.1:27180';
+const HTTPLogger = RequestLogger(/^(?:(?!\.js|\.css|\.png|\.woff2).)+$/, {
+  logRequestHeaders: true,
+  logResponseHeaders: true,
+  logRequestBody: true,
+  logResponseBody: true,
+  stringifyRequestBody: true,
+  stringifyResponseBody: true,
+});
 
 async function hide_devonly(t) {
   // Hide all devonly-elements
@@ -17,50 +30,60 @@ async function hide_devonly(t) {
 async function waitForLoading(t) {
   // Waits for all "Loading..." texts to disappear from page.
   // If it takes longer than 10s, it will fail.
-  let $loading;
-  let matches = 1;
+  let $loading,
+    refresh_count = 0;
 
   console.log('Waiting for loading to disappear...');
-  const start = new Date();
+  let start = new Date();
   do {
-    $loading = Selector('.aw-loading, text', { timeout: 500 }).withText(/Loading[.]{3}/g);
+    $loading = await Selector('.aw-loading, text', { timeout: 500 }).withText(/Loading[.]{3}/g)();
 
     // Useful for debugging:
-    matches = await $loading.count;
-    if (matches > 0) {
-      console.log(`Found ${matches} loading element with contents`); //: ${await $loading.innerText}`);
+    if ($loading) {
+      console.log(`Found loading element with contents - "${$loading.textContent}"`);
+
+      if (new Date() - start > REFRESH_TIMEPERIOD && refresh_count < MAX_REFRESH) {
+        console.log('Refreshing page....');
+        await t.eval(() => location.reload(true));
+        refresh_count++;
+        start = new Date();
+      }
 
       // If taking >20s, throw an error
-      if (new Date() - start > 20000) {
+      if (new Date() - start > MAX_WAIT_TIME && refresh_count >= MAX_REFRESH) {
+        console.log(await t.getBrowserConsoleMessages());
+        console.log(JSON.stringify(HTTPLogger.requests, null, '\t'));
         throw new Error('Timeout while waiting for loading to disappear');
       }
       await t.wait(500);
     }
-  } while (matches >= 1);
+  } while ($loading);
 
   await t.wait(500); // wait an extra 500ms, just in case a visualization is still rendering
   console.log('Loading is gone!');
 }
 
 async function checkNoError(t) {
-  const $error = Selector('div').withText(/[Ee]rror/g);
+  const $error = Selector('div.alert').withText(/[Ee]rror/g);
   try {
     await t.expect(await $error.count).eql(0);
   } catch (e) {
-    console.log('Errors found: ' + $error);
+    console.log('Errors found: ' + (await $error.textContent));
     throw e;
   }
 }
 
+const logJsErrorCode = `
+  window.addEventListener('error', function (e) {
+      console.error(e.message);
+  });`;
+
 fixture(`Home view`).page(baseURL);
 
 // Log JS errors even if --skip-js-errors is given
 // From: https://stackoverflow.com/a/59856422/965332
 test.clientScripts({
-  content: `
-        window.addEventListener('error', function (e) {
-            console.error(e.message);
-        });`,
+  content: logJsErrorCode,
 })(`Skip error but log it`, async t => {
   console.log(await t.getBrowserConsoleMessages());
 });
@@ -80,29 +103,36 @@ test('Screenshot the home view', async t => {
   });
 });
 
-fixture(`Activity view`).page(`${baseURL}/#/activity/fakedata`);
+fixture(`Activity view`).page(`${baseURL}/#/activity/fakedata`).requestHooks(HTTPLogger);
 
-test('Screenshot the activity view', async t => {
+test.clientScripts({
+  content: logJsErrorCode,
+})('Screenshot the activity view', async t => {
   await hide_devonly(t);
   await waitForLoading(t);
-  await checkNoError(t);
   await t.takeScreenshot({
     path: 'activity.png',
     fullPage: true,
   });
+  await checkNoError(t);
 
   // TODO: resize to mobile size and take another screenshot
 });
 
-fixture(`Timeline view`).page(`${baseURL}/#/timeline`);
+fixture(`Timeline view`).page(`${baseURL}/#/timeline`).requestHooks(HTTPLogger);
 
 const durationSelect = Selector('select#duration');
 const durationOption = durationSelect.find('option');
 
-test('Screenshot the timeline view', async t => {
+test.clientScripts({
+  content: logJsErrorCode,
+})('Screenshot the timeline view', async t => {
   await hide_devonly(t);
+  await t.takeScreenshot({
+    path: 'timeline-initial.png',
+    fullPage: true,
+  });
   await waitForLoading(t);
-  await checkNoError(t);
   await t
     .click(durationSelect)
     .click(durationOption.withText('12h'))
@@ -113,39 +143,50 @@ test('Screenshot the timeline view', async t => {
     path: 'timeline.png',
     fullPage: true,
   });
+  await checkNoError(t);
+
+  // Debugging
+  // console.log(await t.getBrowserConsoleMessages());
+  // console.log(JSON.stringify(HTTPLogger.requests, null, '\t'));
 });
 
-fixture(`Buckets view`).page(`${baseURL}/#/buckets/`);
+fixture(`Buckets view`).page(`${baseURL}/#/buckets/`).requestHooks(HTTPLogger);
 
-test('Screenshot the buckets view', async t => {
+test.clientScripts({
+  content: logJsErrorCode,
+})('Screenshot the buckets view', async t => {
   await hide_devonly(t);
   await t.wait(1000);
-  await checkNoError(t);
   await t.takeScreenshot({
     path: 'buckets.png',
     fullPage: true,
   });
+  await checkNoError(t);
 });
 
-fixture(`Setting view`).page(`${baseURL}/#/settings/`);
+fixture(`Setting view`).page(`${baseURL}/#/settings/`).requestHooks(HTTPLogger);
 
-test('Screenshot the settings view', async t => {
+test.clientScripts({
+  content: logJsErrorCode,
+})('Screenshot the settings view', async t => {
   await hide_devonly(t);
-  await checkNoError(t);
   await t.takeScreenshot({
     path: 'settings.png',
     fullPage: true,
   });
+  await checkNoError(t);
 });
 
-fixture(`Stopwatch view`).page(`${baseURL}/#/stopwatch/`);
+fixture(`Stopwatch view`).page(`${baseURL}/#/stopwatch/`).requestHooks(HTTPLogger);
 
-test('Screenshot the stopwatch view', async t => {
+test.clientScripts({
+  content: logJsErrorCode,
+})('Screenshot the stopwatch view', async t => {
   await hide_devonly(t);
   await waitForLoading(t);
-  await checkNoError(t);
   await t.takeScreenshot({
     path: 'stopwatch.png',
     fullPage: true,
   });
+  await checkNoError(t);
 });