El logging es el sistema que registra mensajes de diagnóstico con nivel, origen y marca de tiempo y los entrega a uno o varios backends.
En un microcontrolador, una consola serie sigue siendo una de las ventanas más útiles para observar qué ocurre dentro del firmware.
La depuración por consola (el famoso “printf debugging”) sigue siendo la técnica más utilizada en el mundo embebido. Pero, cuidado. En un sistema de Tiempo Real (RTOS) como Zephyr, usar un printf indiscriminadamente puede ser peligroso. Puede bloquear interrupciones, romper la temporización de un sensor o hacer que una comunicación Bluetooth falle.
Vamos a comparar la salida directa con printk y el subsistema de logging, que permite filtrar y diferir mensajes.
printk vs logging: comparativa
| Característica | printk | Logging (LOG_INF) |
|---|---|---|
| Ejecución | Inmediata o redirigida | Inmediata o diferida |
| Rendimiento | Impacto alto | Impacto mínimo |
| Uso en Interrupciones | Evitar mensajes largos | Admitido, con coste y buffer limitados |
| Formato | Manual (%d, \n) | Automático (Timestamp, color, nivel) |
| Filtrado | No (todo sale) | Sí (por módulo y nivel) |
El método clásico: printk
Zephyr ofrece una función llamada printk. Es el equivalente directo al printf de C estándar o al Serial.print de Arduino.
Su funcionamiento es sencillo: formatea una cadena de texto y la envía byte a byte por la UART configurada como consola.
#include <zephyr/sys/printk.h>
int main(void) {
int contador = 10;
printk("Hola desde Zephyr! Contador: %d\n", contador);
return 0;
}¿Cuándo usarlo?
- En la fase de arranque temprana (boot).
- Para mensajes críticos que deben salir sí o sí, aunque el sistema se esté cayendo a pedazos.
- En ejemplos muy sencillos (“Hola Mundo”).
El problema de printk
Sin redirección al subsistema de logging, printk entrega la salida de forma inmediata y el coste depende del backend de consola. Si CONFIG_LOG_PRINTK está activo, sus mensajes se redirigen al logger y, en modo diferido, también pueden quedar pendientes.
A 115200 baudios, enviar una frase larga puede tardar varios milisegundos. En tiempo de CPU, eso es una eternidad. Si haces esto dentro de una Interrupción (ISR) o un hilo de alta prioridad, puedes matar el rendimiento de tu sistema.
El método profesional: subsistema de logging
El subsistema de logging separa la generación del mensaje de su salida final cuando trabaja en modo diferido.
En lugar de escupir los datos directamente al cable, el sistema de Logging funciona así:
- Tu código llama a
LOG_INF("Mensaje"). - El mensaje se copia rapidísimo a un buffer en memoria RAM.
- Tu código sigue ejecutándose inmediatamente (apenas pierde ciclos).
- Un hilo de proceso extrae los mensajes y los entrega al backend configurado.
Cómo implementar logging en tu código
Para usar esto, necesitamos tres pasos en nuestro archivo .c:
Registrar el módulo: Le damos un nombre a nuestro archivo (ej. “mi_motor”).
Incluir la cabecera: <zephyr/logging/log.h>.
Usar las macros: LOG_INF, LOG_ERR, etc.
#include <zephyr/kernel.h>
#include <zephyr/logging/log.h>
/* 1. Registramos el módulo. El nombre aparecerá en la consola */
LOG_MODULE_REGISTER(mi_app, LOG_LEVEL_INF);
int main(void) {
int sensor_val = 25;
/* Esto es informativo */
LOG_INF("El sistema ha arrancado correctamente");
if (sensor_val > 20) {
/* Esto es una advertencia */
LOG_WRN("Temperatura alta: %d", sensor_val);
}
/* Esto es depuración (no saldrá si el nivel es INF) */
LOG_DBG("Valor raw del sensor: 0x1A");
return 0;
}La salida en la consola se verá así, formateada automáticamente con colores y marcas de tiempo:
[00:00:00.100,000] <inf> mi_app: El sistema ha arrancado correctamente
[00:00:00.105,000] <wrn> mi_app: Temperatura alta: 25Fíjate que el mensaje LOG_DBG no ha salido. Esto es porque al registrar el módulo pusimos LOG_LEVEL_INF. El sistema descarta automáticamente cualquier mensaje de nivel inferior para ahorrar tiempo y espacio.
Configuración en prj.conf
Para que todo esto funcione, tienes que activar el subsistema en tu prj.conf:
# Activar consola y logging
CONFIG_CONSOLE=y
CONFIG_UART_CONSOLE=y
CONFIG_LOG=y
# Opcional: Modo diferido (Deferred) es el default y el recomendado
CONFIG_LOG_MODE_DEFERRED=y
# Opcional: aumentar el buffer si se pierden mensajes
CONFIG_LOG_BUFFER_SIZE=2048Filtrado por módulo
En un proyecto con 10 archivos, el driver del motor, el del Wi-Fi, el del sensor… todos pueden estar escupiendo logs a la vez. La consola es un caos.
Con printk tendrías que ir comentando líneas de código. Con el Logging de Zephyr, puedes silenciar módulos desde el archivo de configuración sin tocar el código C.
El nivel global se puede ajustar en prj.conf:
# Nivel global por defecto: solo errores
CONFIG_LOG_DEFAULT_LEVEL=1Los subsistemas que exponen un símbolo propio permiten configurar CONFIG_<MODULO>_LOG_LEVEL. Para un módulo de aplicación, también puedes fijar el nivel en LOG_MODULE_REGISTER, utilizar el filtrado en tiempo de ejecución o los comandos de la shell de logging.
Usar RTT (Real Time Transfer)
Si estás usando un depurador profesional (como un J-Link de Segger), puedes usar RTT en lugar de UART.
La UART es lenta. RTT usa la interfaz de depuración para escribir directamente en la RAM del microcontrolador desde el PC. Es extremadamente rápido (microsegundos).
Para cambiar de UART a RTT, solo cambias la configuración, ¡el código LOG_INF sigue siendo el mismo!
CONFIG_USE_SEGGER_RTT=y
CONFIG_LOG_BACKEND_RTT=y
CONFIG_LOG_BACKEND_UART=nEl modo diferido reduce la espera en el punto donde se genera el mensaje, pero no vuelve gratuito el logging: consume RAM, CPU y ancho de banda, y puede perder mensajes si el buffer se llena.
