14.3.1. 日誌記錄¶

已出貨的產品無法靠 print() 回報資訊。print() 會寫入 USB stdout，而它只在相機放在開發者工作台上、且開啟著終端機時才存在。在現場沒有任何東西會去讀取它；每一行都會被直接丟棄。logging 函式庫就是它的替代方案 -- 提供等級過濾器、由應用程式自行選擇的輸出目的地，以及一種能說明發生了什麼事、又發生在何時的格式。

相機上的 logging 模組是 CPython 版本的精簡移植 -- 心智模型相同、介面較小，但有幾項對於正式環境設定相當重要的差異。

14.3.1.1. 心智模型¶

日誌記錄由四個部分構成。每個部分各司其職；正是這種分離讓單一 logger 能扇出到多個目的地，而每個目的地各自擁有自己的格式與等級：

Logger 是應用程式呼叫的對象。程式碼寫 log.info("frame %d", n)；logger 就是這個呼叫所落在的物件。logger 透過 logging.getLogger() 以名稱查找。
Handler 決定一筆記錄要送往何處。StreamHandler 會寫入串流（預設為 sys.stderr）；FileHandler 則會附加寫入磁碟上的檔案。一個 logger 可以擁有任意數量的 handler。

備註

在相機上，sys.stdout 與 sys.stderr 都接到同一條 USB CDC 管線 -- 寫入兩者中任一者都會出現在開發者透過 USB 開啟的同一個終端機上。實務上，一個寫入 sys.stderr 的 handler 就等於是一個寫到 print() 所寫位置的 handler。handler 這層抽象仍然提供逐目的地的過濾與格式化；它只是無法提供一條物理上獨立的通道。
Formatter 決定一筆記錄要如何呈現為文字。它接收一筆記錄並回傳要寫出的那一行。每個 formatter 對應一個格式字串；每個 handler 對應一個 formatter。
等級過濾器坐落在每個 logger 與每個 handler 上。記錄帶有等級（DEBUG / INFO / WARNING / ERROR / CRITICAL）。只有等級達到或高於過濾等級的記錄才會通過。

這種分離之所以重要，是因為典型的正式環境設定會有不只一個目的地：一個位於 SD 卡上、把一切（低至 DEBUG）都留下來供事後分析的檔案，以及一個只浮現 WARNING 及更嚴重訊息的 USB 串流，讓接上相機的開發者能看到重點而不會淹沒在細節裡。同一份程式碼、兩個目的地、兩個過濾器。

14.3.1.2. 各個等級及其涵義¶

這五個等級是一個有序的刻度。記錄帶有等級，好讓每個 handler 上的過濾器能丟棄它不關心的那些。

DEBUG -- 追蹤、逐影格計數器、內部狀態傾印。最低的等級；數量很大。
INFO -- 正常的運作事件。Wi-Fi 已連線、已載入某個模型、看門狗已啟動、已輪替到一個新的日誌檔。
WARNING -- 發生了某件意料之外的事，但應用程式已處理它。掉了一個影格、重試了一次網路請求。
ERROR -- 某項操作失敗了，應用程式無法完成它。找不到模型檔、SD 卡寫入被拒絕。
CRITICAL -- 應用程式完全無法繼續執行。記憶體耗盡、必須掛載的項目遺失。

有一個重要的預設值要記住：相機的 logging 模組會把每個 logger 的起始等級設為 WARNING。除非呼叫 Logger.setLevel() -- 通常是作為下方 basicConfig() 呼叫的一部分 -- 否則 DEBUG 與 INFO 等級的記錄都會被默默丟棄。日誌設定「沒在運作」最常見的第一個徵兆，就是應用程式以 INFO 等級發出記錄，而預設過濾器吃掉了那筆記錄。

備註

等級是相機的 logging 唯一提供的過濾器。並沒有 Filter 物件可用於更豐富的逐記錄規則；只要一筆記錄的等級通過，它就會被發出。

