Dartログ出力パッケージを確認

Dart loggingパッケージについてメモ書き。

Dart言語を本番運用で稼働させた時、ログ監視が必要になる。
ふと、「Dartってログ出力どうやるんだろう？」と思ったので調査する。

ネットを検索して出てくるのが、Dart標準の「loggingパッケージ」。
ログパッケージ自体は複数あるが、loggingパッケージはカスタマイズできるらしい。
さっそくこのパッケージを試してみる。

pub.devパッケージサイトで導入手順を確認。
pubspec.yamlに以下を追加。最新バージョンは公式サイトで確認する。

dependencies:
  logging: ^1.1.1

VS Code等の開発環境であれば、ファイルを保存することでパッケージが追加される。
テキストツールで更新しているのであれば「dart pub get」コマンドで追加する。

loggingパッケージをimport。これで準備OK.

import 'package:logging/logging.dart';

続いてコーディング。

import 'package:logging/logging.dart';

// ログメッセージの識別名を設定
final log = Logger('TestLogName');

void main() {
  // ①ログのルートレベルを設定。指定したレベル以上のメッセージが出力される。ALLは全て出力。デフォルトはINFO
  Logger.root.level = Level.ALL;
  // Streamで渡されたデータをlistenで受け取り、printで出力
  Logger.root.onRecord.listen(
    (record) {
      // ②出力メッセージのフォーマットを設定
      print('${record.level.name}: ${record.time}: ${record.message}');
    },
  );
  // ③Streamでメッセージを渡す
  log.info('テストメッセージ1');
  log.severe('テストメッセージ2');
}

②のフォーマットに従ってメッセージが出力される。

INFO: 2023-02-23 21:40:22.275457: テストメッセージ1
SEVERE: 2023-02-23 21:40:22.277489: テストメッセージ2

①のルートレベル設定は以下の通り。
上にいく程ログ出力メッセージが少なくなる。

ルートレベル設定
`Level.OFF`
`Level.SHOUT`
`Level.SEVERE`
`Level.WARNING`
`Level.INFO`
`Level.CONFIG`
`Level.FINE`
`Level.FINER`
`Level.FINEST`

試しにルートレベルを「Level.WARNING」にする。

Logger.root.level = Level.WARNING;

INFOが表示されなくなった。

SEVERE: 2023-02-23 21:58:44.309991: テストメッセージ2

③のStreamでメッセージを渡すlogメソッドは以下の通り。

loggingメソッド
log.shout()
log.severe()
log.warning()
log.info()
log.config()
log.fine()
log.finer()
log.finest()

②の出力メッセージのフォーマットで使用できる値を確認。
pub.devサイトのReadmeに記載がないので、ソースを見ることにする。
loggingパッケージの保存場所はpackage_config.jsonに書いてある。ホームディレクトリ配下の「~/.pub-cache/hosted/pub.dev/logging-1.1.1」となっていた。ディレクトリを開く。

importで読み込んでいるlogging.dartを開く。ここでは以下3ファイルをexportしている。

export 'src/level.dart';
export 'src/log_record.dart';
export 'src/logger.dart';

log_record.dartにフォーマットに使用できる値がコーディングされていた。
「level、message、time」以外に以下が設定されている。
設定値にコメントが付いているので、和訳しておく。

設定値	コメント
loggerName	ログの記録先。Logger()で設定。
sequenceNumber	ログのシーケンス番号。出力順に採番される。
error	エラーに関連するメッセージ。
stackTrace	エラーに関連するスタックトレース。
zone	LogRecord を生成した呼び出しコードのゾーン。

zoneというのは実行場所のコンテキストらしい。とりあえず試してみる。
先ずはlogメソッドの引数を確認する。

「message」が必須、「error」「stackTrace」がオプション引数となっている。
「error」「stackTrace」は例外処理用だろうね。

出力レベルをALLに戻す。

Logger.root.level = Level.ALL;

②の出力メッセージのフォーマットを変更。

'leve:${record.level.name} time:${record.time} message:${record.message} loggerName:${record.loggerName} sequenceNumber:${record.sequenceNumber} zone:${record.zone} error:${record.error} stackTrace:${record.stackTrace}'

「error」「stackTrace」の出力結果を検証するため、例外処理を追加。
log.severe()はcatch文で実行する。

// 例外処理用のクラス。logTest()は常にエラーを返す
class ErrTest {
  bool logbool = true;
  void logTest() {
    if (logbool) {
      throw Error();
    }
  }
}

// 例外処理検証用
try {
  ErrTest errtest = ErrTest();
  errtest.logTest();
} catch (e, st) {
  // 第２引数にエラー、第３引数にスタックトレースを追加
  log.severe('テストメッセージ2', e, st);
}

ソースコードは以下の通り。

import 'package:logging/logging.dart';

// ログメッセージの識別名を設定
final log = Logger('TestLogName');

void main() {
  // ①ログの出力レベルを設定。指定したレベル以上のメッセージが出力される。ALLは全て出力。デフォルトはINFO
  Logger.root.level = Level.ALL;
  // Streamで渡されたデータをlistenで受け取り、printで出力
  Logger.root.onRecord.listen(
    (record) {
      // ②出力メッセージのフォーマットを設定
      print(
          'leve:${record.level.name} time:${record.time} message:${record.message} loggerName:${record.loggerName} sequenceNumber:${record.sequenceNumber} zone:${record.zone} error:${record.error} stackTrace:${record.stackTrace}');
    },
  );
  // ③Streamでメッセージを渡す
  log.info('テストメッセージ1');

  // 例外処理検証用
  try {
    ErrTest errtest = ErrTest();
    errtest.logTest();
  } catch (e, st) {
　　// 第２引数にエラー、第３引数にスタックトレースを追加
    log.severe('テストメッセージ2', e, st);
  }
}

// 例外処理用のクラス。logTest()は常にエラーを返す
class ErrTest {
  bool logbool = true;
  void logTest() {
    if (logbool) {
      throw Error();
    }
  }
}

プログラムを実行する。
ログ出力結果は以下の通り。ログ監視する場合はリダイレクト等でファイルへ出力。

% dart run bin/dev1.dart
leve:INFO time:2023-02-24 23:17:23.063638 message:テストメッセージ1 loggerName:TestLogName sequenceNumber:0 zone:Instance of '_RootZone' error:null stackTrace:null
leve:SEVERE time:2023-02-24 23:17:23.065844 message:テストメッセージ2 loggerName:TestLogName sequenceNumber:1 zone:Instance of '_RootZone' error:Instance of 'Error' stackTrace:#0      ErrTest.logTest (file:///Users/*********/app/dart/dev1/bin/dev1.dart:34:7)
#1      main (file:///Users/*********/app/dart/dev1/bin/dev1.dart:23:13)
#2      _delayEntrypointInvocation.<anonymous closure> (dart:isolate-patch/isolate_patch.dart:297:19)
#3      _RawReceivePort._handleMessage (dart:isolate-patch/isolate_patch.dart:192:26)