14.3.1. Registro de eventos

Un producto entregado no puede comunicarse con print(). print() escribe en la salida estándar USB, que solo existe cuando la cámara está en el banco de un desarrollador con un terminal abierto. Sobre el terreno nadie lo lee; cada línea cae al vacío. La biblioteca logging es el reemplazo: un filtro de nivel, un destino elegido por la aplicación y un formato que indica qué ocurrió y cuándo.

El módulo logging de la cámara es una adaptación reducida del de CPython: el mismo modelo mental, una superficie menor y unas pocas diferencias que importan para la configuración de producción.

14.3.1.1. El modelo mental

El registro de eventos se construye a partir de cuatro piezas. Cada pieza tiene una sola función; esa separación es lo que permite que un único registrador se reparta entre varios destinos, cada uno con su propio formato y nivel:

• Un Logger es a lo que llama la aplicación. El código escribe log.info("frame %d", n); el registrador es el objeto sobre el que aterriza esa llamada. Los registradores se buscan por nombre con logging.getLogger().

• Un Handler decide dónde va un registro. Un StreamHandler escribe en un flujo (sys.stderr de forma predeterminada); un FileHandler añade contenido a un archivo en disco. Un registrador puede tener cualquier número de manejadores.

  Nota

  En la cámara, sys.stdout y sys.stderr están conectados a la misma tubería USB CDC: las escrituras en cualquiera de los dos aparecen en el mismo terminal que un desarrollador tiene abierto sobre USB. Un manejador que escribe en sys.stderr es, en la práctica, un manejador que escribe en el mismo lugar donde escribe print(). La abstracción del manejador sigue dándote filtrado y formato por destino; lo que no te da es un canal físicamente independiente.

• Un Formatter decide cómo se representa un registro como texto. Toma un registro y devuelve la línea que se escribe. Una cadena de formato por formateador; un formateador por manejador.

• Un filtro de nivel se sitúa en cada registrador y en cada manejador. Los registros llevan un nivel (DEBUG / INFO / WARNING / ERROR / CRITICAL). Solo pasan los registros que estén en el nivel del filtro o por encima de él.

Esa separación importa porque una configuración de producción típica tiene más de un destino: un archivo en la tarjeta SD que conserva todo, hasta DEBUG, para el análisis posterior, y un flujo a USB que solo muestra WARNING y peores, de modo que un desarrollador conectado a la cámara vea lo destacado sin ahogarse en detalles. El mismo código, dos destinos, dos filtros.

14.3.1.2. Los niveles y qué significa cada uno

Los cinco niveles forman una escala ordenada. Los registros llevan un nivel para que el filtro de cada manejador pueda descartar los que no le interesan.

• DEBUG – trazado, contadores por fotograma, volcados de estado interno. El nivel más bajo; el volumen es alto.

• INFO – eventos operativos normales. Wi-Fi conectado, un modelo cargado, el watchdog iniciado, un nuevo archivo de registro rotado.

• WARNING – algo inesperado pero que la aplicación gestionó. Un fotograma descartado, una petición de red reintentada.

• ERROR – una operación falló y la aplicación no pudo completarla. Un archivo de modelo ausente, una escritura en la tarjeta SD rechazada.

• CRITICAL – la aplicación no puede continuar en absoluto. Sin memoria, falta un montaje obligatorio.

Un valor predeterminado importante que recordar: el módulo logging de la cámara arranca todos los registradores en WARNING. Los registros en DEBUG e INFO se descartan silenciosamente a menos que se llame a Logger.setLevel(), normalmente como parte de la llamada a basicConfig() de más abajo. Un primer síntoma habitual de una configuración de registro que «no funciona» es que la aplicación emitió en INFO y el filtro predeterminado se comió el registro.

Nota

El nivel es el único filtro que ofrece el logging de la cámara. No hay objetos Filter para reglas por registro más ricas; si el nivel de un registro pasa, se emite.