14.3.1.3. basicConfig：快速上手¶

logging.basicConfig() 只需一次呼叫即可設定根 logger。最常出現的有兩種形態：

一種開發設定，把一切以 INFO 等級送往 USB stderr:

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 風格的範本。相機的 formatter 所支援的欄位：

%(asctime)s -- 由 time.localtime() 格式化而成的時間戳記。預設格式為 %Y-%m-%d %H:%M:%S；傳入 datefmt= 可覆寫之。
%(levelname)s -- DEBUG / INFO / WARNING / ERROR / CRITICAL。
%(name)s -- logger 的名稱（見下一節）。
%(message)s -- 記錄已格式化的訊息。
%(msecs)d -- 記錄時間戳記的毫秒部分。

若未指定格式，預設為 %(levelname)s:%(name)s:%(message)s -- 這對開發設定來說沒問題，但對現場日誌而言並不足夠，因為時間戳記才是讓那個檔案在數週後仍然有用的關鍵。

basicConfig() 在後續呼叫時是無作用的（no-op），除非傳入 force=True。請在啟動時設定一次；不要在執行中途再次呼叫它來「切換目的地」。

備註

相機的 logging 沒有 dictConfig() 或 fileConfig()。設定一律以程式化方式進行 -- 慣例是寫一個從 main.py 呼叫一次的 setup_logging() 輔助函式。

14.3.1.4. 每個模組各自具名的 logger¶

應用程式碼不應呼叫模組層級的捷徑（logging.info()、logging.warning() 等等）。那些全都會匯流經過根 logger，產生的日誌記錄帶有名稱 root -- 對於辨別記錄來自何處毫無用處。

慣例是每個模組一個 logger，並以該模組命名:

# in app/detector.py
import logging

log = logging.getLogger(__name__)

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

如此一來每筆記錄都會在 %(name)s 中帶有 app.detector，日誌行也就說明了是誰發出它的。

相機的 logging 在一個重要面向上與 CPython 不同：logger 命名空間是扁平的。getLogger('app') 與 getLogger('app.detector') 是各自獨立的 logger，彼此沒有父／子關係 -- 在 app 上設定等級並不會傳播到 app.detector。真正有效的機制是：一個本身沒有 handler 的具名 logger 會借用根 logger 的 handler 與等級。這正是為什麼在 root 上單單一次 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")

%-引數形式讓 logger 在等級過濾器決定是否發出該記錄之後才插補引數。在熱迴圈中一個被過濾掉的 DEBUG 呼叫不會為其格式字串付出任何代價。而 f-string 會先行求值，每一次都是，甚至在呼叫尚未抵達 logger 之前。

相機並不支援 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. 多個 handler¶

開頭提到的正式環境分流 -- 把一切以 DEBUG 寫入檔案、把重點以 WARNING 送往 stderr -- 就是兩個附加到同一個 logger 的 handler，各自擁有自己的等級與 formatter:

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)

根 logger 的等級是每筆記錄碰到的第一個過濾器。請把它設為任何 handler 想要看到的最低等級 -- 此處為 DEBUG -- 這樣兩個 handler 都不會被 logger 本身餓著。接著各 handler 的等級才決定哪些記錄真正會被發送到哪個目的地。

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 緩衝。在一次寫入與一次刷新之間發生斷電，會遺失尾端的那些記錄。對於電池供電或會被直接拔插的部署，請在關鍵記錄之後、或定時對 handler 的串流呼叫 flush()。

一個能刷新附加到根 logger 之每個 handler 的小型輔助函式:

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 獨一無二的晶片 ID，以及觸發這次開機的重置原因。
對每個掛載點呼叫 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__)

便能免費取得已設定好的輸出 -- 含完整細節的檔案、含警告的串流、具名的記錄、帶時間戳記的 formatter，以及每次冷開機都有完整記錄的開機過程。