ProtoLog

Android ロギング システムは、すべてのログデータを文字列として表現できるという前提に基づき、誰もが簡単にアクセスして使用できるように設計されています。この前提はほとんどのユースケースに当てはまりますが、特に、専用のツールを使用せずにログを読み取る必要がある場合に重要となります。ただし、ロギングのパフォーマンスを高めてログサイズを制限することが求められる環境では、テキストベースのロギングが最適ではないこともあります。そのようなシナリオの一つが WindowManager です。このシナリオでは、システムへの影響を最小限に抑えながら、リアルタイムのウィンドウ遷移ログを処理できる堅牢なロギング システムが必要となります。

ProtoLog は WindowManager などのサービスでのロギングのニーズに対応するための代替手段です。Logcat と比較した場合の ProtoLog の主なメリットは次のとおりです。

  • ロギングに使用されるリソースの量を抑えられます。
  • デベロッパー側では、デフォルトの Android ロギング フレームワークを使用する場合と違いはありません。
  • 実行時にログ ステートメントを有効または無効にできます。
  • 必要に応じて Logcat にログを記録できます。

ProtoLog はメモリ使用量を最適化するために、文字列インターン メカニズムを使用します。このメカニズムでは、メッセージのコンパイル済みハッシュの計算と保存が行われます。パフォーマンス向上のため、ProtoLog はコンパイル時に文字列インターンを実行し(システム サービスの場合)、実行時にメッセージ ID と引数のみを記録します。また、ProtoLog トレースの生成時またはバグレポートの取得時に、ProtoLog はコンパイル時に作成されたメッセージ辞書を自動的に組み込み、ビルドからのメッセージのデコードができるようにします。

ProtoLog を使用すると、メッセージは Perfetto トレース内にバイナリ形式(proto)で保存されます。メッセージのデコードは Perfetto の trace_processor 内で行われます。このプロセスでは、バイナリ proto メッセージをデコードし、組み込まれたメッセージ辞書を使用してメッセージ ID を文字列に変換し、動的な引数を使用して文字列をフォーマットします。

ProtoLog は android.utils.Log と同じログレベル(dviwewtf)をサポートしています。

クライアントサイドの ProtoLog

当初、ProtoLog は WindowManager のサーバーサイド専用で、単一のプロセスとコンポーネント内で機能するものでした。その後、システム UI プロセスの WindowManager シェルコードも対象に含まれるようになりましたが、ProtoLog を使用するには複雑なボイラープレート セットアップ コードが必要でした。さらに、Proto ロギングはシステム サーバー プロセスとシステム UI プロセスに限定されていたため、他のプロセスに組み込むのは手間がかかり、それぞれに個別のメモリバッファを設定する必要がありました。現在は、ProtoLog をクライアントサイド コードで利用できるようになり、追加のボイラープレート コードは不要になっています。

システム サービス コードとは異なり、クライアントサイド コードでは通常、コンパイル時の文字列インターンがスキップされます。その代わり、文字列インターンはバックグラウンド スレッドで動的に実行されます。その結果、クライアントサイドの ProtoLog は、メモリ使用量に関してはシステム サービス上の ProtoLog と同等のメリットがありますが、パフォーマンス オーバーヘッドはわずかに高くなり、サーバーサイドの ProtoLog での固定されたメモリによるメモリ削減というメリットはありません。

ProtoLog のグループ

ProtoLog メッセージは ProtoLogGroups というグループにまとめられます。Logcat メッセージが TAG でまとめられるのと同様です。この ProtoLogGroups はメッセージのクラスタとして機能し、実行時にまとめて有効または無効にできます。また、コンパイル時にメッセージを削除するかどうかと、ログを記録する場所(proto、Logcat、その両方)も制御します。各 ProtoLogGroup は次のプロパティで構成されます。

  • enabled: false に設定すると、このグループ内のメッセージはコンパイル時に除外され、実行時に使用できなくなります。
  • logToProto: このグループのログをバイナリ形式で記録するかどうかを指定します。
  • logToLogcat: このグループのログを Logcat に記録するかどうかを指定します。
  • tag: ログに記録されたメッセージのソースの名前。

ProtoLog を使用する各プロセスでは、ProtoLogGroup インスタンスを構成する必要があります。

サポートされている引数の型

内部的には、ProtoLog のフォーマット文字列には android.text.TextUtils#formatSimple(String, Object...) が使用されているため、構文は同じです。

ProtoLog は次の引数の型をサポートしています。

  • %b - ブール値
  • %d%x - 整数型(short、integer、long)
  • %f - 浮動小数点型(float または double)
  • %s - 文字列
  • %% - パーセントの文字リテラル

幅修飾子と精度修飾子(%04d%10b など)はサポートされていますが、argument_indexflags はサポートされていません。

新しいサービスでの ProtoLog の使用

新しいプロセスで ProtoLog を使用する方法は次のとおりです。

  1. そのサービスの ProtoLogGroup 定義を作成します。

  2. 定義を初めて使用する前(プロセスの作成時など)に初期化します。

    Protolog.init(ProtologGroup.values());

  3. Protologandroid.util.Log と同じ方法で使用します。

    ProtoLog.v(WM_SHELL_STARTING_WINDOW, "create taskSnapshot surface for task: %d", taskId);

コンパイル時の最適化の有効化

プロセスでコンパイル時の ProtoLog を有効にするには、ビルドルールを変更して protologtool バイナリを呼び出す必要があります。

ProtoLogTool は文字列インターンを実行し、ProtoLog 呼び出しを更新するコード変換バイナリです。このバイナリは次の例のとおり、すべての ProtoLog ロギング呼び出しを変換します。

