SDK logs support (#1624)

* Updated logger to not print ci/sdk logs

* Updated exec for logger changes

* Refactored exec package

* Added endpoint to post logs

* Added a missing test

packages/cli-exec/package.json

@@ -34,6 +34,7 @@
   },
   "dependencies": {
     "@percy/cli-command": "1.28.8-beta.3",
+    "@percy/logger": "1.28.8-beta.3",
     "cross-spawn": "^7.0.3",
     "which": "^2.0.2"
   }

packages/cli-exec/src/exec.js

@@ -1,4 +1,5 @@
 import command from '@percy/cli-command';
+import logger from '@percy/logger';
 import start from './start.js';
 import stop from './stop.js';
 import ping from './ping.js';
@@ -102,6 +103,7 @@ export const exec = command('exec', {
 async function* spawn(cmd, args, percy) {
   let { default: crossSpawn } = await import('cross-spawn');
   let proc, closed, error;
+  const cilog = logger('ci');
 
   try {
     proc = crossSpawn(cmd, args, { stdio: 'pipe' });
@@ -118,7 +120,8 @@ async function* spawn(cmd, args, percy) {
       proc.stderr.on('data', (data) => {
         const message = data.toString();
         let entry = { message, timestamp: Date.now(), type: 'ci' };
-        percy?.log?.error(entry, null, true);
+        // only collect logs if percy was enabled
+        if (percy) cilog.error(entry);
         process.stderr.write(`${data}`);
       });
     }

packages/cli-exec/test/exec.test.js

@@ -163,7 +163,7 @@ describe('percy exec', () => {
       '[percy] Finalized build #1: https://percy.io/test/test/123'
     ]));
 
-    expect(Array.from(logger.instance.ciMessages)[0].message).toContain([
+    expect(logger.instance.query(log => log.debug === 'ci')[0].message).toContain([
       'Some error with secret: [REDACTED]'
     ]);
     expect(stderrSpy).toHaveBeenCalled();
@@ -183,7 +183,7 @@ describe('percy exec', () => {
       '[percy] Running "node ./test/test-data/test_prog.js error"'
     ]));
 
-    expect(Array.from(logger.instance.ciMessages)).toEqual([]);
+    expect(logger.instance.query(log => log.debug === 'ci')).toEqual([]);
     expect(stderrSpy).toHaveBeenCalled();
   });
 

packages/core/src/api.js

@@ -154,6 +154,20 @@ export function createPercyServer(percy, port) {
       await percy.client.sendBuildEvents(percy.build?.id, body);
       res.json(200, { success: true });
     })
+    .route('post', '/percy/log', async (req, res) => {
+      const log = logger('sdk');
+      if (!req.body) {
+        log.error('No request body for /percy/log endpoint');
+        return res.json(400, { error: 'No body passed' });
+      }
+      const level = req.body.level;
+      const message = req.body.message;
+      const meta = req.body.meta || {};
+
+      log[level](message, meta);
+
+      res.json(200, { success: true });
+    })
   // stops percy at the end of the current event loop
     .route('/percy/stop', (req, res) => {
       setImmediate(() => percy.stop());

packages/core/src/percy.js

@@ -427,12 +427,12 @@ export class Percy {
     if (!process.env.PERCY_TOKEN) return;
     try {
       const logsObject = {
-        clilogs: logger.query(() => true)
+        clilogs: logger.query(log => !['ci'].includes(log.debug))
       };
       // Only add CI logs if not disabled voluntarily.
       const sendCILogs = process.env.PERCY_CLIENT_ERROR_LOGS !== 'false';
       if (sendCILogs) {
-        const redactedContent = redactSecrets(logger.query(() => true, true));
+        const redactedContent = redactSecrets(logger.query(log => ['ci'].includes(log.debug)));
         logsObject.cilogs = redactedContent;
       }
       const content = base64encode(Pako.gzip(JSON.stringify(logsObject)));

packages/core/test/api.test.js

@@ -536,6 +536,60 @@ describe('API Server', () => {
     resolve(); // no hanging promises
   });
 
+  it('has a /log endpoint that adds sdk log to logger', async () => {
+    await percy.start();
+
+    const message1 = {
+      level: 'info',
+      message: 'some info',
+      meta: { snapshot: 'Snapshot name', testCase: 'testCase name' }
+    };
+
+    const message2 = {
+      level: 'error',
+      message: 'some error',
+      meta: { snapshot: 'Snapshot name 2', testCase: 'testCase name' }
+    };
+
+    // works with standard messages
+    await expectAsync(request('/percy/log', {
+      body: message1,
+      method: 'post'
+    })).toBeResolvedTo({ success: true });
+
+    await expectAsync(request('/percy/log', {
+      body: message2,
+      method: 'post'
+    })).toBeResolvedTo({ success: true });
+
+    // works without meta
+    await expectAsync(request('/percy/log', {
+      body: {
+        level: 'info',
+        message: 'some other info'
+      },
+      method: 'post'
+    })).toBeResolvedTo({ success: true });
+
+    // throws error on invalid data
+    await expectAsync(request('/percy/log', {
+      body: null,
+      method: 'post'
+    })).toBeRejected();
+
+    const sdkLogs = logger.instance.query(log => log.debug === 'sdk');
+
+    expect(sdkLogs.length).toEqual(4);
+
+    expect(sdkLogs[0].level).toEqual(message1.level);
+    expect(sdkLogs[0].message).toEqual(message1.message);
+    expect(sdkLogs[0].meta).toEqual(message1.meta);
+
+    expect(sdkLogs[1].level).toEqual(message2.level);
+    expect(sdkLogs[1].message).toEqual(message2.message);
+    expect(sdkLogs[1].meta).toEqual(message2.meta);
+  });
+
   it('returns a 500 error when an endpoint throws', async () => {
     spyOn(percy, 'snapshot').and.rejectWith(new Error('test error'));
     await percy.start();

packages/core/test/percy.test.js

@@ -1067,8 +1067,8 @@ describe('Percy', () => {
       percy.log.info('cli_test');
       percy.log.info('ci_test', {}, true);
       const logsObject = {
-        clilogs: Array.from(logger.instance.messages),
-        cilogs: Array.from(logger.instance.ciMessages)
+        clilogs: logger.instance.query(log => log.debug !== 'ci'),
+        cilogs: logger.instance.query(log => log.debug === 'ci')
       };
 
       const content = base64encode(Pako.gzip(JSON.stringify(logsObject)));

packages/logger/src/logger.js

@@ -13,12 +13,11 @@ export class PercyLogger {
   // namespace regular expressions used to determine which debug logs to write
   namespaces = {
     include: [/^.*?$/],
-    exclude: []
+    exclude: [/^ci$/, /^sdk$/]
   };
 
   // in-memory store for logs and meta info
   messages = new Set();
-  ciMessages = new Set();
 
   // track deprecations to limit noisy logging
   deprecations = new Set();
@@ -91,10 +90,7 @@ export class PercyLogger {
   }
 
   // Query for a set of logs by filtering the in-memory store
-  query(filter, ciLogs = false) {
-    if (ciLogs) {
-      return Array.from(this.ciMessages).filter(filter);
-    }
+  query(filter) {
     return Array.from(this.messages).filter(filter);
   }
 
@@ -181,7 +177,7 @@ export class PercyLogger {
 
   // Generic log method accepts a debug group, log level, log message, and optional meta
   // information to store with the message and other info
-  log(debug, level, message, meta = {}, ciLogs = false) {
+  log(debug, level, message, meta = {}) {
     // message might be an error-like object
     let err = typeof message !== 'string' && (level === 'debug' || level === 'error');
     err &&= message.message ? Error.prototype.toString.call(message) : message.toString();
@@ -190,12 +186,7 @@ export class PercyLogger {
     let timestamp = Date.now();
     message = err ? (message.stack || err) : message.toString();
     let entry = { debug, level, message, meta, timestamp, error: !!err };
-    if (ciLogs) {
-      this.ciMessages.add(entry);
-      return;
-    } else {
-      this.messages.add(entry);
-    }
+    this.messages.add(entry);
 
     // maybe write the message to stdio
     if (this.shouldLog(debug, level)) {

packages/logger/test/logger.test.js

@@ -137,25 +137,16 @@ describe('logger', () => {
     }]);
   });
 
-  it('can query for ci logs from the in-memory store', () => {
-    log.info('Not me', { match: false }, true);
-    log.info('Not me', { match: false }, true);
-    log.info('Yes me', { match: true }, true);
-    log.info('Not me', { match: false }, true);
-    log.info('Not me', { match: false }, true);
-
-    expect(logger.query(m => m.meta.match, true)).toEqual([{
-      debug: 'test',
-      level: 'info',
-      message: 'Yes me',
-      timestamp: jasmine.any(Number),
-      meta: { match: true },
-      error: false
-    }]);
+  it('does not write to stdout if CI log', () => {
+    log = logger('ci');
+    log.info('Dont print me');
+
+    expect(helpers.stdout).toEqual([]);
   });
 
-  it('does not write to stdout if CI log', () => {
-    log.info('Not me', { match: false }, true);
+  it('does not write to stdout if SDK log', () => {
+    log = logger('sdk');
+    log.info('Dont print me');
 
     expect(helpers.stdout).toEqual([]);
   });