Flutterアプリケーションでの効果的なログ出力

Flutterアプリケーションでの効果的なログ出力

Flutterに限った話ではなく、ログ出力はアプリ開発において重要な要素であり、開発者が問題を効率的に追跡し、デバッグするのを助けます。
本記事では、Flutterアプリケーションでのログ出力の実装方法について、さまざまなログレベル、ログのフォーマット、外部ログサービスの利用方法を解説し、Flutterにおける具体的なログ設計を提案します。

目次

1. ログの定義
   1.1. ログとは何か？
   1.2. なぜログが必要か？
   1.3. ログレベルとは？
2. ログ設計
   2.1. ログレベルを詳細に定義する
   2.2. 適切にエラーを送信する
3. Flutterアプリでのlog設計
   3.1. loggerの実装
   3.2. trace,debugのイベントを設定
   3.3. infoのイベントの設定
   3.3.1. ユーザの行動ログの記録
   3.3.2. 画面遷移イベント(screen_view)
   3.4. warningのイベントの設定
4. 最後に

1. ログの定義

まずはログとは何かを定義してから話したいと思います。
基本的な話のみなので、知っているよという方は3章のFlutterアプリでのlog設計からみてください。

1.1. ログとは何か？

ログは、アプリケーションが実行中に生成するメッセージの記録です。これらのメッセージは、アプリの動作状況、発生したイベント、エラーや警告などの情報を含んでいます。ログは通常、以下のような情報を含みます：

• イベントの発生時間
• イベントの内容
• イベントの重要度
• イベントが発生した場所

1.2. なぜログが必要か？

ログは、アプリケーション開発と運用の両方において重要な役割を果たします。以下は、ログが必要な理由のいくつかです：

• デバッグ: ログは、アプリケーションの動作を追跡し、エラーやバグを特定するのに役立ちます
• 監視: アプリケーションが正常に動作しているかどうかを監視するためにログを使用します。異常な動作を検出する手がかりとなります
• トラブルシューティング: 問題が発生した場合、ログはその原因を迅速に特定し、解決策を見つけるのに役立ちます
• データ分析を通してソフトウェアを改善するため: ユーザの行動を追跡し、どの機能がよく使われているか、どこで問題が発生しているかを分析するためにログを使用できます。この情報は、ソフトウェアの改善に役立ちます
• 法的証拠: 特定の業界やアプリケーションでは、ログが法的要件を満たすための証拠となる場合があります。例えば、金融機関や医療機関では、特定の操作履歴を保存することが法律で義務付けられていることがあります。ログはこれらの履歴を記録する手段として機能します

1.3. ログレベルとは？

ログレベルは、ログメッセージの重要度を示すために使用されます。これにより、開発者は必要に応じて特定のレベルのログメッセージのみをフィルタリングして表示できます。loggerパッケージでは、以下のログレベルが使用されます：

• trace: 最も詳細なログ。詳細なデバッグ情報を含みます
• debug: システムの動作状況に関する詳細な情報
• info: 一般的な情報。実行時の何らかの注目すべき事象（開始や終了など）
• warning: 警告メッセージ。エラーに近い事象など。実行時に生じた異常とは言い切れないが正常とも異なる何らかの予期しない問題
• error: エラーメッセージ。アプリケーションの一部が正しく動作しないことを示します
• fatal: 非常に重大なエラー。即時の対応が必要な場合に使用されます。 フロント開発の場合は、アプリがクラッシュするようなエラーもfatalとして扱う

これらのログレベルを適切に使用することで、アプリケーションの状態をより正確に把握し、必要な対応を迅速に行うことができます。

2. ログ設計

2章でログとは何かは理解できたかなと思うのですが、実際にどのようにしていくのかがまだイメージできてないかなと思っています。
この章では私が、具体的なログをどのように記録して、どのように役に立てていくのかを検討してみたのでそちらを記載します。

2.1 ログレベルをもっと詳細に定義する

ログレベルの意味だけでは何をどうすれば良いかわからないので、追加でログを見る人、何に使われるか、ログが目にされるタイミング、ログを流す場所を定義しました。

