NestjsでLogging - winstonを使ってファイルに残す & SQLクエリもちゃんとLogging

# はじめに
Nestjsを使い始めてから、なんとなく書き味が分かってきたのでドキュメント化します。
最初はログです。実行したSQLクエリをログファイルに残すのがゴールです。

リポジトリ：https://github.com/michihiko-karino/nestjs-query-logger-sample

# TableOfContents

- NestjsのLoggingのやり方
- 公式Docの最後でwinstonが紹介されてるので使ってみた
- SQLクエリもログとしてファイルに残したいね。TypeORMのLoggerを使ってみた

## NestjsのLoggingのやり方
公式Doc：https://docs.nestjs.com/techniques/logger

公式Docを要約しますと

- `@nestjs/common`の`Logger`クラスがビルトインされています。
- カスタマイズしたい場合は、`LoggerService`インタフェースを実装したクラスを準備してください
- 本番環境でそれぞれの要件に沿う高度なロギングが必要となる場合は[winston](https://github.com/winstonjs/winston)のようなロガーライブラリをNestjsと組み合わせて使うことも出来ます

公式Docの示す通り実装すれば、ひとまずLoggingできることが分かりました。

## 公式Docの最後でwinstonが紹介されてるので使ってみた
次に、ログをファイルに残すことを考えてみます。公式でも紹介されているwinstonを使ってみます

https://github.com/michihiko-karino/nestjs-query-logger-sample/blob/master/src/logger/logger.service.ts

```typescript
import * as winston from 'winston';
import { LoggerService } from '@nestjs/common';

// https://github.com/winstonjs/winston
export class Logger implements LoggerService {
  logger: winston.Logger;

  constructor() {
    const fileFormat = winston.format.combine(
      winston.format.timestamp(),
      winston.format.json(),
    );

    // levelにdebugを指定することでdebug以上のLevelのログが出力される
    // https://github.com/winstonjs/winston#logging
    const logger = winston.createLogger({
      // winstonの機能として、複数のtransport先を指定することができます。
      // 今回の場合であれば、ConsoleとFile両方に出力しています
      transports: [
        new winston.transports.Console({
          level: 'debug',
          format: winston.format.combine(
            winston.format.colorize(),
            winston.format.simple(),
          ),
        }),
        // またFile出力で、「エラーログだけで別ファイルに残したい」などの要件は、levelを指定することで実現できます
        new winston.transports.File({
          filename: 'log/error.log',
          level: 'error',
          format: fileFormat,
        }),
        new winston.transports.File({
          filename: 'log/combined.log',
          level: 'debug',
          format: fileFormat,
        }),
      ],
    });

    this.logger = logger;
  }

  log(message: string) {
    this.logger.log({
      level: 'info',
      message: `${message}`,
    });
  }

  error(message: string, trace: string) {
    this.logger.log({
      level: 'error',
      message: `${message}:${trace}`,
    });
  }

  warn(message: string) {
    this.logger.log({
      level: 'warn',
      message: `WARNING: ${message}`,
    });
  }

  debug(message: string) {
    this.logger.log({
      level: 'debug',
      message: `${message}`,
    });
  }

  verbose(message: string) {
    this.logger.log({
      level: 'verbose',
      message: `${message}`,
    });
  }
}
```

NestjsのLoggerServiceとしては、`log`, `error`, `warn`のメソッドを最低限実装する必要がありますが、`debug`, `verbose`に関しては実装しなくても大丈夫です。
チームや、利用したい状況などを加味して決められればと思います。


## SQLクエリもログとしてファイルに残したいね。TypeORMのLoggerを使ってみた
次です、SQLクエリをConsoleにもFileにものこしたいです。
今回はTypeOrmを使う前提でいきます。

`TypeOrmModule`のモジュールインポートの部分で`logging: true`を渡してあげれば、一先ずコンソールにSQLがでます。

```typescript
...省略...
@Module({
  imports: [
    TypeOrmModule.forRoot({
      ...省略...
      logging: true,
    }),
    LoggerModule,
  ],
...省略...
```

以下のような感じで出ます

> query: SELECT `users`.`id` AS `users_id`, `users`.`name` AS `users_name`, `users`.`email` AS `users_email` FROM `users` `users` WHERE `users`.`id` = ? -- PARAMETERS: [1]

開発時であればこれで満足なときもありますが、本番だとファイルでも残っていると嬉しいこともありますよね

こちらも同じように`typeorm`から`Logger`インタフェースが提供されていますので、それを実装していきましょう

https://github.com/michihiko-karino/nestjs-query-logger-sample/blob/master/src/logger/queryLogger.ts

```typescript
  logQueryError(
    error: string,
    query: string,
    parameters?: any[],
    queryRunner?: QueryRunner,
  ) {
    this.logger.error(this.queryRawer(query, parameters), error);
  }
...省略...

// RAW SQLを出力する
  private queryRawer(query: string, parameters?: any[]): string {
    if (!parameters) {
      return query;
    }
    const copyParams = Array.from(parameters);
    return query.replace(/\?/g, () => copyParams.shift() || '?');
  }
```

`this.logger`は自分で実装したLoggerクラスです。Winstonを利用しているので、そのままファイルにも出力されます。

注意してほしいポイントとしては、`logQueryError`メソッドで渡される`query`文字列では、TypeORMの`find`オプションの`where`などで指定した動的なパラメタは`?`で表現されているため、実際に発行されたクエリでは無いということです。パラメタは`parameters`変数に格納されています。

私はRawなSQLが欲しかったためメソッドを一つ噛ませています。しかしここでも注意してほしいのが、`parameters`を破壊的に変更すると、実際のクエリ発行時にエラーが発生します。なので`Array.from`を使って配列を複製しています。
バグ的な挙動なため将来的には解消されるかもしれません。

後は、こちらのクラスのインスタンスを`TypeOrmModule`のモジュールインポートの部分で`logger`オプションに渡してあげればロギング完了です

### 余談：`.where('users.name = "?"')`のようなクエリを書くと死ぬ
上記のバグ的な挙動が気になってデバッグしたら、ほとんど場合で必ずエラーを吐くクエリを発見しました。

```typescript
createQueryBuilder()
  .select('users')
  .from(User, 'users')
  .where('users.name = "?"')
  .orWhere('users.id = :id', { id: 1 })
  .getOne()
```

`.where('users.name = "?"')`の箇所を`.where('users.name = :name', { name: '?' })`と書けばエラーは発生しません。
TypeORMを使う場合は、SQLに直接`?`を書くことはしないようにしましょう。

### 他に
アクセスログとかも出したいですが、まだ未チャレンジです。
たぶん簡単にできると思います

以上