Protolog

El objetivo del sistema de registro de Android es la accesibilidad universal y la facilidad de uso, siempre que se suponga que todos los datos de registro se pueden representar como una secuencia de caracteres. Esta suposición se alinea con la mayoría de los casos de uso, en particular cuando la legibilidad de los registros es fundamental sin herramientas especializadas. Sin embargo, en entornos que requieren un alto rendimiento de registro y tamaños de registro restringidos, es posible que el registro basado en texto no sea la opción óptima. Un caso de este tipo es WindowManager, que requiere un sistema de registro sólido capaz de controlar los registros de transición de ventanas en tiempo real con un impacto mínimo en el sistema.

ProtoLog es la alternativa para abordar las necesidades de registro de WindowManager y servicios similares. Los principales beneficios de ProtoLog sobre logcat son los siguientes:

  • La cantidad de recursos que se usan para el registro es menor.
  • Desde el punto de vista de un desarrollador, es lo mismo que usar el framework de registro predeterminado de Android.
  • Admite que las instrucciones de registro se habiliten o inhabiliten durante el tiempo de ejecución.
  • Aún se puede acceder a Logcat si es necesario.

Para optimizar el uso de memoria, ProtoLog emplea un mecanismo de internamiento de cadenas que implica calcular y guardar un hash compilado del mensaje. Para mejorar el rendimiento, ProtoLog realiza la incorporación de cadenas durante la compilación (para los servicios del sistema) y solo registra el identificador de mensajes y los argumentos durante el tiempo de ejecución. Además, cuando se genera un registro de ProtoLog o se obtiene un informe de errores, ProtoLog incorpora automáticamente el diccionario de mensajes creado en el momento de la compilación, lo que permite la decodificación de mensajes desde cualquier compilación.

Con ProtoLog, el mensaje se almacena en un formato binario (proto) dentro de un registro de Perfetto. La decodificación de mensajes se realiza dentro de trace_processor de Perfetto. El proceso consiste en decodificar los mensajes de proto binarios, traducir los identificadores de mensajes en cadenas con el diccionario de mensajes incorporado y dar formato a la cadena con argumentos dinámicos.

ProtoLog admite los mismos niveles de registro que android.utils.Log, a saber: d, v, i, w, e y wtf.

ProtoLog del cliente

En un principio, ProtoLog estaba destinado únicamente al servidor de WindowManager, que operaba en un solo proceso y componente. Posteriormente, se expandió para abarcar el código de shell de WindowManager en el proceso de la IU del sistema, pero el uso de ProtoLog requirió un código de configuración de plantilla intrincado. Además, el registro de Proto se limitaba al servidor del sistema y a los procesos de la IU del sistema, lo que dificultaba su incorporación a otros procesos y requería una configuración de búfer de memoria independiente para cada uno. Sin embargo, ProtoLog ahora está disponible para el código del cliente, lo que elimina la necesidad de código de plantilla adicional.

A diferencia del código de los servicios del sistema, el código del cliente suele omitir la internación de cadenas en el tiempo de compilación. En cambio, la incorporación de cadenas se produce de forma dinámica en un subproceso en segundo plano. Como resultado, si bien ProtoLog del cliente proporciona ventajas de uso de memoria comparables a ProtoLog en los servicios del sistema, genera una sobrecarga de rendimiento ligeramente más alta y carece de la ventaja de reducción de memoria de la memoria fijada de su contraparte del servidor.

Grupos de ProtoLog

Los mensajes de ProtoLog se organizan en grupos llamados ProtoLogGroups, de manera similar a como TAG organiza los mensajes de Logcat. Estos ProtoLogGroups sirven como clústeres de mensajes que se pueden habilitar o inhabilitar de forma colectiva durante el tiempo de ejecución. Además, controlan si los mensajes se deben quitar durante la compilación y dónde se deben registrar (proto, logcat o ambos). Cada ProtoLogGroup incluye las siguientes propiedades:

  • enabled: Cuando se establece en false, los mensajes de este grupo se excluyen durante la compilación y no están disponibles durante el tiempo de ejecución.
  • logToProto: Define si este grupo registra con formato binario.
  • logToLogcat: Define si este grupo se registra en Logcat.
  • tag: Es el nombre de la fuente del mensaje registrado.

Cada proceso que usa ProtoLog debe tener configurada una instancia de ProtoLogGroup.