ログレベル	意味	logを見る人	具体的に何に使われるか	確認するタイミング	ログを流す場所
trace	最も詳細なログ。詳細なデバッグ情報を含みます	開発者	コードの細部を調査する際に使用。特に、特定の関数やプロセスの挙動を詳しく見る必要がある場合	デバッグセッション中や新機能の開発時	標準出力（console）
debug	システムの動作状況に関する詳細な情報	開発者	デバッグ作業中に使用。通常の動作における詳細情報を提供し、問題の原因を追跡するのに役立ちます	開発中およびデバッグセッション中	標準出力（console）
info	一般的な情報。実行時の何らかの注目すべき事象（開始や終了など）	開発者、運用担当者	システムの状態や重要なイベント（例えば、アプリケーションの起動や終了）を記録。正常な動作の確認に使用	日常的なモニタリングやシステムの稼働状況確認時	外部サービス（FBAなど）
warning	警告メッセージ。エラーに近い事象など。実行時に生じた異常とは言い切れないが正常とも異なる何らかの予期しない問題	開発者、運用担当者	潜在的な問題を示す。即座の対応は不要だが、後で調査する必要がある場合	定期的なログレビューや問題発生時	外部サービス（FBAなど）
error	エラーメッセージ。アプリケーションの一部が正しく動作しないことを示します	開発者、運用担当者	実行時エラーや障害を記録。問題の原因を特定し、修正が必要	問題発生時や障害発生後	外部サービス（crashlyticsやsentry）
fatal	非常に重大なエラー。即時の対応が必要な場合に使用されます	開発者、運用担当者	システム全体の停止や重大な障害を引き起こすエラーを記録。迅速な対応が必要	即時対応が求められる緊急時	外部サービス（crashlyticsやsentry）

ここで外部サービスが出てきていますが、外部サービスには二種類存在していると思っています。

1. ユーザの行動ログなどを記録し、アプリを改善するために使用するサービス
   • Firebase Analytics log(FBA)など
2. トラブルシューティングのために、エラーなどを記録し、管理してくれるサービス
   • Firebase CrashlyticsやSentry

ログはログとして、認識している方もいるかもですが、
ログの意味と役割を考えると、上記の外部サービスとログを統合することの有用性が分かっていただけると考えています。

2.2 適切にエラーを送信する

levelがtrace,debug,infoについてはあまり考えずに、logを流せば良いと思うのですが、
warning,error,fatalについては、非正常系の場合に発生するlogなので、きちんと考えないとトラブルシューティングなどに役に立たない情報になってしまう可能性があります。
考えるべきことは以下かなと思っています。

1. エラーを潰さずに、正確にログを流す
2. 1つのエラーから連鎖的にエラーが発生する場合、一番根元のエラーでログを送信する

上記を正確に処理するために、以下のルールを適用しています。

1. アプリ内だけで使用されるカスタムExceptionクラスを作成する
   1. AppExceptionという名前にします
   2. AppExceptionは抽象クラスとして定義し、各カスタムExceptionを用意するのが良いと思います
2. 特定の処理でtry catchにてerrorをcatchしたときに、想定されているerrorであればAppExceptionに変換します
   1. 変換する際に適切なlogを送信します
   2. 想定されていないExceptionに関しては、rethrowを行い、上位のレイヤーの処理に回します
   3. 最上位レイヤー(Flutterで言うとUI層)でAppExceptionに変換されていない場合は、原因不明のエラーとしてlogを出力します
3. try catchにてAppExceptionをcatchした場合は、logは出力されているので再度log出力をしないようにする

分かりにくいので、コードで説明すると具体的に以下のような形になります。

exception sample

/// アプリ内固有のカスタム例外クラス
abstract class AppException implements Exception {
  AppException(
    this.message,
  );
  final String message;
}

/// AppExceptionを継承したカスタム例外クラス
class AppFormatException extends AppException {
  AppFormatException(
    super.message,
  );
}

/// 適当に例外を発生させる。
void fizz() {
  try {
    if (DateTime.now().microsecondsSinceEpoch.isEven) {
      throw const FormatException('Invalid format');
    } else {
      throw Exception('unknown error');
    }
  } on FormatException catch (e, s) {
    logger.e(
      'FormatException caught',
      error: e,
      stackTrace: s,
    );
    throw AppFormatException('Handled FormatException');
  }
}

/// 最上位のUIレイヤーでエラーハンドリングを行う。
void fizzBuzz() {
  try {
    fizz();
  } on AppFormatException {
    // userに知らせる。
    ScaffoldMessenger.of(context).showSnackBar(
      const SnackBar(
        content: Text('フォーマットが不正です。'),
      ),
    );
  } on AppException catch (e) {
    /// どこかでAppExceptionに変換されているので
    /// logは流さずに、エラーをハンドリングする。
    showDialog(
      context: context,
      builder: (context) {
        return AlertDialog(
          title: Text(e.message),
        );
      },
    );
  } on Exception catch (e, s) {
    /// ここまで、どこでも、AppExceptionに変換されていないので
    /// 想定していない原因不明なエラーとしてログを出力する。
    logger.e(
      '原因不明のエラー',
      error: e,
      stackTrace: s,
    );
    showDialog(
      context: context,
      builder: (context) {
        return const AlertDialog(
          title: Text('原因不明のエラー'),
        );
      },
    );
  }
}

