💤

NestJS カスタムロガーサンプル

2022/04/13に公開

NestJSのカスタムロガーなかなか作る機会ないかつコードサンプルも少ないので共有します。

僕の場合はexpressからの移行コードがあったため、スクラッチで作ったのですが、NestJS対応のログライブラリを探して使うほうが早い気がします。

こちらの記事を参考にさせていただきました。感謝。
https://zenn.dev/ozen/articles/79e2bfc49a4b5a

公式サイトリファレンス
https://docs.nestjs.com/techniques/logger

NestJSにおけるログのカスタマイズ3種

NestJSには3つのログのカスタマイズ方法が提供されています。

  1. ビルトインロガーにオプションを渡す。
  2. インターフェース LoggerService を実装する。
  3. ビルトインロガー ConsoleLoggerを拡張する。

ビルトインロガーにオプションを渡す

ロガーを無効化したり、

const app = await NestFactory.create(AppModule, {
  logger: false,
});
await app.listen(3000);

出力させるレベルを指定できたりします。

const app = await NestFactory.create(AppModule, {
  logger: ['error', 'warn'],
});
await app.listen(3000);

メリット

  • 簡単

デメリット

  • ロガーの無効化や出力させるレベル以外の指定はできない

インターフェース LoggerService を実装する

NestJSからLoggerServiceインターフェースが提供されてあるので、log error warn debug verboseをそれぞれ実装します。

import { LoggerService } from '@nestjs/common';

export class MyLogger implements LoggerService {
  /**
   * Write a 'log' level log.
   */
  log(message: any, ...optionalParams: any[]) {}

  /**
   * Write an 'error' level log.
   */
  error(message: any, ...optionalParams: any[]) {}

  /**
   * Write a 'warn' level log.
   */
  warn(message: any, ...optionalParams: any[]) {}

  /**
   * Write a 'debug' level log.
   */
  debug?(message: any, ...optionalParams: any[]) {}

  /**
   * Write a 'verbose' level log.
   */
  verbose?(message: any, ...optionalParams: any[]) {}
}
main.ts
const app = await NestFactory.create(AppModule, {
  logger: new MyLogger(), // 指定
});
await app.listen(3000);

メリット

  • 拡張しやすい。

デメリット

  • NestJSが独特なログの扱いをする。

ロガーを自分で作ったとき、NestJSのログも対応したいと思います。NestJSはログを独特な扱い方をします。

たとえば以下のように、logger.logで3つの引数を指定したとします。

import {
  Logger,
} from '@nestjs/common';

const logger = new Logger('context');

// 例えばこのように書くと...
logger.log('test1', 'test2', 'test3');

これは3行で標準出力に出力されます。

// 3行で出力される
// context test1
// context test2
// context test3

もし自分でロガーを作るなら、この挙動も再現しないといけません。これが結構大変でした。後ほど解説します。

ビルトインロガー ConsoleLoggerを拡張する

完全にフルスクラッチで書くよりも、部分的に既存のロガーを拡張したいときもあります。そのときはConsoleLoggerを extends します。

import { ConsoleLogger } from '@nestjs/common';

export class MyLogger extends ConsoleLogger {
  error(message: any, stack?: string, context?: string) {
    // add your tailored logic here
    super.error(...arguments);
  }
}

メリット

  • 拡張しやすい。

デメリット

  • NestJSが独特なログの扱いをする。

ConsoleLogger を拡張してJSONを出力させてみた

今回なぜカスタムロガーを作りたかったのかというと、expressからNestJSへコードを移行過程で既存のコードを活かしたかったからです。

以前のコードでは次のように、ログレベルと第1引数にメッセージ、第2引数にjsonを渡していました。

const logger = new Logger('hoge');
logger.info('message', { requestId: 'rejakjgkjak4jet', userId: 1 });

これが標準出力に次のようにjsonで出力されていました。

{
  "level": "info",
  "message": "message",
  "requestId": "rejakjgkjak4jet",
  "userId": 1
}

この書き方にも対応したかったので、ConsoleLoggerを拡張しました。ただし、前の章で言及したように、NestJS独自のログの使い方にも対応する必要があったため、なかなか大変でした。

