refactor(logger): improve readability and modularity

lib/logger/index.spec.ts

@@ -3,6 +3,7 @@ import fs from 'fs-extra';
 import { partial } from '../../test/util';
 import { add } from '../util/host-rules';
 import { addSecretForSanitizing as addSecret } from '../util/sanitize';
+import type { RenovateLogger } from '.';
 import {
   addMeta,
   addStream,
@@ -59,6 +60,18 @@ describe('logger/index', () => {
     expect(logLevel()).toBe('debug');
   });
 
+  it('should create a child logger', () => {
+    const childLogger = (logger as RenovateLogger).childLogger();
+    const loggerSpy = jest.spyOn(logger, 'debug');
+    const childLoggerSpy = jest.spyOn(childLogger, 'debug');
+
+    childLogger.debug('test');
+
+    expect(loggerSpy).toHaveBeenCalledTimes(0);
+    expect(childLoggerSpy).toHaveBeenCalledTimes(1);
+    expect(childLoggerSpy).toHaveBeenCalledWith('test');
+  });
+
   it('saves problems', () => {
     addSecret('p4$$w0rd');
     levels('stdout', 'fatal');

lib/logger/index.ts

@@ -17,75 +17,89 @@ import {
   withSanitizer,
 } from './utils';
 
-let logContext: string = getEnv('LOG_CONTEXT') ?? nanoid();
-let curMeta: Record<string, unknown> = {};
-
 const problems = new ProblemStream();
-
 let stdoutLevel = validateLogLevel(getEnv('LOG_LEVEL'), 'info');
-const stdout: bunyan.Stream = {
-  name: 'stdout',
-  level: stdoutLevel,
-  stream: process.stdout,
-};
+
+export function getProblems(): BunyanRecord[] {
+  return problems.getProblems();
+}
+
+export function clearProblems(): void {
+  return problems.clearProblems();
+}
 
 export function logLevel(): bunyan.LogLevelString {
   return stdoutLevel;
 }
 
-// istanbul ignore if: not testable
-if (getEnv('LOG_FORMAT') !== 'json') {
-  // TODO: typings (#9615)
-  const prettyStdOut = new RenovateStream() as any;
-  prettyStdOut.pipe(process.stdout);
-  stdout.stream = prettyStdOut;
-  stdout.type = 'raw';
+function createDefaultStreams(
+  stdoutLevel: bunyan.LogLevelString,
+  problems: ProblemStream,
+  logFile: string | undefined,
+): bunyan.Stream[] {
+  const stdout: bunyan.Stream = {
+    name: 'stdout',
+    level: stdoutLevel,
+    stream: process.stdout,
+  };
+
+  // istanbul ignore if: not testable
+  if (getEnv('LOG_FORMAT') !== 'json') {
+    // TODO: typings (#9615)
+    const prettyStdOut = new RenovateStream() as any;
+    prettyStdOut.pipe(process.stdout);
+    stdout.stream = prettyStdOut;
+    stdout.type = 'raw';
+  }
+
+  const problemsStream: bunyan.Stream = {
+    name: 'problems',
+    level: 'warn' as bunyan.LogLevel,
+    stream: problems as any,
+    type: 'raw',
+  };
+
+  // istanbul ignore next: not easily testable
+  const logFileStream: bunyan.Stream | undefined = is.string(logFile)
+    ? createLogFileStream(logFile)
+    : undefined;
+
+  return [stdout, problemsStream, logFileStream].filter(
+    Boolean,
+  ) as bunyan.Stream[];
 }
 
-const bunyanLogger = bunyan.createLogger({
-  name: 'renovate',
-  serializers: {
-    body: configSerializer,
-    cmd: cmdSerializer,
-    config: configSerializer,
-    migratedConfig: configSerializer,
-    originalConfig: configSerializer,
-    presetConfig: configSerializer,
-    oldConfig: configSerializer,
-    newConfig: configSerializer,
-    err: errSerializer,
-  },
-  streams: [
-    stdout,
-    {
-      name: 'problems',
-      level: 'warn' as bunyan.LogLevel,
-      stream: problems as any,
-      type: 'raw',
-    },
-  ].map(withSanitizer),
-});
+// istanbul ignore next: not easily testable
+export function createLogFileStream(logFile: string): bunyan.Stream {
+  // Ensure log file directory exists
+  const directoryName = upath.dirname(logFile);
+  fs.ensureDirSync(directoryName);
+
+  return {
+    name: 'logfile',
+    path: logFile,
+    level: validateLogLevel(getEnv('LOG_FILE_LEVEL'), 'debug'),
+  };
+}
 
-const logFactory = (
+type loggerFunction = (p1: string | Record<string, any>, p2?: string) => void;
+
+function logFactory(
+  bunyanLogger: bunyan,
   _level: bunyan.LogLevelString,
-): ((p1: unknown, p2: unknown) => void) => {
-  return (p1: any, p2: any): void => {
+  curMeta: Record<string, unknown>,
+  logContext: string,
+): loggerFunction {
+  return function (p1: string | Record<string, any>, p2?: string): void {
+    const meta: Record<string, unknown> = {
+      logContext,
+      ...curMeta,
+      ...toMeta(p1),
+    };
+    const msg = getMessage(p1, p2);
     let level = _level;
-    if (p2) {
-      // meta and msg provided
-      const msg = p2;
-      const meta: Record<string, unknown> = { logContext, ...curMeta, ...p1 };
-      const remappedLevel = getRemappedLevel(msg);
-      // istanbul ignore if: not testable
-      if (remappedLevel) {
-        meta.oldLevel = level;
-        level = remappedLevel;
-      }
-      bunyanLogger[level](meta, msg);
-    } else if (is.string(p1)) {
-      // only message provided
-      const msg = p1;
-      const meta: Record<string, unknown> = { logContext, ...curMeta };
+
+    if (is.string(msg)) {
       const remappedLevel = getRemappedLevel(msg);
       // istanbul ignore if: not testable
       if (remappedLevel) {
@@ -94,11 +108,21 @@ const logFactory = (
       }
       bunyanLogger[level](meta, msg);
     } else {
-      // only meta provided
-      bunyanLogger[level]({ logContext, ...curMeta, ...p1 });
+      bunyanLogger[level](meta);
     }
   };
-};
+}
+
+function getMessage(
+  p1: string | Record<string, any>,
+  p2?: string,
+): string | undefined {
+  return is.string(p1) ? p1 : p2;
+}
+
+function toMeta(p1: string | Record<string, any>): Record<string, unknown> {
+  return is.object(p1) ? p1 : {};
+}
 
 const loggerLevels: bunyan.LogLevelString[] = [
   'trace',
@@ -109,69 +133,145 @@ const loggerLevels: bunyan.LogLevelString[] = [
   'fatal',
 ];
 
-export const logger: Logger = { once: { reset: onceReset } } as any;
+export class RenovateLogger implements Logger {
+  logger: Logger = { once: { reset: onceReset } } as any;
+
+  constructor(
+    private readonly bunyanLogger: bunyan,
+    private context: string,
+    private meta: Record<string, unknown>,
+  ) {
+    for (const level of loggerLevels) {
+      this.logger[level] = this.logFactory(level) as never;
+      this.logger.once[level] = this.logOnceFn(level);
+    }
+  }
+
+  addStream(stream: bunyan.Stream): void {
+    this.bunyanLogger.addStream(withSanitizer(stream));
+  }
+
+  childLogger(): RenovateLogger {
+    return new RenovateLogger(
+      this.bunyanLogger.child({}),
+      this.context,
+      this.meta,
+    );
+  }
+
+  trace = this.log.bind(this, 'trace');
+  debug = this.log.bind(this, 'debug');
+  info = this.log.bind(this, 'info');
+  warn = this.log.bind(this, 'warn');
+  error = this.log.bind(this, 'error');
+  fatal = this.log.bind(this, 'fatal');
+
+  once = this.logger.once;
 
-loggerLevels.forEach((loggerLevel) => {
-  logger[loggerLevel] = logFactory(loggerLevel) as never;
+  get logContext(): string {
+    return this.context;
+  }
+
+  set logContext(context: string) {
+    this.context = context;
+  }
+
+  setMeta(obj: Record<string, unknown>): void {
+    this.meta = { ...obj };
+  }
+
+  addMeta(obj: Record<string, unknown>): void {
+    this.meta = { ...this.meta, ...obj };
+  }
 
-  const logOnceFn = (p1: any, p2: any): void => {
-    once(() => {
-      const logFn = logger[loggerLevel];
-      if (is.undefined(p2)) {
-        logFn(p1);
-      } else {
-        logFn(p1, p2);
+  removeMeta(fields: string[]): void {
+    for (const key of Object.keys(this.meta)) {
+      if (fields.includes(key)) {
+        delete this.meta[key];
       }
-    }, logOnceFn);
-  };
-  logger.once[loggerLevel] = logOnceFn as never;
-});
+    }
+  }
 
-const logFile = getEnv('LOG_FILE');
-// istanbul ignore if: not easily testable
-if (is.string(logFile)) {
-  // ensure log file directory exists
-  const directoryName = upath.dirname(logFile);
-  fs.ensureDirSync(directoryName);
+  private logFactory(level: bunyan.LogLevelString): loggerFunction {
+    return logFactory(this.bunyanLogger, level, this.meta, this.context);
+  }
 
-  addStream({
-    name: 'logfile',
-    path: logFile,
-    level: validateLogLevel(getEnv('LOG_FILE_LEVEL'), 'debug'),
-  });
+  private logOnceFn(level: bunyan.LogLevelString): loggerFunction {
+    const logOnceFn = (p1: string | Record<string, any>, p2?: string): void => {
+      once(() => {
+        this.log(level, p1, p2);
+      }, logOnceFn);
+    };
+    return logOnceFn;
+  }
+
+  private log(
+    level: bunyan.LogLevelString,
+    p1: string | Record<string, any>,
+    p2?: string,
+  ): void {
+    const logFn = this.logger[level];
+    if (is.string(p1)) {
+      logFn(p1);
+    } else {
+      logFn(p1, p2);
+    }
+  }
 }
 
+const defaultStreams = createDefaultStreams(
+  stdoutLevel,
+  problems,
+  getEnv('LOG_FILE'),
+);
+const bunyanLogger = bunyan.createLogger({
+  name: 'renovate',
+  serializers: {
+    body: configSerializer,
+    cmd: cmdSerializer,
+    config: configSerializer,
+    migratedConfig: configSerializer,
+    originalConfig: configSerializer,
+    presetConfig: configSerializer,
+    oldConfig: configSerializer,
+    newConfig: configSerializer,
+    err: errSerializer,
+  },
+  streams: defaultStreams.map(withSanitizer),
+});
+
+const logContext: string = getEnv('LOG_CONTEXT') ?? nanoid();
+const loggerInternal = new RenovateLogger(bunyanLogger, logContext, {});
+
+export const logger: Logger = loggerInternal;
+
 export function setContext(value: string): void {
-  logContext = value;
+  loggerInternal.logContext = value;
 }
 
 export function getContext(): any {
-  return logContext;
+  return loggerInternal.logContext;
 }
 
 // setMeta overrides existing meta, may remove fields if no longer existing
 export function setMeta(obj: Record<string, unknown>): void {
-  curMeta = { ...obj };
+  loggerInternal.setMeta(obj);
 }
 
 // addMeta overrides or adds fields but does not remove any
 export function addMeta(obj: Record<string, unknown>): void {
-  curMeta = { ...curMeta, ...obj };
+  loggerInternal.addMeta(obj);
 }
 
 // removeMeta removes the provided fields from meta
 export function removeMeta(fields: string[]): void {
-  Object.keys(curMeta).forEach((key) => {
-    if (fields.includes(key)) {
-      delete curMeta[key];
-    }
-  });
+  loggerInternal.removeMeta(fields);
 }
 
 export /* istanbul ignore next */ function addStream(
   stream: bunyan.Stream,
 ): void {
-  bunyanLogger.addStream(withSanitizer(stream));
+  loggerInternal.addStream(stream);
 }
 
 /**
@@ -189,11 +289,3 @@ export function levels(
     stdoutLevel = level;
   }
 }
-
-export function getProblems(): BunyanRecord[] {
-  return problems.getProblems();
-}
-
-export function clearProblems(): void {
-  return problems.clearProblems();
-}