fix: create spinner-aware logger to more easily avoid jumbled logs

spinner.interrupt functionality already existed, but it required
code to manually use it.

createLogger now accepts a spinner, so any calls to such a logger
will automatically go through spinner.interrupt for safe
logging when a spinner is present

Author: mvirgil

src/commands/sourcemaps.ts

@@ -171,8 +171,8 @@ sourcemapsCommand
         sourcemapsCommand.error(COMMON_ERROR_MESSAGES.REALM_NOT_SPECIFIED);
       }
 
-      const logger = createLogger(options.debug ? LogLevel.DEBUG : LogLevel.INFO);
       const spinner = createSpinner();
+      const logger = createLogger(options.debug ? LogLevel.DEBUG : LogLevel.INFO, spinner);
       try {
         await runSourcemapUpload({ ...options, directory: options.path }, { logger, spinner });
       } catch (e) {

src/sourcemaps/index.ts

@@ -187,24 +187,18 @@ export async function runSourcemapUpload(options: SourceMapUploadOptions, ctx: S
       // eslint-disable-next-line @typescript-eslint/no-unused-vars
     ].filter(([_, value]) => typeof value !== 'undefined'));
 
-    spinner.interrupt(() => {
-      logger.debug('Uploading %s', path);
-      logger.debug('PUT', url);
-    });
+    logger.debug('Uploading %s', path);
+    logger.debug('PUT', url);
 
     const dryRunUploadFile: typeof uploadFile = async () => {
-      spinner.interrupt( () => {
-        logger.info('sourceMapId %s would be used to upload %s', sourceMapId, path);
-      });
+      logger.info('sourceMapId %s would be used to upload %s', sourceMapId, path);
     };
     const uploadFileFn = options.dryRun ? dryRunUploadFile : uploadFile;
 
     // notify user if we cannot be certain the "sourcemaps inject" command was already run
     const alreadyInjected = await wasInjectAlreadyRun(path, logger);
     if (!alreadyInjected.result) {
-      spinner.interrupt(() => {
-        logger.warn(alreadyInjected.message);
-      });
+      logger.warn(alreadyInjected.message);
     }
 
     // upload a single file

src/utils/logger.ts

@@ -15,6 +15,7 @@
 */
 
 import chalk from 'chalk';
+import { Spinner } from './spinner';
 
 /** Logger methods can be called just like console.log */
 export interface Logger {
@@ -31,14 +32,27 @@ export const enum LogLevel {
   DEBUG = 1
 }
 
-export function createLogger(logLevel: LogLevel): Logger {
+export function createLogger(logLevel: LogLevel, spinner?: Spinner): Logger {
   // Send info to stdout, and all other logs to stderr
-  return {
+  const basicLogger = {
     error: (msg, ...params) => LogLevel.ERROR >= logLevel && prefixedConsoleError(chalk.stderr.red('ERROR '), msg, ...params),
     warn: (msg, ...params) => LogLevel.WARN >= logLevel && prefixedConsoleError(chalk.stderr.yellow('WARN '), msg, ...params),
     info: (msg, ...params) => LogLevel.INFO >= logLevel && console.log(msg, ...params),
     debug: (msg, ...params) => LogLevel.DEBUG >= logLevel && prefixedConsoleError(chalk.stderr.gray('DEBUG '), msg, ...params),
   } as Logger;
+
+  if (spinner) {
+    // wrap logging functions with spinner.interrupt() to avoid jumbled logs when the spinner is active
+    const spinnerAwareLogger = {
+      error: (...args) => { spinner.interrupt(() => basicLogger.error(...args)); },
+      warn: (...args) => { spinner.interrupt(() => basicLogger.warn(...args)); },
+      info: (...args) => { spinner.interrupt(() => basicLogger.info(...args)); },
+      debug: (...args) => { spinner.interrupt(() => basicLogger.debug(...args)); },
+    } as Logger;
+    return spinnerAwareLogger;
+  } else {
+    return basicLogger;
+  }
 }
 
 /** Carefully wrap console.error so the logger can properly support format strings */

test/utils/logger.test.ts

@@ -15,10 +15,14 @@
 */
 
 import { createLogger, LogLevel } from '../../src/utils/logger';
+import { createSpinner, Spinner } from '../../src/utils/spinner';
 
 describe('createLogger', () => {
 
-  test('should respect log level', () => {
+  test.each([
+    [undefined],        /* test case:  normal logger (without a spinner) */
+    [createSpinner()]   /* test case:  spinner-aware logger */
+  ])('should respect log level', (spinner: Spinner | undefined) => {
     const output: unknown[] = [];
     const logMock = jest.spyOn(console, 'log').mockImplementation((arg: unknown) => output.push(arg));
     const errorMock = jest.spyOn(console, 'error').mockImplementation((arg: unknown) => output.push(arg));
@@ -31,7 +35,7 @@ describe('createLogger', () => {
     ]);
 
     for (const [ level, label ] of levels.entries()) {
-      const logger = createLogger(level);
+      const logger = createLogger(level, spinner);
       logger.error(`${label}.error`);
       logger.warn(`${label}.warn`);
       logger.info(`${label}.info`);
@@ -86,4 +90,24 @@ describe('createLogger', () => {
     errorMock.mockRestore();
   });
 
+  test('should invoke spinner.interrupt() before logging, if a spinner is provided', () => {
+    const output: unknown[] = [];
+    const logMock = jest.spyOn(console, 'log').mockImplementation((arg: unknown) => output.push(arg));
+    const errorMock = jest.spyOn(console, 'error').mockImplementation((arg: unknown) => output.push(arg));
+    const spinner = createSpinner();
+    jest.spyOn(spinner, 'interrupt');
+
+    const logger = createLogger(LogLevel.DEBUG, spinner);
+
+    logger.error('error with spinner');
+    logger.warn('warn with spinner');
+    logger.info('info with spinner');
+    logger.debug('debug with spinner');
+
+    expect(spinner.interrupt).toHaveBeenCalledTimes(4);
+
+    logMock.mockRestore();
+    errorMock.mockRestore();
+  });
+
 });