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.