Updated measure to support auto exception logging

percy · Oct 14, 2024 · 2300c24 · 2300c24
1 parent 3ee5ae6
commit 2300c24
Show file tree

Hide file tree

Showing 3 changed files with 37 additions and 6 deletions.
diff --git a/packages/logger/src/index.js b/packages/logger/src/index.js
@@ -4,7 +4,6 @@ import TimeIt from './timing.js';
 export function logger(name) {
   return new Logger().group(name);
 }
-const timer = new TimeIt(logger('timer'));
 
 Object.defineProperties(logger, {
   stdout: { get: () => Logger.stdout },
@@ -14,8 +13,8 @@ Object.defineProperties(logger, {
   query: { value: (...args) => logger.instance.query(...args) },
   format: { value: (...args) => logger.instance.format(...args) },
   loglevel: { value: (...args) => logger.instance.loglevel(...args) },
-  timeit: { get: () => timer },
-  measure: { value: (...args) => timer.measure(...args) }
+  timeit: { get: () => new TimeIt(logger.instance.group('timer')) },
+  measure: { value: (...args) => logger.timeit.measure(...args) }
 });
 
 export default logger;
diff --git a/packages/logger/src/timing.js b/packages/logger/src/timing.js
@@ -1,4 +1,3 @@
-
 export default class TimeIt {
   // returns a singleton instance
   constructor(log) {
@@ -10,11 +9,25 @@ export default class TimeIt {
 
   async measure(name, identifier, meta, callback) {
     const startTime = Date.now();
+    let errorMsg;
+    let errorStack;
     try {
       return await callback();
+    } catch (e) {
+      errorMsg = e.message;
+      errorStack = e.stack;
+      throw e;
     } finally {
       const duration = Date.now() - startTime;
-      this.log.debug(`${name} - ${identifier} - ${duration / 1000}s`, meta);
+      this.log.debug(
+        `${name} - ${identifier} - ${duration / 1000}s`,
+        {
+          durationMs: duration,
+          errorMsg,
+          errorStack,
+          ...meta
+        }
+      );
     }
   }
 }
diff --git a/packages/logger/test/logger.test.js b/packages/logger/test/logger.test.js
@@ -495,12 +495,31 @@ describe('logger', () => {
         logger.timeit.log.loglevel('debug');
         await logger.measure('step', 'test', meta, callback);
         expect(helpers.stdout).toEqual([
-          `[${colors.magenta('percy')}] abcd`
+          `[${colors.magenta('percy:test')}] abcd`
         ]);
         expect(helpers.stderr).toEqual([
           `[${colors.magenta('percy:timer')}] step - test - 60s`
         ]);
       });
+
+      it('should capture error info', async () => {
+        const meta = { abc: '123' };
+        const error = new Error('Error');
+        const callback = async () => { log.info('abcd'); throw error; };
+
+        logger.timeit.log.loglevel('debug');
+        try {
+          await logger.measure('step', 'test1', meta, callback);
+        } catch (e) {
+          expect(e).toEqual(error);
+        }
+        expect(helpers.stdout).toEqual([
+          `[${colors.magenta('percy:test')}] abcd`
+        ]);
+        const mlog = logger.instance.query((msg => msg.debug === 'timer'))[0];
+        expect(mlog.meta.errorMsg).toEqual('Error');
+        expect(mlog.meta.errorStack).toEqual(jasmine.stringContaining('Error: Error'));
+      });
     });
   });
 });