Improve logging integration with VIP-CLI (#170)

This refactor the logging to be better integrated in VIP-CLI

Author: rinatkhaziev

lib/app.js

@@ -96,7 +96,11 @@ module.exports = class App {
      * @since 3.0.0
      * @alias app.shell
      */
-    this.log = new Log(_.merge({}, lando.config, {logName: this.name}));
+    if (lando.log && typeof lando.log.child === 'function') {
+      this.log = lando.log.child(this.name);
+    } else {
+      this.log = new Log(_.merge({}, lando.config, {logName: this.name}));
+    }
     this.shell = new Shell(this.log);
     this.engine = bootstrap.setupEngine(
         lando.config,

lib/lando.js

@@ -201,9 +201,9 @@ module.exports = class Lando {
     const Cli = require('./cli');
     const Log = require('./logger');
     const ErrorHandler = require('./error');
+    this.log = new Log(this.config);
     this.cache = bootstrap.setupCache(this.log, this.config);
     this.cli = new Cli();
-    this.log = new Log(this.config);
     this.error = new ErrorHandler(this.log);
     this.events = new AsyncEvents(this.log);
     this.user = require('./user');

lib/logger.js

@@ -44,45 +44,47 @@ const sanitizeKeys = (sanitizedKeys = []) => winston.format(info => {
 });
 
 // Custom console format that mimics the old formatter behavior
-const consoleFormat = (logName, logLevelConsole) => winston.format.printf(({level, message, timestamp, ...meta}) => {
-  // Get da prefixes
-  const element = (logName === 'lando') ? 'lando' : logName;
-  const elementColor = (logName === 'lando') ? 'lando' : 'app';
-  // Set the leftmost column width
-  fcw = _.max([fcw, _.size(element)]);
-
-  // Extract the splat array (format arguments) if available
-  const splat = meta[Symbol.for('splat')] || [];
-
-  // Format the message with splat arguments using util.format
-  const formattedMessage = splat.length > 0 ?
-    util.format(message, ...splat) :
-    message;
-
-  // Remove splat from meta before serializing
-  const metaWithoutSplat = {...meta};
-  delete metaWithoutSplat[Symbol.for('splat')];
-
-  // Serialize remaining metadata
-  const serializedMeta = Object.keys(metaWithoutSplat).length ?
-    ' ' + JSON.stringify(metaWithoutSplat) :
-    '';
-
-  // Default output
-  const output = [
-    winston.format.colorize({colors: logColors}).colorize(elementColor, _.padEnd(element.toLowerCase(), fcw)),
-    winston.format.colorize({colors: logColors}).colorize('timestamp', timestamp),
-    winston.format.colorize().colorize(level, level.toUpperCase()),
-    '==>',
-    formattedMessage + serializedMeta,
-  ];
-
-  // If this is a warning or error and we aren't verbose then omit prefixes
-  if (_.includes(userLevels, level) && _.includes(userLevels, logLevelConsole)) {
-    return _.drop(output, 2).join(' ');
-  }
-  return output.join(' ');
-});
+const consoleFormat = (logLevelConsole, defaultLogName) =>
+  winston.format.printf(({level, message, timestamp, logName, ...meta}) => {
+    // Get da prefixes
+    const resolvedLogName = logName || defaultLogName;
+    const element = (resolvedLogName === 'lando') ? 'lando' : resolvedLogName;
+    const elementColor = (resolvedLogName === 'lando') ? 'lando' : 'app';
+    // Set the leftmost column width
+    fcw = _.max([fcw, _.size(element)]);
+
+    // Extract the splat array (format arguments) if available
+    const splat = meta[Symbol.for('splat')] || [];
+
+    // Format the message with splat arguments using util.format
+    const formattedMessage = splat.length > 0 ?
+      util.format(message, ...splat) :
+      message;
+
+    // Remove splat from meta before serializing
+    const metaWithoutSplat = {...meta};
+    delete metaWithoutSplat[Symbol.for('splat')];
+
+    // Serialize remaining metadata
+    const serializedMeta = Object.keys(metaWithoutSplat).length ?
+      ' ' + JSON.stringify(metaWithoutSplat) :
+      '';
+
+    // Default output
+    const output = [
+      winston.format.colorize({colors: logColors}).colorize(elementColor, _.padEnd(element.toLowerCase(), fcw)),
+      winston.format.colorize({colors: logColors}).colorize('timestamp', timestamp),
+      winston.format.colorize().colorize(level, level.toUpperCase()),
+      '==>',
+      formattedMessage + serializedMeta,
+    ];
+
+    // If this is a warning or error and we aren't verbose then omit prefixes
+    if (_.includes(userLevels, level) && _.includes(userLevels, logLevelConsole)) {
+      return _.drop(output, 2).join(' ');
+    }
+    return output.join(' ');
+  });
 
 /**
  * Logs a debug message.
@@ -178,43 +180,52 @@ const consoleFormat = (logName, logLevelConsole) => winston.format.printf(({leve
  * // Log a warning message
  * lando.log.warning('Something is up with app %s in directory %s', appName, dir);
  */
-module.exports = class Log extends EventEmitter {
-  constructor({logDir, logLevelConsole = 'warn', logLevel = 'debug', logName = 'lando'} = {}) {
+class Log extends EventEmitter {
+  constructor({logDir, logFile, logLevelConsole = 'warn', logLevel = 'debug', logName = 'lando', logger} = {}) {
     super();
 
+    if (process.env.DEBUG) {
+      try {
+        const debugLib = require('debug');
+        debugLib.disable('winston:*');
+      } catch {
+        // Ignore if debug is unavailable.
+      }
+    }
+
     // If loglevelconsole is numeric lets map it!
     if (_.isInteger(logLevelConsole)) logLevelConsole = logLevels[logLevelConsole];
 
     // Initialize sanitized keys
     this.sanitizedKeys = ['auth', 'token', 'password', 'key', 'api_key', 'secret', 'machine_token'];
 
-    // Create formats
-    const formats = [
-      winston.format.timestamp({format: () => new Date().toISOString().slice(11, 19)}),
-      sanitizeKeys(this.sanitizedKeys)(),
-    ];
-
-    // The default console transport
-    const transports = [
-      new winston.transports.Console({
-        format: winston.format.combine(
-            ...formats,
-            consoleFormat(logName, logLevelConsole),
-        ),
-        level: logLevelConsole,
-      }),
-    ];
+    if (logger) {
+      this.sanitizedKeys = logger.sanitizedKeys || this.sanitizedKeys;
+      logger.sanitizedKeys = this.sanitizedKeys;
+      this.logger = logName ? logger.child({logName}) : logger;
+    } else {
+      // Create formats
+      const formats = [
+        winston.format.timestamp({format: () => new Date().toISOString().slice(11, 19)}),
+        sanitizeKeys(this.sanitizedKeys)(),
+      ];
 
-    // If we have a log path then let's add in some file transports
-    if (logDir) {
-      // Ensure the log dir actually exists
-      fs.mkdirSync(logDir, {recursive: true});
+      // The default console transport
+      const transports = [
+        new winston.transports.Console({
+          format: winston.format.combine(
+              ...formats,
+              consoleFormat(logLevelConsole, logName),
+          ),
+          level: logLevelConsole,
+        }),
+      ];
 
       // File format without colorization
       const fileFormat = winston.format.combine(
           winston.format.timestamp(),
           sanitizeKeys(this.sanitizedKeys)(),
-          winston.format.printf(({timestamp, level, message, ...meta}) => {
+          winston.format.printf(({timestamp, level, message, logName, ...meta}) => {
             // Extract the splat array (format arguments) if available
             const splat = meta[Symbol.for('splat')] || [];
 
@@ -232,35 +243,55 @@ module.exports = class Log extends EventEmitter {
               ' ' + JSON.stringify(metaWithoutSplat) :
               '';
 
-            return `${timestamp} [${logName}] ${level.toUpperCase()}: ${formattedMessage}${serializedMeta}`;
+            const resolvedLogName = logName || 'lando';
+            return `${timestamp} [${resolvedLogName}] ${level.toUpperCase()}: ${formattedMessage}${serializedMeta}`;
           }),
       );
 
-      // Add in our generic and error logs
-      transports.push(new winston.transports.File({
-        format: fileFormat,
-        level: 'warn',
-        maxsize: 500000,
-        maxFiles: 2,
-        filename: path.join(logDir, `${logName}-error.log`),
-      }));
-      transports.push(new winston.transports.File({
-        format: fileFormat,
-        level: logLevel,
-        maxsize: 500000,
-        maxFiles: 3,
-        filename: path.join(logDir, `${logName}.log`),
-      }));
-    }
+      if (logFile) {
+        const resolvedLogFile = path.isAbsolute(logFile) ?
+          logFile :
+          path.join(logDir || '', logFile);
+        fs.mkdirSync(path.dirname(resolvedLogFile), {recursive: true});
+        transports.push(new winston.transports.File({
+          format: fileFormat,
+          level: logLevel,
+          maxsize: 500000,
+          maxFiles: 3,
+          filename: resolvedLogFile,
+        }));
+      } else if (logDir) {
+        // Ensure the log dir actually exists
+        fs.mkdirSync(logDir, {recursive: true});
 
-    // Add custom colors to winston
-    winston.addColors(logColors);
+        // Add in our generic and error logs
+        transports.push(new winston.transports.File({
+          format: fileFormat,
+          level: 'warn',
+          maxsize: 500000,
+          maxFiles: 2,
+          filename: path.join(logDir, `${logName}-error.log`),
+        }));
+        transports.push(new winston.transports.File({
+          format: fileFormat,
+          level: logLevel,
+          maxsize: 500000,
+          maxFiles: 3,
+          filename: path.join(logDir, `${logName}.log`),
+        }));
+      }
 
-    // Create the winston logger
-    this.logger = winston.createLogger({
-      transports: transports,
-      exitOnError: true,
-    });
+      // Add custom colors to winston
+      winston.addColors(logColors);
+
+      // Create the winston logger
+      this.logger = winston.createLogger({
+        transports: transports,
+        exitOnError: true,
+        defaultMeta: {logName},
+      });
+      this.logger.sanitizedKeys = this.sanitizedKeys;
+    }
 
     // Create aliases for winston methods to maintain compatibility
     ['error', 'warn', 'info', 'verbose', 'debug', 'silly'].forEach(level => {
@@ -269,15 +300,12 @@ module.exports = class Log extends EventEmitter {
 
     // Expose transports for compatibility with tests
     this.transports = [];
-    transports.forEach((transport, index) => {
+    const loggerTransports = this.logger && this.logger.transports ? this.logger.transports : [];
+    loggerTransports.forEach(transport => {
       if (transport instanceof winston.transports.Console) {
         this.transports.push(transport);
       } else if (transport instanceof winston.transports.File) {
-        if (transport.filename && transport.filename.includes('-error.log')) {
-          this.transports.push(transport);
-        } else if (transport.filename) {
-          this.transports.push(transport);
-        }
+        if (transport.filename) this.transports.push(transport);
       }
     });
 
@@ -288,7 +316,14 @@ module.exports = class Log extends EventEmitter {
   // Method to help other things add sanitizations
   alsoSanitize(key) {
     this.sanitizedKeys.push(key);
+    if (this.logger) this.logger.sanitizedKeys = this.sanitizedKeys;
     // We need to recreate the format with the updated keys
     // For simplicity, we'll just add to the array and it will be used in next log call
   }
-};
+
+  child(logName) {
+    return new Log({logger: this.logger, logName});
+  }
+}
+
+module.exports = Log;

package-lock.json

@@ -136,5 +136,8 @@
     "rimraf": "^6.1.2",
     "sinon": "^4.3.0",
     "sinon-chai": "^3.7.0"
+  },
+  "peerDependencies": {
+    "debug": "^4.4.3"
   }
 }