The Android logging system aims to achieve universal accessibility and ease of use, assuming all log data can be represented as a sequence of characters. This assumption aligns with most use cases, particularly when log readability is crucial without specialized tools. However, in environments demanding high logging performance and restricted log sizes, text-based logging is not optimal. One such scenario is WindowManager, which requires a robust logging system that handles real-time window transition logs with minimal system impact.
ProtoLog is the alternative to address the logging needs of WindowManager and similar services. ProtoLog offers the following benefits over logcat:
- Uses fewer resources for logging.
- From a developer's perspective, it works the same as the default Android logging framework.
- Lets you enable or disable log statements at runtime.
- Can also log to logcat.
To optimize memory usage, ProtoLog uses a string interning mechanism. This mechanism calculates and saves a compiled hash of the message. To improve performance, ProtoLog performs string interning during compilation for system services. It records only the message identifier and arguments at runtime. When you generate a ProtoLog trace or obtain a bug report, ProtoLog automatically incorporates the message dictionary created at compile time. This enables message decoding from any build.
ProtoLog stores messages in a binary format (proto) within a Perfetto trace.
Message decoding occurs within Perfetto's trace_processor
. The process decodes
the binary proto messages, translates message identifiers into strings using the
embedded message dictionary, and formats the string using dynamic arguments.
ProtoLog supports the same log levels as android.utils.Log
, which are d
,
v
, i
, w
, e
, and wtf
.
Client-side ProtoLog
Initially, ProtoLog was intended only for the server side of the WindowManager, operating within a single process and component. Later, it was expanded to encompass the WindowManager shell code in the System UI process. However, using ProtoLog required intricate boilerplate setup code. Additionally, Proto logging was restricted to system server and System UI processes. This made it difficult to incorporate into other processes and required a separate memory buffer setup for each. ProtoLog is now available for client-side code, eliminating the need for additional boilerplate code.
Unlike system services code, client-side code usually skips compile-time string interning. Instead, string interning occurs dynamically in a background thread. As a result, while client-side ProtoLog provides memory use advantages comparable to ProtoLog on system services, it incurs a slightly higher performance overhead and lacks the memory reduction advantage of pinned memory that its server-side counterpart offers.
ProtoLog groups
ProtoLog messages are organized into groups called ProtoLogGroups
, similar to
how Logcat messages are organized by TAG
. These ProtoLogGroups
serve as
message clusters that you can enable or disable at runtime. They also control
whether messages are stripped during compilation and where they are logged
(proto, logcat, or both). Each ProtoLogGroup
includes the following
properties:
enabled
: When set tofalse
, messages in this group are excluded during compilation and aren't available at runtime.logToProto
: Defines if this group logs with binary format.logToLogcat
: Defines if this group logs to logcat.tag
: Name of the source of the logged message.
Each process that uses ProtoLog must have a ProtoLogGroup
instance configured.
Supported argument types
ProtoLog internally formats strings using android.text.TextUtils#formatSimple(String, Object...)
,
so its syntax is the same.
ProtoLog supports the following argument types:
%b
- boolean%d
,%x
- integral type (short, integer, or long)%f
- floating point type (float or double)%s
- string%%
- a literal percent character
Width and precision modifiers, such as %04d
and %10b
, are supported.
However, argument_index
and flags
aren't supported.
Use ProtoLog in a new service
To use ProtoLog in a new service, follow these steps:
- Create a
ProtoLogGroup
definition for this service. Initialize the definition before its first use. For example, initialize it during process creation:
ProtoLog.init(ProtoLogGroup.values());
Use
ProtoLog
in the same way you useandroid.util.Log
:ProtoLog.v(WM_SHELL_STARTING_WINDOW, "create taskSnapshot surface for task: %d", taskId);
Enable compile-time optimization
To enable compile-time ProtoLog in a process, you must change its build rules
and invoke the protologtool
binary.
ProtoLogTool
is a code transformation binary that performs string interning
and updates ProtoLog invocation. This binary transforms every ProtoLog
logging
call as shown in this example:
ProtoLog.x(ProtoLogGroup.GROUP_NAME, "Format string %d %s", value1, value2);
into:
if (ProtoLogImpl.isEnabled(GROUP_NAME)) {
int protoLogParam0 = value1;
String protoLogParam1 = String.valueOf(value2);
ProtoLogImpl.x(ProtoLogGroup.GROUP_NAME, 1234560b0100, protoLogParam0, protoLogParam1);
}
In this example, ProtoLog
, ProtoLogImpl
, and ProtoLogGroup
are the
classes provided as arguments (can be imported, static imported, or full path,
wildcard imports aren't allowed) and, x
is the logging method.
The transformation is done at the source level. A hash is generated from the
format string, log level, and log group name, and inserted after the
ProtoLogGroup
argument. The real generated code is inlined and a number of new
line characters is added as to preserve line numbering in file.
Example:
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"],
}
Command line options
One of the main advantages of ProtoLog is that you can enable or disable it at
runtime. For example, you can have more verbose logging in a build, disabled by
default, and enabled it during local development, for debugging a specific
issue. This pattern is used, for example, in WindowManager with the groups
WM_DEBUG_WINDOW_TRANSITIONS
and WM_DEBUG_WINDOW_TRANSITIONS_MIN
enabling
different types of transition logging, with the former being enabled by default.
You can configure ProtoLog using Perfetto, when starting a trace. You can also
configure ProtoLog locally using the adb
command line.
The command adb shell cmd protolog_configuration
supports the following
arguments:
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
Tips for effective usage
ProtoLog uses string interning for both the message and any string arguments passed. This means that, to gain more benefit from ProtoLog, the messages should isolate repeated values into variables.
For example, consider the following statement:
Protolog.v(MY_GROUP, "%s", "The argument value is " + argument);
When optimized at compile time, it translates to this:
ProtologImpl.v(MY_GROUP, 0x123, "The argument value is " + argument);
If ProtoLog is used in the code with arguments A,B,C
:
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");
It results in the following messages in memory:
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)
If, instead, the ProtoLog statement was written as:
Protolog.v(MY_GROUP, "The argument value is %s", argument);
The in memory buffer would end up as:
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)
This sequence results in a memory footprint that is 35% smaller.
Winscope viewer
Winscope's ProtoLog viewer tab shows ProtoLog traces organized in a tabular format. You can filter traces by log level, tag, source file (where the ProtoLog statement is present), and message content. All columns are filterable. Clicking the timestamp in the first column transports the timeline to the message timestamp. Additionally, clicking Go to Current Time scrolls the ProtoLog table back to the timestamp selected in the timeline:
Figure 1. ProtoLog viewer