ProtoLog.x(ProtoLogGroup.GROUP_NAME, "Format string %d %s", value1, value2);

変換後:

if (ProtoLogImpl.isEnabled(GROUP_NAME)) {
    int protoLogParam0 = value1;
    String protoLogParam1 = String.valueOf(value2);
    ProtoLogImpl.x(ProtoLogGroup.GROUP_NAME, 1234560b0100, protoLogParam0, protoLogParam1);
}

この例では、ProtoLogProtoLogImplProtoLogGroup は引数として指定されたクラス(インポート、静的インポート、完全パスのいずれかで、ワイルドカードのインポートは使用不可)で、x はロギング メソッドです。

変換はソースレベルで行われます。ハッシュはフォーマット文字列、ログレベル、ロググループ名から生成され、ProtoLogGroup 引数の後に挿入されます。実際に生成されたコードはインライン化され、改行文字がいくつか追加されて、ファイル内の行番号を保持します。

例:

genrule {
    name: "wm_shell_protolog_src",
    srcs: [
        ":protolog-impl", // protolog lib
        ":wm_shell_protolog-groups", // protolog groups declaration
        ":wm_shell-sources", // source code
    ],
    tools: ["protologtool"],
    cmd: "$(location protologtool) transform-protolog-calls " +
        "--protolog-class com.android.internal.protolog.ProtoLog " +
        "--loggroups-class com.android.wm.shell.protolog.ShellProtoLogGroup " +
        "--loggroups-jar $(location :wm_shell_protolog-groups) " +
        "--viewer-config-file-path /system_ext/etc/wmshell.protolog.pb " +
        "--legacy-viewer-config-file-path /system_ext/etc/wmshell.protolog.json.gz " +
        "--legacy-output-file-path /data/misc/wmtrace/shell_log.winscope " +
        "--output-srcjar $(out) " +
        "$(locations :wm_shell-sources)",
    out: ["wm_shell_protolog.srcjar"],
}

コマンドライン オプション

ProtoLog の主なメリットの一つは、実行時に有効または無効にできることです。たとえば、ビルドでは詳細なロギングをデフォルトで無効にしておき、ローカルでの開発時には有効にして特定の問題をデバッグできます。この方法は、たとえば WindowManager で、WM_DEBUG_WINDOW_TRANSITIONS グループと WM_DEBUG_WINDOW_TRANSITIONS_MIN グループを使用してさまざまなタイプの遷移ロギングを有効にする場合に使用されます。なお、前者はデフォルトで有効になっています。

トレースを開始するときに、Perfetto を使用して ProtoLog を構成できます。また、adb コマンドラインを使用して ProtoLog をローカルで構成することもできます。

adb shell cmd protolog_configuration コマンドは次の引数をサポートしています。

help
  Print this help text.

groups (list | status)
  list - lists all ProtoLog groups registered with ProtoLog service"
  status <group> - print the status of a ProtoLog group"

logcat (enable | disable) <group>"
  enable or disable ProtoLog to logcat

効果的な使用のためのヒント

ProtoLog はメッセージと渡された文字列引数の両方に文字列インターンを使用します。つまり、ProtoLog をより効果的に使用するには、メッセージで繰り返し値を変数に分離します。

たとえば、次のステートメントについて考えてみます。

Protolog.v(MY_GROUP, "%s", "The argument value is " + argument);

コンパイル時に最適化すると、次のように変換されます。

ProtologImpl.v(MY_GROUP, 0x123, "The argument value is " + argument);

引数 A,B,C が含まれるコードで ProtoLog を使用すると次のようになります。

Protolog.v(MY_GROUP, "%s", "The argument value is A");
Protolog.v(MY_GROUP, "%s", "The argument value is B");
Protolog.v(MY_GROUP, "%s", "The argument value is C");
Protolog.v(MY_GROUP, "%s", "The argument value is A");

メモリには次のメッセージが保存されます。

Dict:
  0x123: "%s"
  0x111: "The argument value is A"
  0x222: "The argument value is B"
  0x333: "The argument value is C"

Message1 (Hash: 0x123, Arg1: 0x111)
Message2 (Hash: 0x123, Arg2: 0x222)
Message3 (Hash: 0x123, Arg3: 0x333)
Message4 (Hash: 0x123, Arg1: 0x111)

代わりに ProtoLog ステートメントを次のように記述します。

Protolog.v(MY_GROUP, "The argument value is %s", argument);

メモリ内バッファは次のようになります。

Dict:
  0x123: "The argument value is %s" (24 b)
  0x111: "A" (1 b)
  0x222: "B" (1 b)
  0x333: "C" (1 b)

Message1 (Hash: 0x123, Arg1: 0x111)
Message2 (Hash: 0x123, Arg2: 0x222)
Message3 (Hash: 0x123, Arg3: 0x333)
Message4 (Hash: 0x123, Arg1: 0x111)

このシーケンスではメモリ使用量を 35% 削減できます。

Winscope のビューア

Winscope の [ProtoLog Viewer] タブでは、ProtoLog トレースが表形式でまとめられています。こちらではトレースをログレベル、タグ、ソースファイル(ProtoLog ステートメントが存在する場所)、メッセージ コンテンツでフィルタできます。すべての列にフィルタを適用できます。最初の列のタイムスタンプをクリックすると、タイムラインがメッセージのタイムスタンプに移動します。また、[Go to Current Time] をクリックすると、ProtoLog テーブルがタイムラインで選択したタイムスタンプに戻ります。

ProtoLog Viewer

図 1. ProtoLog Viewer