実際に拡張してみた

オリジナルロガーにはwinstonを使ってます。

もともとの書き方とNestJSの書き方に対応させます。

const logger = new Logger('hoge');

// このように書くと...
logger.log('test1', 'test2', 'test3');
// 3行で出力される
// { "level": "info", "context": "hoge", "message": "test1" }
// { "level": "info", "context": "hoge", "message": "test2" }
// { "level": "info", "context": "hoge", "message": "test3" }

// このように書くと
logger.log('message', { requestId: 'rejakjgkjak4jet', userId: 1 });
// 1行で出力される 
// { "level": "info", "context": "hoge", "message": "message", "requestId": "rejakjgkjak4jet", "userId": 1 }

タイプ判別util。NestJSのロガー対応で利用します。

share/util
export const isString = (val: any): val is string => {
  return typeof val === 'string';
};

export const isUndefined = (obj: any): obj is undefined =>
  typeof obj === 'undefined';
export const isNil = (val: any): val is null =>
  isUndefined(val) || val === null;

export const isObject = (fn: any): fn is object =>
  !isNil(fn) && typeof fn === 'object';

export const isPlainObject = (fn: any): fn is object => {
  if (!isObject(fn)) {
    return false;
  }
  const proto = Object.getPrototypeOf(fn);
  if (proto === null) {
    return true;
  }
  const ctor =
    Object.prototype.hasOwnProperty.call(proto, 'constructor') &&
    proto.constructor;

  return (
    typeof ctor === 'function' &&
    ctor instanceof ctor &&
    Function.prototype.toString.call(ctor) ===
      Function.prototype.toString.call(Object)
  );
};

ロガーサービスです。isConventionalLogがtrueであれば自分が使っていた書き方、falseであればNestJSの書き方であると判別しています。NestJSの書き方はよくわからなかったのですが、内部を覗いてコード借りてきました。

logger/myLogger.sevice.ts
/* eslint-disable @typescript-eslint/ban-types */

/* eslint-disable @typescript-eslint/no-explicit-any */
import { ConsoleLogger, ConsoleLoggerOptions } from '@nestjs/common';
import winston from 'winston';

import { isString, isPlainObject } from '../share/util';

export class MyLoggerService extends ConsoleLogger {
  private logger: winston.Logger;

  // contextを指定できる。 const logger = new Logger('context');
  constructor(context: string | undefined, options: ConsoleLoggerOptions) {
    super(context ?? 'no detect', options);
    const transports = [
      new winston.transports.Console({
        silent: process.env.LOG_SILENT === 'true',
        format: winston.format.combine(winston.format.json()),
        level: process.env.LOG_LEVEL || 'info',
      }),
    ];

    this.logger = winston.createLogger({
      transports,
    });
  }

  log(comment: string, ...optionalParams: [...any, string?]): void {
    if (this.isConventionalLog(optionalParams)) {
      this.printLikeConventional(comment, 'info', optionalParams[0]);
    } else {
      const { messages, context } = this.localGetContextAndMessagesToPrint([
        comment,
        ...optionalParams,
      ]);
      this.printLikeNest(messages, 'info', context);
    }
  }

  error(comment: string, ...optionalParams: [...any, string?, string?]): void {
    if (this.isConventionalLog(optionalParams)) {
      this.printLikeConventional(comment, 'error', optionalParams[0]);
    } else {
      const { stack, messages, context } =
        this.localGetContextAndStackAndMessagesToPrint([
          comment,
          ...optionalParams,
        ]);
      this.printLikeNest(messages, 'error', context);
      if (stack) {
        this.logger
          .child({
            context: context ?? this.context,
          })
          .error(stack);
      }
    }
  }

  debug(comment: string, ...optionalParams: [...any, string?]): void {
    if (this.isConventionalLog(optionalParams)) {
      this.printLikeConventional(comment, 'debug', optionalParams[0]);
    } else {
      const { messages, context } = this.localGetContextAndMessagesToPrint([
        comment,
        ...optionalParams,
      ]);
      this.printLikeNest(messages, 'debug', context);
    }
  }

