Refactor logging

src/index.ts

@@ -2,4 +2,5 @@ export {NodeKit} from './nodekit';
 export {AppContext} from './lib/context';
 export {AppConfig, AppContextParams, AppDynamicConfig} from './types';
 export {AppError} from './lib/app-error';
+export {NodeKitLogger} from './lib/logging';
 export * from './lib/public-consts';

src/lib/context.ts

@@ -2,21 +2,21 @@ import {IncomingHttpHeaders} from 'http';
 
 import {JaegerTracer} from 'jaeger-client';
 import {FORMAT_HTTP_HEADERS, Span, SpanContext, Tags} from 'opentracing';
-import pino from 'pino';
 
 import {NodeKit} from '../nodekit';
 import {AppConfig, AppContextParams, AppDynamicConfig, Dict} from '../types';
 
 import {AppError} from './app-error';
 import {REQUEST_ID_HEADER, REQUEST_ID_PARAM_NAME} from './consts';
 import {extractErrorInfo} from './error-parser';
+import {NodeKitLogger} from './logging';
 
 type ContextParams = ContextInitialParams | ContextParentParams;
 
 interface ContextInitialParams {
     contextId?: string;
     config: AppConfig;
-    logger: pino.Logger;
+    logger: NodeKitLogger;
     tracer: JaegerTracer;
     stats: AppTelemetrySendStats;
     parentSpanContext?: SpanContext;
@@ -55,7 +55,7 @@ export class AppContext {
 
     protected appParams: AppContextParams;
     protected name: string;
-    private logger: pino.Logger;
+    private logger: NodeKitLogger;
     private tracer: JaegerTracer;
     private span?: Span;
     private startTime: number;
@@ -115,25 +115,35 @@ export class AppContext {
     }
 
     logError(message: string, error?: AppError | Error | unknown, extra?: Dict) {
-        if (error) {
-            this.logger.error(
-                Object.assign({}, this.prepareExtra(extra), extractErrorInfo(error)),
-                this.prepareLogMessage(message),
-            );
-        } else if (extra) {
-            this.logger.error(this.prepareExtra(extra), this.prepareLogMessage(message));
-        } else {
-            this.logger.error(this.loggerExtra, this.prepareLogMessage(message));
-        }
+        const preparedMessage = this.prepareLogMessage(message);
+        const preparedExtra = this.prepareExtra(extra);
+
+        const logObject = this.getLogObject(error, extra);
+
+        this.logger.error(logObject, preparedMessage);
 
         this.span?.setTag(Tags.SAMPLING_PRIORITY, 1);
         this.span?.setTag(Tags.ERROR, true);
-        this.span?.log(
-            Object.assign({}, this.prepareExtra(extra), {
-                event: message,
-                stack: error instanceof Error && error?.stack,
-            }),
-        );
+        this.span?.log({
+            ...preparedExtra,
+            event: message,
+            stack: error instanceof Error && error.stack,
+        });
+    }
+
+    logWarn(message: string, error?: AppError | Error | unknown, extra?: Dict) {
+        const preparedMessage = this.prepareLogMessage(message);
+        const preparedExtra = this.prepareExtra(extra);
+
+        const logObject = this.getLogObject(error, extra);
+
+        this.logger.warn(logObject, preparedMessage);
+
+        this.span?.log({
+            ...preparedExtra,
+            event: message,
+            stack: error instanceof Error && error.stack,
+        });
     }
 
     create(name: string, params?: Omit<ContextParentParams, 'parentContext'>) {
@@ -263,4 +273,14 @@ export class AppContext {
     private mergeExtra(extraParent: Dict | undefined, extraCurrent: Dict | undefined) {
         return Object.assign({}, extraParent, extraCurrent);
     }
+
+    private getLogObject(error: Error | unknown, extra: Dict | undefined) {
+        if (error) {
+            return {...this.prepareExtra(extra), ...extractErrorInfo(error)};
+        } else if (extra) {
+            return this.prepareExtra(extra);
+        } else {
+            return this.loggerExtra;
+        }
+    }
 }

src/lib/logging.ts

@@ -1,4 +1,79 @@
 import pino from 'pino';
+import {Dict} from '../types';
+
+export interface NodeKitLogger {
+    info(message: string): void;
+    info(extra: Dict | undefined, message: string): void;
+
+    error(message: string): void;
+    error(extra: Dict | undefined, message: string): void;
+
+    warn(message: string): void;
+    warn(extra: Dict | undefined, message: string): void;
+
+    trace(message: string): void;
+    trace(extra: Dict | undefined, message: string): void;
+
+    debug(message: string): void;
+    debug(extra: Dict | undefined, message: string): void;
+}
+
+export class PinoLogger implements NodeKitLogger {
+    private logger: pino.Logger;
+
+    constructor(logger: pino.Logger) {
+        this.logger = logger;
+    }
+    info(message: string): void;
+    info(extra: Dict | undefined, message: string): void;
+    info(msgOrExtra: string | Dict | undefined, message?: string): void {
+        if (typeof msgOrExtra === 'string') {
+            this.logger.info(message);
+        } else {
+            this.logger.info(msgOrExtra, message);
+        }
+    }
+
+    warn(message: string): void;
+    warn(extra: Dict | undefined, message: string): void;
+    warn(msgOrExtra: string | Dict | undefined, message?: string): void {
+        if (typeof msgOrExtra === 'string') {
+            this.logger.info(message);
+        } else {
+            this.logger.info(msgOrExtra, message);
+        }
+    }
+
+    error(message: string): void;
+    error(extra: Dict | undefined, message: string): void;
+    error(msgOrExtra: string | Dict | undefined, message?: string): void {
+        if (typeof msgOrExtra === 'string') {
+            this.logger.error(message);
+        } else {
+            this.logger.error(msgOrExtra, message);
+        }
+    }
+
+    trace(message: string): void;
+    trace(extra: Dict | undefined, message: string): void;
+    trace(msgOrExtra: string | Dict | undefined, message?: string): void {
+        if (typeof msgOrExtra === 'string') {
+            this.logger.trace(message);
+        } else {
+            this.logger.trace(msgOrExtra, message);
+        }
+    }
+
+    debug(message: string): void;
+    debug(extra: Dict | undefined, message: string): void;
+    debug(msgOrExtra: string | Dict | undefined, message?: string): void {
+        if (typeof msgOrExtra === 'string') {
+            this.logger.debug(message);
+        } else {
+            this.logger.debug(msgOrExtra, message);
+        }
+    }
+}
 
 /**
  * workaround to provide IntelliSense hints https://stackoverflow.com/a/61048124
@@ -34,9 +109,12 @@ export function initLogger({appName, devMode, destination, level = 'debug'}: Ini
         transport: transportConfig,
     };
 
+    let pinoInstance: pino.Logger;
     if (destination && !devMode) {
-        return pino(options, destination);
+        pinoInstance = pino(options, destination);
     } else {
-        return pino(options);
+        pinoInstance = pino(options);
     }
+
+    return new PinoLogger(pinoInstance);
 }

src/nodekit.ts

@@ -1,12 +1,11 @@
 import * as dotenv from 'dotenv';
 import {JaegerTracer, initTracer} from 'jaeger-client';
-import pino from 'pino';
 
 import {NODEKIT_BASE_CONFIG} from './lib/base-config';
 import {AppContext} from './lib/context';
 import {DynamicConfigPoller, DynamicConfigSetup} from './lib/dynamic-config-poller';
 import {loadFileConfigs} from './lib/file-configs';
-import {initLogger} from './lib/logging';
+import {NodeKitLogger, initLogger} from './lib/logging';
 import {prepareClickhouseClient} from './lib/telemetry/clickhouse';
 import {isTrueEnvValue} from './lib/utils/is-true-env';
 import prepareSensitiveHeadersRedacter, {
@@ -38,7 +37,7 @@ export class NodeKit {
         isTrueEnvValue: typeof isTrueEnvValue;
     };
 
-    private logger: pino.Logger;
+    private logger: NodeKitLogger;
     private tracer: JaegerTracer;
 
     private shutdownHandlers: ShutdownHandler[];
@@ -65,12 +64,16 @@ export class NodeKit {
             appLoggingLevel: process.env.APP_LOGGING_LEVEL || fileConfig.appLoggingLevel,
         });
 
-        this.logger = initLogger({
-            appName: this.config.appName as string,
-            devMode: appDevMode,
-            destination: this.config.appLoggingDestination,
-            level: this.config.appLoggingLevel,
-        });
+        if (this.config.appLogger) {
+            this.logger = this.config.appLogger;
+        } else {
+            this.logger = initLogger({
+                appName: this.config.appName as string,
+                devMode: appDevMode,
+                destination: this.config.appLoggingDestination,
+                level: this.config.appLoggingLevel,
+            });
+        }
 
         const redactSensitiveQueryParams = prepareSensitiveQueryParamsRedacter(
             this.config.nkDefaultSensitiveQueryParams?.concat(

src/tests/logging.test.ts

@@ -1,4 +1,5 @@
-import {NodeKit} from '..';
+import {NodeKit, NodeKitLogger} from '..';
+import {Dict} from '../types';
 
 const setupNodeKit = () => {
     const logger = {
@@ -136,3 +137,65 @@ test('check logging from nested ctx', () => {
         msg: `[${ctxName}] log error ${logPostfix}`,
     });
 });
+
+test('logging with a custom logger', () => {
+    const warnLog = jest.fn();
+    const debugLog = jest.fn();
+    const infoLog = jest.fn();
+    const errorLog = jest.fn();
+    const traceLog = jest.fn();
+    class CustomLogger implements NodeKitLogger {
+        warn(msgOrObject: string | Dict | undefined, message?: string) {
+            warnLog(msgOrObject, message);
+        }
+        debug(msgOrObject: string | Dict | undefined, message?: string) {
+            debugLog(msgOrObject, message);
+        }
+        info(msgOrObject: string | Dict | undefined, message?: string) {
+            infoLog(msgOrObject, message);
+        }
+        error(msgOrObject: string | Dict | undefined, message?: string) {
+            errorLog(msgOrObject, message);
+        }
+        trace(msgOrObject: string | Dict | undefined, message?: string) {
+            traceLog(msgOrObject, message);
+        }
+    }
+
+    const customLogger = new CustomLogger();
+    const nodekit = new NodeKit({
+        config: {
+            appLogger: customLogger,
+        },
+    });
+
+    const ctx = nodekit.ctx.create('test_ctx');
+
+    ctx.log('test');
+
+    expect(infoLog).toHaveBeenCalledWith(undefined, '[test_ctx] test');
+
+    const err = new Error('test errorLog');
+    ctx.logError('errorLog message', err);
+    expect(errorLog).toHaveBeenCalledWith(
+        {
+            err: {
+                message: 'test errorLog',
+                stack: err.stack,
+            },
+        },
+        '[test_ctx] errorLog message',
+    );
+
+    const warnErr = new Error('test warnLog');
+    ctx.logWarn('warnLog message', warnErr);
+    expect(warnLog).toHaveBeenCalledWith(
+        {
+            err: {
+                message: 'test warnLog',
+                stack: warnErr.stack,
+            },
+        },
+        '[test_ctx] warnLog message',
+    );
+});

src/types.ts

@@ -1,7 +1,7 @@
 import type {pino} from 'pino';
 
 import {REQUEST_ID_PARAM_NAME, USER_ID_PARAM_NAME, USER_LANGUAGE_PARAM_NAME} from './lib/consts';
-import type {LoggingLevel} from './lib/logging';
+import type {LoggingLevel, NodeKitLogger} from './lib/logging';
 
 export interface AppConfig {
     appName?: string;
@@ -24,6 +24,7 @@ export interface AppConfig {
 
     appLoggingDestination?: pino.DestinationStream;
     appLoggingLevel?: LoggingLevel;
+    appLogger?: NodeKitLogger;
 
     appTracingEnabled?: boolean;
     appTracingServiceName?: string;