✨ Improve testing mode and support in sdk-utils based tests (#1031)

* ✨ Add additional testing mode features

- Support sabotaging remote logging connections
- Track API requests and allow access to tracked requests
- Allow setting a build error to propigate for failed requests

* ✨ Update sdk-utils test helpers to work with testing mode

* 🐛 Fix sdk-utils logging history entries

- Store the full error stack trace when logging an error message
- Include boolean error value in entry like core's logger

* 🐛 Wait for first message when connecting to a remote logger

This fixes an issue, especially in tests, where setting a loglevel may race to be overridden when
immediately following a fresh remote connection

* ✅ Ignore testing generic request error messages with sdk-utils

This util is designed to only make requests to the CLI API only. Since the CLI API is always
accessible for sdk-utils tests, there is never a missing response error message to allow the
fallback message to be constructed from generic response properties.

* 🚲 Change build-failure testing command name

packages/core/src/api.js

@@ -14,12 +14,21 @@ export function createPercyServer(percy, port) {
   let server = Server.createServer({ port })
   // facilitate logger websocket connections
     .websocket('/(logger)?', ws => {
+      // support sabotaging remote logging connections in testing mode
+      if (percy.testing?.remoteLogging === false) return ws.terminate();
+
+      // track all remote logging connections in testing mode
+      if (percy.testing) (percy.testing.remoteLoggers ||= new Set()).add(ws);
+      ws.addEventListener('close', () => percy.testing?.remoteLoggers?.delete(ws));
+
+      // listen for messages with specific logging payloads
       ws.addEventListener('message', ({ data }) => {
         let { log, messages = [] } = JSON.parse(data);
         for (let m of messages) logger.instance.messages.add(m);
         if (log) logger.instance.log(...log);
       });
 
+      // respond with the current loglevel
       ws.send(JSON.stringify({
         loglevel: logger.loglevel()
       }));
@@ -37,25 +46,34 @@ export function createPercyServer(percy, port) {
         res.setHeader('X-Percy-Core-Version', percy.testing?.version ?? pkg.version);
       }
 
+      // track all api reqeusts in testing mode
+      if (percy.testing && !req.url.pathname.startsWith('/test/')) {
+        (percy.testing.requests ||= []).push({
+          url: `${req.url.pathname}${req.url.search}`,
+          method: req.method,
+          body: req.body
+        });
+      }
+
       // support sabotaging requests in testing mode
       if (percy.testing?.api?.[req.url.pathname] === 'error') {
-        return res.json(500, { success: false, error: 'Error: testing' });
+        next = () => Promise.reject(new Error(percy.testing.build?.error || 'testing'));
       } else if (percy.testing?.api?.[req.url.pathname] === 'disconnect') {
-        return req.connection.destroy();
+        next = () => req.connection.destroy();
       }
 
       // return json errors
       return next().catch(e => res.json(e.status ?? 500, {
-        build: percy.build,
+        build: percy.testing?.build || percy.build,
         error: e.message,
         success: false
       }));
     })
   // healthcheck returns basic information
     .route('get', '/percy/healthcheck', (req, res) => res.json(200, {
+      build: percy.testing?.build ?? percy.build,
       loglevel: percy.loglevel(),
       config: percy.config,
-      build: percy.build,
       success: true
     }))
   // get or set config options
@@ -102,22 +120,34 @@ export function createPercyServer(percy, port) {
       body = Buffer.isBuffer(body) ? body.toString() : body;
 
       if (cmd === 'reset') {
-        // the reset command will reset testing mode and clear any logs
-        percy.testing = {};
+        // the reset command will terminate connections, clear logs, and reset testing mode
+        percy.testing.remoteLoggers?.forEach(ws => ws.terminate());
         logger.instance.messages.clear();
+        percy.testing = {};
       } else if (cmd === 'version') {
         // the version command will update the api version header for testing
         percy.testing.version = body;
       } else if (cmd === 'error' || cmd === 'disconnect') {
         // the error or disconnect commands will cause specific endpoints to fail
-        percy.testing.api = { ...percy.testing.api, [body]: cmd };
+        (percy.testing.api ||= {})[body] = cmd;
+      } else if (cmd === 'build-failure') {
+        // the build-failure command will cause api errors to include a failed build
+        percy.testing.build = { failed: true, error: 'Build failed' };
+      } else if (cmd === 'remote-logging') {
+        // the remote-logging command will toggle remote logging support
+        if (body === false) percy.testing.remoteLoggers?.forEach(ws => ws.terminate());
+        percy.testing.remoteLogging = body;
       } else {
         // 404 for unknown commands
         return res.send(404);
       }
 
-      return res.json(200, { testing: percy.testing });
+      return res.json(200, { success: true });
     })
+  // returns an array of raw requests made to the api
+    .route('get', '/test/requests', (req, res) => res.json(200, {
+      requests: percy.testing.requests
+    }))
   // returns an array of raw logs from the logger
     .route('get', '/test/logs', (req, res) => res.json(200, {
       logs: Array.from(logger.instance.messages)

packages/core/test/api.test.js

@@ -1,4 +1,5 @@
 import path from 'path';
+import WebSocket from 'ws';
 import PercyConfig from '@percy/config';
 import { logger, setupTest, fs } from './helpers/index.js';
 import Percy from '@percy/core';
@@ -245,10 +246,16 @@ describe('API Server', () => {
     const post = (p, body) => request(`${addr}${p}`, { method: 'post', body });
     const req = p => request(`${addr}${p}`, { retries: 0 }, false);
 
+    let log = (lvl, msg) => new Promise((resolve, reject) => {
+      let ws = new WebSocket('ws://localhost:5338/logger');
+      let data = JSON.stringify({ log: ['remote', lvl, msg] });
+      ws.on('close', () => reject(new Error('Connection closed')));
+      ws.on('message', () => resolve(ws.send(data)));
+    });
+
     beforeEach(async () => {
-      percy = await Percy.start({
-        testing: true
-      });
+      percy = await Percy.start({ testing: true });
+      logger.instance.messages.clear();
     });
 
     it('implies loglevel silent and dryRun', () => {
@@ -270,6 +277,23 @@ describe('API Server', () => {
       ]));
     });
 
+    it('enables a /test/requests endpoint to return tracked requests', async () => {
+      // should not track testing mode requests
+      await get('/percy/healthcheck');
+      await get('/test/snapshot');
+      await post('/percy/config', { clientInfo: 'foo/bar' });
+      await get('/test/logs');
+      await get('/percy/idle?param');
+
+      let { requests } = await get('/test/requests');
+
+      expect(requests).toEqual([
+        { method: 'GET', url: '/percy/healthcheck' },
+        { method: 'POST', url: '/percy/config', body: { clientInfo: 'foo/bar' } },
+        { method: 'GET', url: '/percy/idle?param' }
+      ]);
+    });
+
     it('enables several /test/api endpoint commands', async () => {
       expect(percy.testing).toEqual({});
       await post('/test/api/version', false);
@@ -278,6 +302,10 @@ describe('API Server', () => {
       expect(percy.testing).toHaveProperty('version', '0.0.1');
       await post('/test/api/reset');
       expect(percy.testing).toEqual({});
+      await post('/test/api/remote-logging', false);
+      expect(percy.testing).toHaveProperty('remoteLogging', false);
+      await post('/test/api/build-failure');
+      expect(percy.testing).toHaveProperty('build', { failed: true, error: 'Build failed' });
       await post('/test/api/error', '/percy/healthcheck');
       expect(percy.testing).toHaveProperty('api', { '/percy/healthcheck': 'error' });
       await post('/test/api/disconnect', '/percy/healthcheck');
@@ -307,17 +335,62 @@ describe('API Server', () => {
       expect(statusCode).toEqual(500);
     });
 
+    it('can make endpoints return a build failure via /test/api/build-failure', async () => {
+      let expected = { failed: true, error: 'Build failed' };
+      let { build } = await get('/percy/healthcheck');
+      expect(build).toBeUndefined();
+
+      await post('/test/api/build-failure');
+      ({ build } = await get('/percy/healthcheck'));
+      expect(build).toEqual(expected);
+
+      // errors include build info
+      await post('/test/api/error', '/percy/snapshot');
+      let { body: snapshot } = await req('/percy/snapshot');
+      expect(snapshot).toHaveProperty('error', expected.error);
+      expect(snapshot).toHaveProperty('build', expected);
+    });
+
     it('can make endpoints destroy connections via /test/api/disconnect', async () => {
       await expectAsync(req('/percy/healthcheck')).toBeResolved();
       await post('/test/api/disconnect', '/percy/healthcheck');
       await expectAsync(req('/percy/healthcheck')).toBeRejected();
     });
 
+    it('can toggle accepting logging connections via /test/api/remote-logging', async () => {
+      await log('info', 'testing 1');
+
+      // remote log sent
+      expect(await get('/test/logs')).toHaveProperty('logs', [
+        jasmine.objectContaining({ message: 'testing 1' })
+      ]);
+
+      // disable accepting remote logging connections
+      await post('/test/api/remote-logging', false);
+      await expectAsync(log('info', 'testing 2'))
+        .toBeRejectedWithError('Connection closed');
+
+      // logs not sent
+      expect(await get('/test/logs')).toHaveProperty('logs', [
+        jasmine.objectContaining({ message: 'testing 1' })
+      ]);
+
+      // enable accepting remote logging connections again
+      await post('/test/api/remote-logging', true);
+      await log('info', 'testing 3');
+
+      // remote log sent
+      expect(await get('/test/logs')).toHaveProperty('logs', [
+        jasmine.objectContaining({ message: 'testing 1' }),
+        jasmine.objectContaining({ message: 'testing 3' })
+      ]);
+    });
+
     it('can reset testing mode and clear logs via /test/reset', async () => {
       // already tested up above
       await post('/test/api/version', false);
       await post('/test/api/disconnect', '/percy/healthcheck');
-      percy.log.info('foo bar from test');
+      await log('info', 'foo bar from test');
 
       // the actual endpoint to test
       await post('/test/api/reset');

packages/sdk-utils/package.json

@@ -26,8 +26,6 @@
       "node": "./dist/index.js",
       "default": "./dist/bundle.js"
     },
-    "./test/server": "./test/server.js",
-    "./test/client": "./test/client.js",
     "./test/helpers": {
       "node": "./test/helpers.js",
       "default": "./test/client.js"
@@ -36,13 +34,9 @@
   "scripts": {
     "build": "node ../../scripts/build",
     "lint": "eslint --ignore-path ../../.gitignore .",
-    "test": "node ../../scripts/test",
+    "test": "percy exec --testing -- node ../../scripts/test",
     "test:coverage": "yarn test --coverage"
   },
-  "karma": {
-    "run_start": "node test/server start",
-    "run_complete": "node test/server stop"
-  },
   "rollup": {
     "external": [
       "ws"

packages/sdk-utils/src/logger.js

@@ -25,9 +25,10 @@ const log = logger.log = (ns, lvl, msg, meta) => {
     if (err) msg = { name: msg.name, message: msg.message, stack: msg.stack };
     return remote.socket.send(JSON.stringify({ log: [ns, lvl, msg, meta] }));
   } else {
-    // keep log history when not remote
-    let [debug, level, message, timestamp] = [ns, lvl, msg, Date.now()];
-    (log.history ||= []).push({ debug, level, message, meta, timestamp });
+    // keep log history of full message when not remote
+    let message = err ? msg.stack : msg.toString();
+    let [debug, level, timestamp, error] = [ns, lvl, Date.now(), !!err];
+    (log.history ||= []).push({ debug, level, message, meta, timestamp, error });
   }
 
   // check if the specific level is within the local loglevel range
@@ -37,7 +38,7 @@ const log = logger.log = (ns, lvl, msg, meta) => {
 
     // colorize the label when possible for consistency with the CLI logger
     if (!process.env.__PERCY_BROWSERIFIED__) label = `\u001b[95m${label}\u001b[39m`;
-    msg = `[${label}] ${(err && debug && msg?.stack) || msg}`;
+    msg = `[${label}] ${(err && debug && msg.stack) || msg}`;
 
     if (process.env.__PERCY_BROWSERIFIED__) {
       // use console[warn|error|log] in browsers
@@ -81,11 +82,17 @@ const remote = logger.remote = async timeout => {
     let address = new URL('/logger', percy.address).href;
     // create and cache a websocket connection
     let ws = remote.socket = await createWebSocket(address, timeout);
-    // accept loglevel updates
-    /* istanbul ignore next: difficult to test currently */
-    ws.onmessage = e => loglevel(JSON.parse(e.data).loglevel);
-    // cleanup message handler on close
-    ws.onclose = () => (remote.socket = (ws.onmessage = (ws.onclose = null)));
+
+    await new Promise((resolve, reject) => {
+      // accept loglevel updates and resolve after first message
+      ws.onmessage = e => resolve(loglevel(JSON.parse(e.data).loglevel));
+      ws.onclose = () => {
+        // cleanup listeners and reject if not resolved
+        remote.socket = ws.onmessage = ws.onclose = null;
+        reject(new Error('Connection closed'));
+      };
+    });
+
     // send any messages already logged in this environment
     if (log.history) ws.send(JSON.stringify({ messages: log.history }));
   } catch (err) {

packages/sdk-utils/src/request.js

@@ -14,6 +14,7 @@ export async function request(path, options = {}) {
   if (!(response.status >= 200 && response.status < 300)) {
     throw Object.assign(new Error(), {
       message: response.body.error ||
+      /* istanbul ignore next: in tests, there's always an error message */
         `${response.status} ${response.statusText}`,
       response
     });