  warn(comment: string, ...optionalParams: [...any, string?]): void {
    if (this.isConventionalLog(optionalParams)) {
      this.printLikeConventional(comment, 'warn', optionalParams[0]);
    } else {
      const { messages, context } = this.localGetContextAndMessagesToPrint([
        comment,
        ...optionalParams,
      ]);
      this.printLikeNest(messages, 'warn', context);
    }
  }

  private isConventionalLog(
    optionalParams: [...any, string?, string?],
  ): boolean {
    return (
      optionalParams.length > 0 &&
      optionalParams.length <= 2 && // contextが指定されると自動的にベースクラスがoptionalParamsの最後に追加してくるため、2つはあり得る。
      isPlainObject(optionalParams[0])
    );
  }

  // 複数行で出力させる。
  private printLikeNest(
    messages: string[],
    level: 'info' | 'warn' | 'error' | 'debug',
    context?: string,
  ): void {
    switch (level) {
      case 'info':
      default:
        messages.forEach((message) => {
          this.logger
            .child({
              context: context ?? this.context,
            })
            .info(message);
        });
        break;
      case 'warn':
        messages.forEach((message) => {
          this.logger
            .child({
              context: context ?? this.context,
            })
            .warn(message);
        });
        break;
      case 'error':
        messages.forEach((message) => {
          this.logger
            .child({
              context: context ?? this.context,
            })
            .error(message);
        });
        break;
      case 'debug':
        messages.forEach((message) => {
          this.logger
            .child({
              context: context ?? this.context,
            })
            .debug(message);
        });
        break;
    }
  }

  // 従来の出力の仕方
  private printLikeConventional(
    comment: string,
    level: 'info' | 'warn' | 'error' | 'debug',
    options: object,
  ): void {
    switch (level) {
      case 'info':
      default:
        this.logger
          .child({
            context: this.context,
            ...options,
          })
          .info(comment);
        break;
      case 'warn':
        this.logger
          .child({
            context: this.context,
            ...options,
          })
          .warn(comment);
        break;
      case 'error':
        this.logger
          .child({
            context: this.context,
            ...options,
          })
          .error(comment);
        break;
      case 'debug':
        this.logger
          .child({
            context: this.context,
            ...options,
          })
          .debug(comment);
        break;
    }
  }

  /**
   * ベースクラスのやつ引き出して来た。
   * @param args
   * @returns
   */
  private localGetContextAndStackAndMessagesToPrint(
    args: [...any, string?, string?],
  ): {
    stack?: string;
    messages: string[];
    context?: string;
  } {
    const { messages, context } = this.localGetContextAndMessagesToPrint(args);

    const lastElement = messages[messages.length - 1];
    const isStack = isString(lastElement);
    if (!isStack) {
      return { messages, context };
    }

    return {
      stack: lastElement,
      messages: messages.slice(0, messages.length - 1),
      context,
    };
  }

  /**
   * ベースクラスのやつ引き出して来た。
   * @param args
   * @returns
   */
  private localGetContextAndMessagesToPrint(args?: [...any, string?] | null): {
    context?: string;
    messages: string[];
  } {
    if (!args || args.length <= 0) {
      return { messages: [], context: this.context };
    }
    const lastElement = args[args.length - 1];
    const isContext = isString(lastElement);
    if (!isContext) {
      return { messages: args, context: this.context };
    }

    return {
      context: lastElement,
      messages: args.slice(0, args.length - 1),
    };
  }
}
app.module.ts
import { MyLoggerModule } from './myLogger/myLogger.module';

@Module({
  imports: [
    MyLoggerModule,
  ],
})
export class AppModule
logger/myLogger.module.ts
import { Module } from '@nestjs/common';

import { MyLoggerService } from './myLogger.service';

@Module({
  providers: [MyLoggerService],
  exports: [MyLoggerService],
})
export class MyLoggerModule {}
main.ts
  const app = await NestFactory.create(AppModule);
  app.useLogger(app.get(MyLoggerService));

Discussion