このような設計にすることによって、エラーの根本的な場所が明確になり、
トラブルシューティングが簡単になると思います。

エラーの場所を正確に把握するために、stackTraceの扱いには注意してください。
stackTraceはthrowされた場所を示します。そのため、rethrowではなくthrowでerrorを投げてしまうとstackTraceがその場所からエラーが発生したと記録することになります。
loggerを出力する際には、最初にエラーが発生した場所のstackTraceを含めるようにしてください。
また、エラーをAppExceptionに変換せず、上位レイヤーに伝搬させる場合にはrethrowを絶対に使用してください。

3. Flutterアプリでのlog実装

3章にてlog設計ができたので、そのルールに則った実装を行なっていきます。
また、今回はFBA,Firebase Crashlyticsを使用しているので
そちらの特有の設定についても記載しておきます。

3.1 loggerの実装

まず初めに2章で記載したログ設計に基づいたloggerの実装を行います。
loggerの実装については、以下の記事にてまとめているのでそちらをご確認ください。

コードの全貌は以下のようになっています。

logger.dart

import 'dart:developer' as dev;

import 'package:firebase_analytics/firebase_analytics.dart';
import 'package:firebase_core/firebase_core.dart';
import 'package:firebase_crashlytics/firebase_crashlytics.dart';
import 'package:flutter/foundation.dart';
import 'package:logger/logger.dart';

final logger = CustomLogger();

/// ログ出力をカスタマイズします。
///
/// t,dはconsoleに出力します。
/// i,wはFBAにログを送信します。
/// (wは集計して、どのユーザが遭遇しているかをみたい。)
/// e,fはFirebaseCrashlyticsにログを送信します。
class CustomLogger extends Logger {
  CustomLogger()
      : super(
          output: CustomOutput(),
          printer: PrettyPrinter(
            methodCount: 1, // 表示されるコールスタックの数
            errorMethodCount: 5, // 表示されるスタックトレースのコールスタックの数
            lineLength: 80, // 区切りラインの長さ
            printTime: true, // タイムスタンプを出力するかどうか
          ),
          level: kReleaseMode ? Level.info : Level.trace,
        );

  /// FBAにログを送信します。
  Future<void> _sendLog(
    String name,
    Map<String, String>? parameters,
  ) async {
    // 初期化されていない場合は終了
    if (Firebase.apps.isEmpty) return;
    try {
      return FirebaseAnalytics.instance
          .logEvent(name: name, parameters: parameters);
    } catch (e, s) {
      super.e('logの出力エラー', error: e, stackTrace: s);
    }
  }

  /// log出力とFBAにログを送信します。
  void info({
    required String name,
    Map<String, Object?>? parameters,
  }) {
    final logParameters =
        parameters?.map((key, value) => MapEntry(key, value.toString()));
    // log出します。
    // ignore: deprecated_member_use_from_same_package
    i(
      '$name: $logParameters',
    );
    _sendLog(name, logParameters);
  }

  /// warning出力とFBAにログを送信します。
  void warning({
    required String name,
    Object? error,
    StackTrace? stackTrace,
    Map<String, dynamic>? parameters,
  }) {
    final logParameters = {
      'error': error,
      'stackTrace': stackTrace,
      'level': 'warning',
      ...parameters ?? {},
    }.map((key, value) => MapEntry(key, value.toString()));
    // log出します。
    // ignore: deprecated_member_use_from_same_package
    w(
      name,
      error: error,
      stackTrace: stackTrace,
    );
    _sendLog(name, logParameters);
  }

  /// iを使用しないように警告を出します。
  @Deprecated('infoを使用してください。')
  @override
  void i(
    dynamic message, {
    DateTime? time,
    Object? error,
    StackTrace? stackTrace,
  }) {
    super.i(message, error: error, time: time, stackTrace: stackTrace);
  }

  /// wを使用しないように警告を出します。
  @Deprecated('warningを使用してください。')
  @override
  void w(
    dynamic message, {
    DateTime? time,
    Object? error,
    StackTrace? stackTrace,
  }) {
    super.w(message, error: error, time: time, stackTrace: stackTrace);
  }

