14.3.1. Журналювання

Готовий продукт не може передавати дані додому за допомогою print(). print() записує у USB stdout, який існує лише тоді, коли камера підключена до розробницького столу з відкритим терміналом. У полі нічого не зчитує ці дані; кожен рядок просто відкидається. Бібліотека logging є заміною – фільтр рівнів, ціль на вибір застосунку, та формат, який описує що сталося і коли.

Модуль logging на камері є спрощеним портом CPython – та сама концептуальна модель, менша поверхня, кілька відмінностей, які важливі для налаштування у продакшені.

14.3.1.1. Концептуальна модель

Журналювання складається з чотирьох частин. Кожна частина виконує одне завдання; така розділеність дозволяє одному журналу надсилати дані до кількох цілей, кожна з власним форматом і рівнем:

  • Logger – це те, що викликає застосунок. Код пише log.info("frame %d", n); журнал – це об’єкт, до якого надходить виклик. Журнали отримують за іменем через logging.getLogger().

  • Handler вирішує куди надходить запис. StreamHandler записує у потік (за замовчуванням sys.stderr); FileHandler дописує у файл на диску. Журнал може мати будь-яку кількість обробників.

    Примітка

    На камері sys.stdout та sys.stderr підключені до одного USB CDC каналу – записи до будь-якого з них відображаються в одному терміналі, відкритому розробником через USB. Обробник, що записує у sys.stderr, на практиці є обробником, що записує туди ж, куди й print(). Абстракція обробника все одно дає вам фільтрацію та форматування для кожної цілі; вона просто не дає фізично окремого каналу.

  • Formatter вирішує як запис відображається у текст. Він приймає запис і повертає рядок, який буде записано. Один рядок формату на форматер; один форматер на обробник.

  • Фільтр рівнів присутній на кожному журналі та кожному обробнику. Записи містять рівень (DEBUG / INFO / WARNING / ERROR / CRITICAL). Проходять лише записи на рівні або вище рівня фільтра.

Ця розділеність важлива, тому що типове налаштування у продакшені має більше однієї цілі: файл на SD-карті, що зберігає все аж до DEBUG для аналізу після збою, та потік до USB, що показує лише WARNING і гірше, щоб розробник, підключений до камери, бачив головне без того, щоб тонути в деталях. Той самий код, дві цілі, два фільтри.

14.3.1.2. Рівні та їх значення

П’ять рівнів утворюють упорядковану шкалу. Записи містять рівень, щоб фільтр на кожному обробнику міг відкидати ті, що не цікавлять.

  • DEBUG – трасування, лічильники кадрів, дампи внутрішнього стану. Найнижчий рівень; обсяг великий.

  • INFO – звичайні операційні події. Wi-Fi підключено, модель завантажено, сторожовий таймер запущено, новий файл журналу ротовано.

  • WARNING – щось несподіване, але застосунок це обробив. Відкинутий кадр, повторна мережева відповідь.

  • ERROR – операція не вдалася і застосунок не міг її завершити. Відсутній файл моделі, відмова запису на SD-карту.

  • CRITICAL – застосунок взагалі не може продовжувати. Немає пам’яті, відсутнє обов’язкове монтування.

Одне важливе налаштування за замовчуванням: модуль logging на камері запускає кожен журнал на рівні WARNING. Записи на DEBUG та INFO тихо відкидаються, якщо не викликати Logger.setLevel() – зазвичай як частину виклику basicConfig() нижче. Типовий перший симптом налаштування журналювання, яке «не працює» – це те, що застосунок надіслав запис на INFO, а фільтр за замовчуванням його з’їв.

Примітка

Рівень – єдиний фільтр, який пропонує logging на камері. Немає об’єктів Filter для більш складних правил на рівні запису; якщо рівень запису проходить, він надсилається.

14.3.1.3. basicConfig: швидкий старт

logging.basicConfig() налаштовує кореневий журнал за один виклик. Найчастіше зустрічаються два варіанти:

Налаштування для розробки, все до USB stderr на INFO

import logging

logging.basicConfig(level=logging.INFO)

Налаштування для продакшену, все у файл на SD-карті з форматом часової мітки:

import logging

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

Передайте або filename= для FileHandler, або stream= для StreamHandler; вони взаємовиключні у basicConfig().

Рядок формату є шаблоном у стилі %(field)s. Поля, які підтримує форматер камери:

  • %(asctime)s – мітка часу, сформована з time.localtime(). Формат за замовчуванням – %Y-%m-%d %H:%M:%S; передайте datefmt= для перевизначення.

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

  • %(name)s – ім’я журналу (дивіться наступний розділ).

  • %(message)s – відформатоване повідомлення запису.

  • %(msecs)d – мілісекундна частина мітки часу запису.

Формат за замовчуванням, якщо жоден не вказано, – %(levelname)s:%(name)s:%(message)s – що добре для налаштування розробки та недостатньо для польового журналу, де мітка часу робить файл корисним тижні потому.

basicConfig() є no-op під час наступних викликів, якщо не передано force=True. Налаштовуйте один раз при запуску; не викликайте знову для «зміни цілі» під час виконання.

Примітка

Модуль logging на камері не має dictConfig() або fileConfig(). Конфігурація завжди програмна – один допоміжний setup_logging(), що викликається один раз з main.py, є стандартним підходом.

14.3.1.4. Іменовані журнали для кожного модуля

Код застосунку не повинен викликати скорочення на рівні модуля (logging.info(), logging.warning() тощо). Вони всі проходять через кореневий журнал, і отримані записи журналу містять ім’я root – марно для визначення звідки надійшов запис.