14.3.1.3. basicConfig: el inicio rápido

logging.basicConfig() configura el registrador raíz en una sola llamada. Dos formas aparecen con más frecuencia:

Una configuración de desarrollo, todo a stderr de USB en INFO:

import logging

logging.basicConfig(level=logging.INFO)

Una configuración de producción, todo a un archivo en la tarjeta SD con un formato con marca de tiempo:

import logging

logging.basicConfig(
    filename='/sdcard/logs/app.log',
    level=logging.INFO,
    format='%(asctime)s %(levelname)s %(name)s: %(message)s',
)

Pasa filename= para un FileHandler o stream= para un StreamHandler; los dos son mutuamente excluyentes en basicConfig().

La cadena de formato es una plantilla de estilo %(field)s. Los campos que admite el formateador de la cámara:

• %(asctime)s – marca de tiempo formateada a partir de time.localtime(). El formato predeterminado es %Y-%m-%d %H:%M:%S; pasa datefmt= para anularlo.

• %(levelname)s – DEBUG / INFO / WARNING / ERROR / CRITICAL.

• %(name)s – el nombre del registrador (consulta la siguiente sección).

• %(message)s – el mensaje formateado del registro.

• %(msecs)d – la fracción de milisegundos de la marca de tiempo del registro.

El formato predeterminado, si no se da ninguno, es %(levelname)s:%(name)s:%(message)s, que está bien para la configuración de desarrollo e inadecuado para un registro de campo, donde la marca de tiempo es lo que hace útil el archivo semanas después.

basicConfig() no hace nada en las llamadas posteriores a menos que se pase force=True. Configúralo una vez al inicio; no vuelvas a llamarlo para «cambiar de destino» a mitad de la ejecución.

Nota

El logging de la cámara no tiene dictConfig() ni fileConfig(). La configuración siempre es programática: la convención es un único ayudante setup_logging() llamado una vez desde main.py.

14.3.1.4. Registradores con nombre por módulo

El código de la aplicación no debería llamar a los atajos a nivel de módulo (logging.info(), logging.warning(), etc.). Todos esos canalizan a través del registrador raíz, y los registros resultantes llevan el nombre root, inútil para indicar de dónde vino el registro.

La convención es un registrador por módulo, con el nombre del módulo:

# in app/detector.py
import logging

log = logging.getLogger(__name__)

def detect(frame):
    log.info("detect on %dx%d frame", frame.width(), frame.height())

Cada registro lleva entonces app.detector en %(name)s y la línea de registro dice quién lo emitió.

El logging de la cámara difiere del de CPython en un aspecto importante: el espacio de nombres de registradores es plano. getLogger('app') y getLogger('app.detector') son registradores independientes sin relación padre/hijo: establecer un nivel en app no se propaga a app.detector. El mecanismo que sí funciona: un registrador con nombre sin manejadores propios toma prestados los manejadores y el nivel del registrador raíz. Así es como una única llamada a basicConfig() sobre la raíz configura cada llamada a getLogger() de cualquier otra parte de la aplicación.

14.3.1.5. Formato perezoso de argumentos con %

Escribe:

log.info("processed %d frames in %d ms", count, dt)

No:

log.info(f"processed {count} frames in {dt} ms")

La forma con argumentos % permite que el registrador interpole los argumentos después de que el filtro de nivel haya decidido si emitir el registro. Una llamada a DEBUG descartada dentro de un bucle intensivo no paga nada por su cadena de formato. Una f-string se evalúa primero, cada vez, antes incluso de que la llamada llegue al registrador.

La palabra clave extra= de CPython para campos estructurados no está soportada en la cámara; en su lugar, pasa los valores como argumentos del mensaje.

14.3.1.6. Registro de excepciones

Dentro de un bloque except, Logger.exception() registra el mensaje en nivel ERROR y además añade al registro el rastreo de la excepción actual:

try:
    frame = csi0.snapshot()
    process(frame)