  /// FirebaseCrashlyticsにerrorを記録する。
  Future<void> _recordError(
    dynamic message, {
    required Level level,
    Object? error,
    StackTrace? stackTrace,
  }) async {
    try {
      // 初期化されていない場合は終了
      if (Firebase.apps.isEmpty) return;
      await FirebaseCrashlytics.instance.recordError(
        error,
        stackTrace,
        reason: message,
        printDetails: false,
        fatal: level == Level.fatal,
      );
    } catch (e) {
      dev.log('logの出力エラー', name: 'logger');
    }
  }

  /// FirebaseCrashlyticsにログを送信する。
  Future<void> _sendMessage(
    dynamic message,
  ) async {
    try {
      if (Firebase.apps.isEmpty) return;
      await FirebaseCrashlytics.instance.log(message.toString());
    } catch (e) {
      dev.log('logの出力エラー', name: 'logger');
    }
  }

  @override
  void e(
    dynamic message, {
    DateTime? time,
    Object? error,
    StackTrace? stackTrace,
  }) {
    super.e(message, time: time, error: error, stackTrace: stackTrace);
    _recordError(
      message,
      level: Level.error,
      error: error,
      stackTrace: stackTrace,
    );
  }

  @override
  void f(
    dynamic message, {
    DateTime? time,
    Object? error,
    StackTrace? stackTrace,
  }) {
    super.f(message, time: time, error: error, stackTrace: stackTrace);
    _recordError(
      message,
      level: Level.fatal,
      error: error,
      stackTrace: stackTrace,
    );
  }

  /// FirebaseAnalytics,CrashlyticsにuserIdを設定する。
  Future<void> setUserId(String? id) async {
    try {
      // 初期化されていない場合は終了
      if (Firebase.apps.isEmpty) return;
      // FirebaseAnalyticsにuserIdを設定する
      await FirebaseAnalytics.instance.setUserId(id: id);
    } catch (e, s) {
      super.e('setUserIdの実行に失敗しました。', error: e, stackTrace: s);
    }
  }

  /// FBAにcustom keyを設定する。
  Future<void> setUserProperty({
    required String name,
    required String? value,
  }) async {
    try {
      // 初期化されていない場合は終了
      if (Firebase.apps.isEmpty) return;
      await FirebaseAnalytics.instance
          .setUserProperty(name: name, value: value);
    } catch (e, s) {
      super.e('setUserPropertyの実行に失敗しました。', error: e, stackTrace: s);
    }
  }
}

/// log出力をカスタマイズします。
///
/// デフォルトではiOSにて色が出力されないため、修正します。
class CustomOutput extends LogOutput {
  @override
  void output(OutputEvent event) {
    // log出します。
    for (final e in event.lines) {
      dev.log(e, name: 'logger');
    }
  }
}

3.2 trace,debugのイベントを設定

trace,debugについては開発時にしか出力しませんので、好きなところで使ってください。
また、出力するlogのサイズも気にする必要はないので、知りたい内容を出力してください。

3.3 infoのイベントの設定

infoについては、FBAに送信されます。
主にユーザの行動を記録するために使用します。

• ユーザが何かを選択した
• ユーザがボタンを押した
• ユーザが何かを始めた

...etc

3.3.1 ユーザの行動ログの記録

ログ設計とはまた別軸だと思いますが、ユーザの行動ログも適切に設計する必要があると思います。
特に私が大切だと思うのは、行動ログはユーザの行動を記録するものであって、解析結果を記録するものではないということです。

例えば、「Aの画面に滞在した時間を知りたい」と言う要求があったとすると、
以下二つの方法で記録することが考えられます。

1. Aが開かれたときに、アプリ内で記録し、Aを閉じる際の時間と差分をとって、「A画面の滞在時間イベント」として記録する
2. Aの画面が開かれた時のイベントと、Aの画面が閉じた時のイベントを記録して、BigQueryなどの解析サービスを使用して、差分を計算して滞在時間を計算する

言われるまでも無いかも知れないですが、2.の方法を採用し、ログはユーザの行動を記録するのみにして、アプリ内で計算はしない方が良いです。
ユーザの行動ログを記録するためだけに、アプリ内にロジックを記載しようとしているのなら、考えを改めた方が良いと思います。
コードが読みにくくなり、複雑性がまして、保守が難しくなります。

3.3.2 画面遷移イベント(screen_view)

FBAを使用する場合画面遷移イベント(screen_view)は特別なイベントとなり、
その他のイベントと一緒に現在の画面名が一緒に記録されます。
画面遷移イベントを適切に設定することで、ユーザの行動パターンを明快に知ることができます。
ですが、Flutterでは少し手を加えないと正確に設定することが難しいので設定を行う方法を記載します。