Tipos de argumento compatibles

De forma interna, las cadenas de formato de ProtoLog usan android.text.TextUtils#formatSimple(String, Object...), por lo que su sintaxis es la misma.

ProtoLog admite los siguientes tipos de argumentos:

  • %b: Es un valor booleano.
  • %d, %x: Tipo de número entero (short, integer o long)
  • %f: Es el tipo de punto flotante (flotante o doble).
  • %s: Es una cadena.
  • %%: Es un carácter porcentual literal.

Se admiten los modificadores de ancho y precisión, como %04d y %10b, pero no argument_index ni flags.

Usa ProtoLog en un servicio nuevo

Para usar ProtoLog en un proceso nuevo, haz lo siguiente:

  1. Crea una definición de ProtoLogGroup para este servicio.

  2. Inicializa la definición antes de su primer uso (por ejemplo, en la creación del proceso):

    Protolog.init(ProtologGroup.values());

  3. Usa Protolog de la misma manera que android.util.Log:

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

Habilita la optimización del tiempo de compilación

Para habilitar ProtoLog en el tiempo de compilación en un proceso, debes cambiar sus reglas de compilación y, luego, invocar el objeto binario protologtool.

ProtoLogTool es un objeto binario de transformación de código que realiza la incorporación de cadenas y actualiza la invocación de ProtoLog. Este binario transforma cada llamada de registro ProtoLog como se muestra en este ejemplo:

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

en:

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

En este ejemplo, ProtoLog, ProtoLogImpl y ProtoLogGroup son las clases proporcionadas como argumentos (se pueden importar, importar de forma estática o de ruta de acceso completa, no se permiten importaciones de comodín) y x es el método de registro.

La transformación se realiza a nivel de la fuente. Se genera un hash a partir de la cadena de formato, el nivel de registro y el nombre del grupo de registros, y se inserta después del argumento ProtoLogGroup. El código generado real se intercala y se agregan varios caracteres de línea nuevos para preservar el número de línea en el archivo.

Ejemplo:

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"],
}

Opciones de línea de comandos

Una de las principales ventajas de ProtoLog es que puedes habilitarlo o inhabilitarlo durante el tiempo de ejecución. Por ejemplo, puedes tener un registro más detallado en una compilación, que está inhabilitado de forma predeterminada, y habilitarlo durante el desarrollo local para depurar un problema específico. Este patrón se usa, por ejemplo, en WindowManager con los grupos WM_DEBUG_WINDOW_TRANSITIONS y WM_DEBUG_WINDOW_TRANSITIONS_MIN que habilitan diferentes tipos de registro de transición, y el primero se habilita de forma predeterminada.

Puedes configurar ProtoLog con Perfetto cuando inicias un registro. También puedes configurar ProtoLog de forma local con la línea de comandos adb.

El comando adb shell cmd protolog_configuration admite los siguientes argumentos:

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

Sugerencias para un uso eficaz

ProtoLog usa la incorporación de cadenas para el mensaje y cualquier argumento de cadena que se pase. Esto significa que, para obtener más beneficios de ProtoLog, los mensajes deben aislar los valores repetidos en variables.

Por ejemplo, considera la siguiente declaración:

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

Cuando se optimiza en el tiempo de compilación, se traduce a lo siguiente:

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

Si se usa ProtoLog en el código con argumentos A,B,C, sucede lo siguiente:

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");

Como resultado, se muestran los siguientes mensajes en la memoria:

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)

En cambio, si la sentencia ProtoLog se escribió de la siguiente manera:

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

El búfer en la memoria terminaría de la siguiente manera:

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)

Esta secuencia genera un espacio en memoria un 35% más pequeño.

Visualizador de Winscope

La pestaña del visor de ProtoLog de Winscope muestra los seguimientos de ProtoLog organizados en un formato tabular. Puedes filtrar los seguimientos por nivel de registro, etiqueta, archivo de origen (donde está presente la sentencia ProtoLog) y contenido del mensaje. Todas las columnas se pueden filtrar. Si haces clic en la marca de tiempo de la primera columna, el cronograma se trasladará a la marca de tiempo del mensaje. Además, si haces clic en Ir a la hora actual, la tabla de ProtoLog se desplaza hasta la marca de tiempo seleccionada en el cronograma:

Visor de ProtoLog

Figura 1: Visor de ProtoLog