except Exception:
    log.exception("frame loop iteration failed")

El rastreo se captura mediante sys.print_exception(), que es lo que da a un registro de excepción su bloque multilínea Traceback (most recent call last):. Esta es la herramienta adecuada para el manejo de excepciones de nivel superior: capturar, registrar y continuar.

14.3.1.7. Varios manejadores

La división de producción mencionada al principio – todo a un archivo en DEBUG, lo destacado a stderr en WARNING – son dos manejadores conectados al mismo registrador, cada uno con su propio nivel y formateador:

import logging

fmt = '%(asctime)s %(levelname)s %(name)s: %(message)s'

file_handler = logging.FileHandler('/sdcard/logs/app.log')
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(logging.Formatter(fmt))

stream_handler = logging.StreamHandler()
stream_handler.setLevel(logging.WARNING)
stream_handler.setFormatter(logging.Formatter(fmt))

root = logging.getLogger()
root.setLevel(logging.DEBUG)          # admit everything to the filters
root.addHandler(file_handler)
root.addHandler(stream_handler)

El nivel del registrador raíz es el primer filtro que encuentra cada registro. Ajústalo al nivel más bajo que cualquier manejador quiera ver – DEBUG aquí – para que ningún manejador quede privado por el propio registrador. Los niveles por manejador deciden entonces qué registros se emiten realmente a cada destino.

14.3.1.8. Rotación de archivos de registro

El logging de la cámara no tiene RotatingFileHandler ni TimedRotatingFileHandler. La rotación es tarea de la aplicación.

El patrón consiste en mantener el FileHandler actual en un lugar conocido, cambiarlo por uno nuevo cuando se cumpla el criterio de rotación, y dejar que una ruta con fecha proporcione el límite natural del archivo. Para una rotación por hora en /sdcard/logs/<year>/<month>/<day>/<hour>.log:

import logging
import time

_LOG_FMT = '%(asctime)s %(levelname)s %(name)s: %(message)s'
_current_path = None
_current_handler = None

def _hourly_path(now):
    return '/sdcard/logs/{:04d}/{:02d}/{:02d}/{:02d}.log'.format(
        now[0], now[1], now[2], now[3])

def rotate_if_needed():
    global _current_path, _current_handler

    path = _hourly_path(time.localtime())
    if path == _current_path:
        return

    root = logging.getLogger()
    if _current_handler is not None:
        root.removeHandler(_current_handler)
        _current_handler.close()

    _current_handler = logging.FileHandler(path)
    _current_handler.setFormatter(logging.Formatter(_LOG_FMT))
    root.addHandler(_current_handler)
    _current_path = path

Llama a rotate_if_needed() una vez por iteración del bucle principal; la comprobación de la ruta es barata y el cambio solo ocurre en el límite de la hora. El árbol de directorios debe existir antes de que FileHandler pueda abrir el archivo.

14.3.1.9. Vaciado en despliegues sensibles a la energía

Las escrituras de FileHandler pasan por el almacenamiento en búfer de Python del objeto de archivo subyacente. Una pérdida de energía entre una escritura y un vaciado pierde los registros finales. Para despliegues alimentados por batería o de tirar del enchufe, llama a flush() en el flujo del manejador después de los registros críticos, o mediante un temporizador.

Un pequeño ayudante que vacía cada manejador conectado al registrador raíz:

import logging

def flush_handlers():
    for handler in logging.getLogger().handlers:
        if hasattr(handler, 'stream'):
            handler.stream.flush()

Llama a flush_handlers() justo después de un registro que la aplicación no puede permitirse perder:

log.critical("memory low: restarting")
flush_handlers()

Como medida de seguridad en segundo plano, llámalo desde el bucle principal con la cadencia que equilibre la frescura del registro frente al desgaste de la memoria flash; una vez por segundo suele ser más que suficiente. Logger.critical() no desencadena un vaciado por sí mismo.

14.3.1.10. Diagnósticos en el arranque