Flutterで画面遷移イベントを簡単に記録するためにはNavigatorObserverの使用を推奨します。
NavigatorObserverを使用すると、go_routerでの画面遷移も記録できますが、Dialog,BottomSheetなども記録することができます。

Dialog,BottomSheetなどは、RouteSettingを設定することを忘れないでください。
RouteSettingのnameとargumentsを指定することで正確にscree_viewを設定することができます。

FBAではAnalyticsNavigatorObserverが用意されているのですが、
そちらは以下の点で使いにくい部分があります。

• RouteSettingのargumentsを記録することができない
• go_router_builderで使用するとUnit Testで使用するとFirebase 初期化エラーが発生する

そのため、以下のように独自に作って記録するように変更しています。

custom_firebase_analytics_observer.dart

import 'package:dlsite_library/core/logger.dart';
import 'package:flutter/widgets.dart';

class CustomFirebaseAnalyticsObserver
    extends RouteObserver<ModalRoute<dynamic>> {
  CustomFirebaseAnalyticsObserver();
  Route<dynamic>? currentRoute;

  void sendScreenView(Route<dynamic> route) {
    final screenName = route.settings.name;

    late Map<String, dynamic> args;

    switch (route.settings.arguments) {
      case final Map<String, dynamic> arguments:
        args = arguments;
      case null:
        args = {};
      default:
        // map以外の場合はエラーログを出力して、アプリを正常に動作させるために空のMapを作成する
        logger.e(
          'not supported arguments type',
          error: ArgumentError('not supported arguments type'),
          stackTrace: StackTrace.current,
        );
        // アプリは正常に動作させる
        args = {};
    }
    if (screenName == null) return;
    try {
      currentRoute = route;
      logger.info(
        name: 'screen_view',
        parameters: {
          'screen_class': screenName,
          'screen_name': screenName,
          ...args,
        },
      );
    } catch (e, s) {
      logger.e('Failed to log screen view', error: e, stackTrace: s);
    }
  }

  @override
  void didPush(Route<dynamic> route, Route<dynamic>? previousRoute) {
    super.didPush(route, previousRoute);
    logger.d('didPush: ${route.settings.name}');
    sendScreenView(route);
  }

  @override
  void didReplace({Route<dynamic>? newRoute, Route<dynamic>? oldRoute}) {
    super.didReplace(newRoute: newRoute, oldRoute: oldRoute);
    if (newRoute == null) return;

    logger.d('didReplace: ${newRoute.settings.name}');
    sendScreenView(newRoute);
  }

  @override
  void didPop(Route<dynamic> route, Route<dynamic>? previousRoute) {
    super.didPop(route, previousRoute);
    if (previousRoute == null) return;

    logger.d('didPop: ${route.settings.name}');

    sendScreenView(previousRoute);
  }
}

Route? currentRoute を保持しているのは、go_router_builderのStatefulShellBranchDataを使用する場合に、Branch間の移動ではこのNavigatorObserverが動かない問題があるためです。
Branchを遷移する際は手動で、Observerを取得して、sendScreenViewを実行するようにしています。

class HogeBranch extends StatefulShellBranchData {
  HogeBranch();
  static final List<NavigatorObserver> $observers = [CustomFirebaseAnalyticsObserver()];

  /// 画面遷移時に、FirebaseAnalyticsにscreen_viewを送信する
  static void sendScreenView() {
    final observer = $observers.first as CustomFirebaseAnalyticsObserver;
    final currentRoute = observer.currentRoute;
    if (currentRoute != null) {
      observer.sendScreenView(currentRoute);
    }
  }
}

// 使い方 ブランチが移動された際に以下を実行
HogeBranch.sendScreenView()

また、flutterではデフォルトでUIViewController または Activity の内容を自動でscreen_viewとして記録する処理が入っています。特別な理由がない限りこの自動で記録する機能は混乱するだけなのでoffにした方が良いと思います。
offにする方法はこちらに記載されています。

3.4 warningのイベントの設定

warningは「エラーに近い事象など。実行時に生じた異常とは言い切れないが正常とも異なる何らかの予期しない問題」なので、FBAとして計測し、どの警告が一番発生しているかやどのようなユーザの動きで発生しているかなどを計測する必要があります。

そのため、FBAに送信します。
送信方法はinfoと同様です。

4. 最後に

効果的なログ出力は、Flutterアプリケーションのメンテナンスとデバッグにおいて非常に重要です。堅牢なログ出力メカニズムを設定し、異なるログレベルを活用し、適切にフォーマットされたログを外部サービスと統合することで、問題が迅速に特定され解決されるようになります。

Let's Flutter Life！！