Стандартний підхід – один журнал на модуль, названий за модулем:

# in app/detector.py
import logging

log = logging.getLogger(__name__)

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

Кожен запис тоді несе app.detector у %(name)s, і рядок журналу показує, хто його надіслав.

Модуль logging на камері відрізняється від CPython в одному важливому аспекті: простір імен журналів є пласким. getLogger('app') та getLogger('app.detector') є незалежними журналами без відносин батько/дочірній – встановлення рівня на app не поширюється на app.detector. Механізм, який працює: іменований журнал без власних обробників бере обробники та рівень кореневого журналу. Саме так один виклик basicConfig() на корені налаштовує кожен виклик getLogger() в іншому місці застосунку.

14.3.1.5. Ліниве форматування з %-аргументами

Пишіть:

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

Не:

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

Форма %-аргументів дозволяє журналу інтерполювати аргументи після того, як фільтр рівнів вирішив, чи надсилати запис. Відфільтрований виклик DEBUG у гарячому циклі нічого не витрачає на свій рядок формату. F-рядок обчислюється першим, кожен раз, ще до того, як виклик навіть досягає журналу.

Ключове слово CPython extra= для структурованих полів не підтримується на камері; передавайте значення як аргументи повідомлення.

14.3.1.6. Журналювання винятків

Всередині блоку except, Logger.exception() записує повідомлення на рівні ERROR і додає трасування поточного винятку до запису:

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

Трасування захоплюється через sys.print_exception(), що дає журналу винятку його багаторядковий блок Traceback (most recent call last):. Це правильний інструмент для обробки винятків верхнього рівня – перехопити, записати і продовжити.

14.3.1.7. Кілька обробників

Розподіл для продакшену, згаданий на початку – все у файл на DEBUG, важливе до stderr на WARNING – це два обробники, підключені до одного журналу, кожен з власним рівнем і форматером:

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)

Рівень кореневого журналу є першим фільтром, через який проходить кожен запис. Встановіть його на найнижчий рівень, який хоче бачити будь-який обробник – тут DEBUG – щоб жоден обробник не голодував через сам журнал. Рівні для кожного обробника тоді вирішують, які записи насправді надсилаються до якої цілі.

14.3.1.8. Ротація файлів журналу

Модуль logging на камері не має RotatingFileHandler або TimedRotatingFileHandler. Ротація є завданням застосунку.

Шаблон полягає у зберіганні поточного FileHandler у відомому місці, заміні його новим при спрацюванні критерію перекочування, і використанні шляху з датою для природного обмеження файлу. Для погодинного перекочування у /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

Викликайте rotate_if_needed() один раз за ітерацію головного циклу; перевірка шляху дешева, а заміна відбувається лише на межі години. Дерево каталогів повинно існувати перед тим, як FileHandler зможе відкрити файл.

14.3.1.9. Скидання буфера при розгортаннях з чутливістю до живлення

Записи FileHandler проходять через Python-буферизацію базового об’єкта файлу. Втрата живлення між записом і скиданням буфера призводить до втрати кінцевих записів. Для розгортань від батареї або з можливістю вимкнення живлення, викликайте flush() на потоці обробника після критичних записів або за таймером.

Невеликий допоміжний метод, що скидає буфер всіх обробників, підключених до кореневого журналу:

import logging

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

Викликайте flush_handlers() одразу після запису, який застосунок не може дозволити собі втратити:

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

Для фонової безпеки викликайте його з головного циклу з такою частотою, яка збалансовує свіжість журналу зі зносом флеш-пам’яті – одного разу на секунду зазвичай достатньо. Logger.critical() не запускає скидання буфера сам по собі.

14.3.1.10. Діагностика при завантаженні

Польовий журнал без контексту майже марний. Перші записи під час кожного холодного завантаження повинні ідентифікувати яка камера, яка збірка запущена, та як камера дійшла до цього завантаження. Три джерела на пристрої між собою охоплюють все це:

  • omv – версія мікропрограми OpenMV.

  • os.uname() – версія MicroPython, назва плати + MCU, а також git-тег і дата збірки джерела, з якого було зібрано мікропрограму.

  • machine – унікальний кремнієвий ідентифікатор MCU та причина скидання, яка ініціювала це завантаження.

  • os.listdir() для кожної точки монтування – файлові системи, які фактично змонтувалися.

Допоміжний метод, що вносить всі ці дані до перших записів журналу:

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)

Типовий журнал відкривається приблизно так:

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

На восьмому рядку кожного файлу журналу оператор знає фізичний пристрій, лінію мікропрограми, чому камера завантажилася, та яке сховище змонтувалося. unique id – це заводський кремнієвий серійний номер MCU; він залишається незмінним після перепрошивання та заміни SD-карти. build – git-тег та дата дерева мікропрограми, з якого було зібрано образ – єдине поле, яке говорить: «це точно той двійковий файл, що було відправлено до цього пристрою у цей момент часу.»

14.3.1.11. Підсумовуємо все разом

Повне налаштування журналювання для продакшену, оформлене як допоміжний метод, що main.py викликає один раз при запуску:

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)

Потім на початку main.py

from app.logging_setup import setup_logging, log_boot_diagnostics

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

Кожен модуль в іншому місці застосунку просто робить:

import logging

log = logging.getLogger(__name__)

і безкоштовно отримує налаштований вивід – файл з повними деталями, потік з попередженнями, іменовані записи, форматер з міткою часу та задокументоване завантаження при кожному холодному старті.