Un registro de campo sin contexto es casi inútil. Los primeros registros de cada arranque en frío deberían identificar qué cámara es, qué compilación se está ejecutando y cómo llegó la cámara a este arranque. Tres fuentes en el dispositivo cubren todo eso entre ellas:

• omv – la versión del firmware de OpenMV.

• os.uname() – la versión de MicroPython, el nombre de la placa más el MCU, y la etiqueta de git y la fecha de compilación del código fuente a partir del cual se compiló el firmware.

• machine – el identificador único de silicio del MCU y la causa de reinicio que desencadenó este arranque.

• os.listdir() contra cada punto de montaje – los sistemas de archivos que realmente se levantaron.

Un ayudante que vuelca cada uno de esos datos en los primeros registros del log:

import binascii
import logging
import machine
import omv
import os

log = logging.getLogger(__name__)

_RESET_NAMES = {
    machine.PWRON_RESET: "power-on",
    machine.HARD_RESET: "hard reset",
    machine.WDT_RESET: "watchdog timeout",
    machine.DEEPSLEEP_RESET: "wake from deep sleep",
    machine.SOFT_RESET: "soft reset",
}

def log_boot_diagnostics():
    uname = os.uname()

    log.info("machine: %s", uname.machine)
    log.info("unique id: %s",
             binascii.hexlify(machine.unique_id()).decode())
    log.info("firmware: openmv %s, micropython %s",
             omv.version_string(), uname.release)
    log.info("build: %s", uname.version)
    log.info("reset cause: %s",
             _RESET_NAMES.get(machine.reset_cause(), "unknown"))

    for mount in ('/flash', '/sdcard', '/rom'):
        try:
            os.listdir(mount)
            log.info("mount %s: ok", mount)
        except OSError as e:
            log.warning("mount %s: %s", mount, e)

Un registro típico se abre con algo como:

INFO machine: OPENMV4 with STM32H743
INFO unique id: 002C00543235501020373835
INFO firmware: openmv 5.0.0, micropython 1.28.0
INFO build: v1.28.0-101-gabc1234 on 2026-06-09
INFO reset cause: watchdog timeout
INFO mount /flash: ok
INFO mount /sdcard: ok
INFO mount /rom: ok

Ocho líneas dentro de cada archivo de registro, el operador conoce la unidad física, el linaje del firmware, por qué arrancó la cámara y qué almacenamiento se levantó. unique id es el número de serie de silicio programado de fábrica en el MCU; es el mismo entre reflasheos y entre cambios de tarjeta SD. build es la etiqueta de git y la fecha del árbol de firmware a partir del cual se compiló la imagen; el único campo que dice «este es exactamente el binario que se entregó a esta unidad en este momento concreto».

14.3.1.11. Juntándolo todo

Una configuración completa de registro de producción, agrupada en un ayudante que main.py llama una vez al inicio:

import logging

_LOG_FMT = '%(asctime)s %(levelname)s %(name)s: %(message)s'

def setup_logging(log_path):
    fh = logging.FileHandler(log_path)
    fh.setLevel(logging.DEBUG)
    fh.setFormatter(logging.Formatter(_LOG_FMT))

    sh = logging.StreamHandler()
    sh.setLevel(logging.WARNING)
    sh.setFormatter(logging.Formatter(_LOG_FMT))

    root = logging.getLogger()
    root.setLevel(logging.DEBUG)
    root.addHandler(fh)
    root.addHandler(sh)

Luego, al principio de main.py:

from app.logging_setup import setup_logging, log_boot_diagnostics

setup_logging('/sdcard/logs/app.log')
log_boot_diagnostics()

Cualquier otro módulo de la aplicación simplemente hace:

import logging

log = logging.getLogger(__name__)

y obtiene la salida configurada gratis: archivo con el detalle completo, flujo con las advertencias, registros con nombre, formateador con marca de tiempo y un arranque documentado en cada encendido en frío.