From 1c49020cfcefe836c2258f7e9e9574ff4624c267 Mon Sep 17 00:00:00 2001 From: ninadbstack <60422475+ninadbstack@users.noreply.github.com> Date: Thu, 20 Jun 2024 11:51:39 +0530 Subject: [PATCH] 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 | 1 + packages/cli-exec/src/exec.js | 5 ++- packages/cli-exec/test/exec.test.js | 4 +-- packages/core/src/api.js | 14 ++++++++ packages/core/src/percy.js | 4 +-- packages/core/test/api.test.js | 54 +++++++++++++++++++++++++++++ packages/core/test/percy.test.js | 4 +-- packages/logger/src/logger.js | 17 +++------ packages/logger/test/logger.test.js | 25 +++++-------- 9 files changed, 91 insertions(+), 37 deletions(-) diff --git a/packages/cli-exec/package.json b/packages/cli-exec/package.json index 33494a365..8c4e64130 100644 --- a/packages/cli-exec/package.json +++ b/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" } diff --git a/packages/cli-exec/src/exec.js b/packages/cli-exec/src/exec.js index 2bb0e5a02..ea0220adb 100644 --- a/packages/cli-exec/src/exec.js +++ b/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}`); }); } diff --git a/packages/cli-exec/test/exec.test.js b/packages/cli-exec/test/exec.test.js index 32bdc647f..31314f45f 100644 --- a/packages/cli-exec/test/exec.test.js +++ b/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(); }); diff --git a/packages/core/src/api.js b/packages/core/src/api.js index 94c1f25df..49abc1f29 100644 --- a/packages/core/src/api.js +++ b/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()); diff --git a/packages/core/src/percy.js b/packages/core/src/percy.js index 7afb1b5af..49544af9a 100644 --- a/packages/core/src/percy.js +++ b/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))); diff --git a/packages/core/test/api.test.js b/packages/core/test/api.test.js index a41588541..fa6c1c789 100644 --- a/packages/core/test/api.test.js +++ b/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(); diff --git a/packages/core/test/percy.test.js b/packages/core/test/percy.test.js index 265fe2ac3..253788a5d 100644 --- a/packages/core/test/percy.test.js +++ b/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))); diff --git a/packages/logger/src/logger.js b/packages/logger/src/logger.js index cb687e571..a1c76fb23 100644 --- a/packages/logger/src/logger.js +++ b/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)) { diff --git a/packages/logger/test/logger.test.js b/packages/logger/test/logger.test.js index 685d3f348..f16151c88 100644 --- a/packages/logger/test/logger.test.js +++ b/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([]); });