14.3.1. Naplózás

Egy leszállított termék nem tud hazatelefonálni a print() segítségével. A print() az USB stdout-ra ír, ami csak akkor létezik, ha a kamera egy fejlesztő munkapadján van, nyitott terminállal. A terepen semmi sem olvassa; minden sor a padlóra esik. A logging könyvtár ennek a helyettesítője – egy szintszűrő, egy az alkalmazás által választott célhely, és egy formátum, amely megmondja, mi és mikor történt.

A kamerán lévő logging modul a CPython megfelelőjének lecsupaszított átirata – ugyanaz a gondolati modell, kisebb felület, néhány eltéréssel, amelyek a éles üzemű beállításnál számítanak.

14.3.1.1. A gondolati modell

A naplózás négy darabból épül fel. Mindegyik darabnak egyetlen feladata van; ez a szétválasztás teszi lehetővé, hogy egyetlen logger több célhelyre elágazzon, mindegyik a saját formátumával és szintjével:

  • A Logger az, amit az alkalmazás meghív. A kód azt mondja: log.info("frame %d", n); a logger az az objektum, amelyre ez a hívás érkezik. A loggereket név alapján keressük meg a logging.getLogger() segítségével.

  • A Handler dönti el, hogy hová kerül egy rekord. Egy StreamHandler egy adatfolyamra ír (alapértelmezetten a sys.stderr-re); egy FileHandler egy lemezen lévő fájlhoz fűz hozzá. Egy loggernek tetszőleges számú handlere lehet.

    Megjegyzés

    A kamerán a sys.stdout és a sys.stderr ugyanahhoz az USB CDC csatornához van bekötve – a bármelyikre történő írás ugyanazon a terminálon jelenik meg, amelyet a fejlesztő USB-n keresztül nyitva tart. Egy sys.stderr-re író handler a gyakorlatban olyan handler, amely ugyanoda ír, ahová a print(). A handler absztrakció továbbra is biztosít célhelyenkénti szűrést és formázást; csak épp nem ad fizikailag külön csatornát.

  • A Formatter dönti el, hogy hogyan jelenik meg egy rekord szövegként. Fog egy rekordot, és visszaadja a kiírandó sort. Egy formátumsztring formatterenként; egy formatter handlerenként.

  • A szintszűrő minden loggeren és minden handleren ott ül. A rekordok egy szintet hordoznak (DEBUG / INFO / WARNING / ERROR / CRITICAL). Csak a szűrő szintjén vagy afölött lévő rekordok jutnak át.

Ez a szétválasztás azért számít, mert egy tipikus éles üzemű beállításnak egynél több célhelye van: egy fájl az SD-kártyán, amely mindent megtart egészen a DEBUG szintig az utólagos elemzéshez, és egy adatfolyam az USB felé, amely csak a WARNING szintet és a rosszabbat hozza felszínre, hogy a kamerához csatlakozott fejlesztő lássa a lényeget anélkül, hogy belefulladna a részletekbe. Ugyanaz a kód, két célhely, két szűrő.

14.3.1.2. Szintek és hogy mit jelent mindegyik

Az öt szint egy rendezett skála. A rekordok egy szintet hordoznak, hogy az egyes handlereken lévő szűrő eldobhassa azokat, amelyek nem érdeklik.

  • DEBUG – nyomkövetés, képkockánkénti számlálók, belső állapot kiírások. A legalacsonyabb szint; nagy mennyiségű.

  • INFO – normál működési események. A Wi-Fi csatlakozott, egy modell betöltődött, a watchdog elindult, egy új naplófájl került forgatásra.

  • WARNING – valami váratlan, de az alkalmazás kezelte. Egy eldobott képkocka, egy újrapróbált hálózati kérés.

  • ERROR – egy művelet meghiúsult, és az alkalmazás nem tudta befejezni. Egy hiányzó modellfájl, egy elutasított SD-kártya írás.

  • CRITICAL – az alkalmazás egyáltalán nem tud folytatódni. Elfogyott a memória, hiányzik egy kötelező csatlakoztatás.

Egy fontos alapértelmezés, amelyet érdemes megjegyezni: a kamera logging modulja minden loggert WARNING szinten indít. A DEBUG és INFO szintű rekordok csendben eldobódnak, hacsak nem hívják meg a Logger.setLevel()-t – általában az alábbi basicConfig() hívás részeként. Egy „nem működő” naplózási beállítás gyakori első tünete, hogy az alkalmazás INFO szinten bocsátott ki, és az alapértelmezett szűrő megette a rekordot.

Megjegyzés

A szint az egyetlen szűrő, amelyet a kamera logging modulja kínál. Nincsenek Filter objektumok a részletesebb rekordonkénti szabályokhoz; ha egy rekord szintje átjut, akkor kibocsátódik.

14.3.1.3. basicConfig: a gyorsindítás

A logging.basicConfig() egyetlen hívással konfigurálja a gyökér loggert. Két alak fordul elő leggyakrabban:

Egy fejlesztői beállítás, minden az USB stderr-re INFO szinten:

import logging

logging.basicConfig(level=logging.INFO)

Egy éles üzemű beállítás, minden egy SD-kártyán lévő fájlba, időbélyeggel ellátott formátummal:

import logging

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

Adj át vagy filename=-t egy FileHandler-hez, vagy stream=-et egy StreamHandler-hez; a kettő kölcsönösen kizárja egymást a basicConfig()-ban.

A formátumsztring egy %(field)s-stílusú sablon. A kamera formattere a következő mezőket támogatja:

  • %(asctime)s – a time.localtime()-ból formázott időbélyeg. Az alapértelmezett formátum %Y-%m-%d %H:%M:%S; a felülírásához add át a datefmt=-et.

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

  • %(name)s – a logger neve (lásd a következő szakaszt).

  • %(message)s – a rekord formázott üzenete.

  • %(msecs)d – a rekord időbélyegének ezredmásodperc-törtrésze.

Az alapértelmezett formátum, ha nincs megadva, a %(levelname)s:%(name)s:%(message)s – ami a fejlesztői beállításhoz megfelelő, de elégtelen egy terepi naplóhoz, ahol épp az időbélyeg teszi a fájlt hetekkel később is hasznossá.

A basicConfig() a további hívásoknál üresjárat, hacsak nem adják át a force=True-t. Konfiguráld egyszer az indításkor; ne hívd meg újra, hogy futás közben „célhelyet válts”.

Megjegyzés

A kamera logging moduljában nincs dictConfig() vagy fileConfig(). A konfiguráció mindig programozott – egyetlen setup_logging() segédfüggvény, amelyet egyszer hívnak meg a main.py-ból, ez a bevett gyakorlat.

14.3.1.4. Modulonként elnevezett loggerek

Az alkalmazás kódjának nem szabad a modulszintű rövidítéseket hívnia (logging.info(), logging.warning() és így tovább). Ezek mind a gyökér loggeren keresztül haladnak, és az ebből származó naplórekordok a root nevet hordozzák – haszontalan annak megállapítására, hogy honnan jött a rekord.

A bevett gyakorlat modulonként egy logger, a modulról elnevezve:

# in app/detector.py
import logging

log = logging.getLogger(__name__)

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

Ekkor minden rekord az app.detector-t hordozza a %(name)s-ben, és a naplósor megmondja, ki bocsátotta ki.

A kamera logging modulja egy fontos szempontból eltér a CPythontól: a logger névtér lapos. A getLogger('app') és a getLogger('app.detector') független loggerek, szülő/gyermek kapcsolat nélkül – egy szint beállítása az app-on nem terjed át az app.detector-ra. A mechanizmus, ami működik: egy saját handlerekkel nem rendelkező, elnevezett logger kölcsönveszi a gyökér logger handlereit és szintjét. Így állít be egyetlen, a gyökéren meghívott basicConfig() hívás minden más, az alkalmazás bármely pontján lévő getLogger() hívást.

14.3.1.5. Lusta %-argumentumos formázás

Írd ezt:

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

Ne ezt:

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

A %-argumentumos forma lehetővé teszi, hogy a logger az argumentumokat azután helyettesítse be, hogy a szintszűrő eldöntötte, kibocsátja-e a rekordot. Egy kiszűrt DEBUG hívás egy gyakran futó hurokban semmibe sem kerül a formátumsztringjéért. Egy f-string elsőként, minden alkalommal kiértékelődik, még mielőtt a hívás egyáltalán elérné a loggert.

A CPython extra= kulcsszava strukturált mezőkhöz nem támogatott a kamerán; helyette add át az értékeket üzenetargumentumként.

14.3.1.6. Kivételek naplózása

Egy except blokkon belül a Logger.exception() ERROR szinten naplózza az üzenetet, és hozzáfűzi az aktuális kivétel veremkövetését a rekordhoz:

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

A veremkövetést a sys.print_exception() rögzíti, ami egy kivételnaplónak a többsoros Traceback (most recent call last): blokkját adja. Ez a megfelelő eszköz a legfelső szintű kivételkezeléshez – elkapni, naplózni és továbbmenni.

14.3.1.7. Több handler

A fentebb említett éles üzemű felosztás – minden egy fájlba DEBUG szinten, a lényeg a stderr-re WARNING szinten – két handler, amely ugyanahhoz a loggerhez van csatolva, mindegyik a saját szintjével és formatterével:

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)

A gyökér logger szintje az első szűrő, amelybe minden rekord beleütközik. Állítsd a legalacsonyabb szintre, amelyet bármelyik handler látni akar – itt DEBUG-ra –, hogy egyik handlert se éheztesse ki maga a logger. A handlerenkénti szintek aztán eldöntik, mely rekordok kerülnek ténylegesen kibocsátásra mely célhelyre.

14.3.1.8. Naplófájlok forgatása

A kamera logging moduljában nincs RotatingFileHandler vagy TimedRotatingFileHandler. A forgatás az alkalmazás feladata.

A minta az, hogy az aktuális FileHandler-t egy ismert helyen tartjuk, egy újra cseréljük, amikor a forgatási feltétel teljesül, és hagyjuk, hogy egy dátumozott útvonal biztosítsa a természetes fájlhatárt. Óránkénti forgatáshoz a /sdcard/logs/<year>/<month>/<day>/<hour>.log útvonalra:

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

Hívd meg a rotate_if_needed()-et a fő hurok minden iterációjában egyszer; az útvonal-ellenőrzés olcsó, és a csere csak az órahatáron történik meg. A könyvtárfának léteznie kell, mielőtt a FileHandler meg tudja nyitni a fájlt.

14.3.1.9. Ürítés energiaérzékeny telepítéseknél

A FileHandler írásai a mögöttes fájlobjektum Python-pufferelésén mennek keresztül. Egy áramkimaradás egy írás és egy ürítés között elveszíti a végén lévő rekordokat. Akkumulátoros vagy húzd-ki-a-dugót telepítéseknél hívd meg a flush()-t a handler adatfolyamán a kritikus rekordok után, vagy időzítve.

Egy kis segédfüggvény, amely üríti a gyökér loggerhez csatolt összes handlert:

import logging

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

Hívd meg a flush_handlers()-t közvetlenül egy olyan rekord után, amelyet az alkalmazás nem engedhet meg magának elveszíteni:

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

Háttérbeli biztonság érdekében hívd meg a fő hurokból olyan ütemben, amely egyensúlyt teremt a naplófrissesség és a flash memória kopása között – másodpercenként egyszer általában bőven elég. A Logger.critical() önmagában nem vált ki ürítést.

14.3.1.10. Indítási diagnosztika

Egy terepi napló kontextus nélkül szinte haszontalan. Minden hidegindításnál az első rekordoknak azonosítaniuk kell, hogy melyik kamera, milyen build fut, és hogyan jutott el a kamera ehhez az indításhoz. Három eszközfedélzeti forrás együtt mindezt lefedi:

  • omv – az OpenMV firmware verziója.

  • os.uname() – a MicroPython verziója, a lapka neve + MCU, valamint a git címke és annak a forrásnak a buildelési dátuma, amelyből a firmware épült.

  • machine – az MCU egyedi szilícium-azonosítója és az ezt az indítást kiváltó visszaállítási ok.

  • os.listdir() minden csatlakozási ponton – a fájlrendszerek, amelyek ténylegesen elindultak.

Egy segédfüggvény, amely mindegyiket behúzza a napló első rekordjaiba:

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)

Egy tipikus napló valami ilyesmivel nyit:

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

Minden naplófájl nyolc sorára az üzemeltető ismeri a fizikai egységet, a firmware leszármazási vonalát, hogy miért indult el a kamera, és melyik tároló jött fel. Az unique id az MCU gyárilag beprogramozott szilícium-sorozatszáma; ez azonos az újraflashelések és az SD-kártya cserék között. A build annak a firmware-fának a git címkéje és dátuma, amelyből a kép épült – az az egyetlen mező, amely azt mondja: „pontosan ez az a bináris, amely ehhez az egységhez ezen az időponton kiszállításra került.”

14.3.1.11. Összerakva

Egy teljes éles üzemű naplózási beállítás, egy segédfüggvénybe szervezve, amelyet a main.py egyszer hív meg az indításkor:

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)

Majd a main.py tetején:

from app.logging_setup import setup_logging, log_boot_diagnostics

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

Az alkalmazás bármely más moduljának csak ennyit kell tennie:

import logging

log = logging.getLogger(__name__)

és ingyen megkapja a konfigurált kimenetet – fájlt teljes részletességgel, adatfolyamot figyelmeztetésekkel, elnevezett rekordokat, időbélyeggel ellátott formattert, és egy dokumentált indítást minden hidegindításnál.