14.3.1. การบันทึกข้อมูล (Logging)

ผลิตภัณฑ์ที่จัดส่งออกไปไม่สามารถส่งข้อมูลกลับบ้านด้วย print() ได้ print() เขียนไปยัง USB stdout ซึ่งมีอยู่เฉพาะเมื่อกล้องอยู่บนโต๊ะของนักพัฒนาที่เปิดเทอร์มินัลไว้ ในภาคสนามไม่มีสิ่งใดมาอ่านข้อมูลนั้น ทุกบรรทัดจะถูกทิ้งไป ไลบรารี logging คือตัวแทนที่แท้จริง -- มีตัวกรองระดับ ปลายทางตามที่แอปพลิเคชันเลือก และรูปแบบที่บอกว่าเกิดอะไรขึ้นและเมื่อใด

โมดูล logging บนกล้องเป็นพอร์ตที่ลดขนาดมาจาก CPython -- มีแนวคิดเดียวกัน พื้นผิวเล็กลง และความแตกต่างบางประการที่สำคัญสำหรับการตั้งค่าในการใช้งานจริง

14.3.1.1. แนวคิดหลัก

ระบบ logging ถูกสร้างขึ้นจากสี่ส่วน แต่ละส่วนมีหน้าที่เดียว การแยกกันนี้ทำให้ logger หนึ่งตัวส่งออกไปยังหลายปลายทางได้ แต่ละปลายทางมีรูปแบบและระดับของตัวเอง:

• Logger คือสิ่งที่แอปพลิเคชันเรียกใช้ โค้ดเขียนว่า log.info("frame %d", n) logger คือออบเจ็กต์ที่รับการเรียกนั้น Logger ถูกค้นหาด้วยชื่อผ่าน logging.getLogger()

• Handler ตัดสินใจว่าเรคอร์ดจะไปที่ ไหน StreamHandler เขียนไปยัง stream (sys.stderr ตามค่าเริ่มต้น) ส่วน FileHandler ต่อท้ายไฟล์บนดิสก์ Logger หนึ่งตัวสามารถมี handler ได้หลายตัว

  Note

  บนกล้อง sys.stdout และ sys.stderr เชื่อมต่อกับ USB CDC pipe เดียวกัน -- การเขียนไปยังทั้งสองจะปรากฏบนเทอร์มินัลเดียวกันที่นักพัฒนาเปิดผ่าน USB handler ที่เขียนไปยัง sys.stderr ในทางปฏิบัติ คือ handler ที่เขียนไปยังที่เดียวกับ print() การแยก handler ยังคงให้การกรองและการจัดรูปแบบแต่ละปลายทาง แต่ไม่ได้ให้ช่องทางทางกายภาพที่แยกต่างหาก

• Formatter ตัดสินใจว่าเรคอร์ดจะแสดงเป็นข้อความอย่าง ไร มันรับเรคอร์ดและส่งคืนบรรทัดที่จะถูกเขียน หนึ่งสตริงรูปแบบต่อหนึ่ง formatter หนึ่ง formatter ต่อหนึ่ง handler

• ตัวกรองระดับ อยู่บน logger ทุกตัวและ handler ทุกตัว เรคอร์ดมีระดับ (DEBUG / INFO / WARNING / ERROR / CRITICAL) เฉพาะเรคอร์ดที่ระดับเท่ากับหรือสูงกว่าระดับตัวกรองเท่านั้นที่จะผ่านไปได้

การแยกนั้นสำคัญเพราะการตั้งค่าในการผลิตทั่วไปมีปลายทางมากกว่าหนึ่งแห่ง: ไฟล์บนการ์ด SD ที่เก็บทุกอย่างลงถึงระดับ DEBUG สำหรับการวิเคราะห์หลังเหตุการณ์ และ stream ไปยัง USB ที่แสดงเฉพาะ WARNING ขึ้นไปเพื่อให้นักพัฒนาที่เชื่อมต่อกับกล้องเห็นสิ่งสำคัญโดยไม่จมกับรายละเอียด โค้ดเดียวกัน สองปลายทาง สองตัวกรอง

14.3.1.2. ระดับและความหมายของแต่ละระดับ

ห้าระดับเป็นมาตราส่วนที่เรียงลำดับ เรคอร์ดมีระดับเพื่อให้ตัวกรองบน handler แต่ละตัวสามารถทิ้งเรคอร์ดที่ไม่สนใจได้

• DEBUG -- การติดตาม, ตัวนับแต่ละเฟรม, การดัมพ์สถานะภายใน ระดับต่ำสุด ปริมาณสูง

• INFO -- เหตุการณ์การดำเนินงานปกติ Wi-Fi เชื่อมต่อแล้ว, โมเดลโหลดแล้ว, watchdog เริ่มแล้ว, ไฟล์บันทึกใหม่หมุนเวียนเข้ามา

• WARNING -- บางอย่างไม่คาดคิดแต่แอปพลิเคชันจัดการได้ เฟรมที่หลุดหาย, คำขอเครือข่ายที่ลองใหม่

• ERROR -- การดำเนินการล้มเหลวและแอปพลิเคชันไม่สามารถดำเนินการให้เสร็จสมบูรณ์ได้ ไฟล์โมเดลหายไป, การเขียนการ์ด SD ถูกปฏิเสธ

• CRITICAL -- แอปพลิเคชันไม่สามารถดำเนินต่อไปได้เลย หน่วยความจำหมด, mount ที่จำเป็นขาดหายไป

ค่าเริ่มต้นที่สำคัญที่ต้องจำ: โมดูล logging ของกล้องเริ่มต้น logger ทุกตัวที่ระดับ WARNING เรคอร์ดที่ระดับ DEBUG และ INFO จะถูกทิ้งอย่างเงียบๆ เว้นแต่จะเรียก Logger.setLevel() -- โดยปกติเป็นส่วนหนึ่งของการเรียก basicConfig() ด้านล่าง อาการแรกที่พบบ่อยของการตั้งค่า logging ที่ "ไม่ทำงาน" คือแอปพลิเคชันส่งออกที่ระดับ INFO และตัวกรองเริ่มต้นกิน record นั้นทิ้ง

Note

ระดับเป็นตัวกรองเดียวที่ logging ของกล้องมีให้ ไม่มีออบเจ็กต์ Filter สำหรับกฎต่อเรคอร์ดที่ซับซ้อนกว่านั้น ถ้าระดับของเรคอร์ดผ่าน มันก็จะถูกส่งออก

14.3.1.3. basicConfig: การเริ่มต้นอย่างรวดเร็ว

logging.basicConfig() กำหนดค่า root logger ในการเรียกเดียว รูปแบบที่พบบ่อยสองแบบ:

การตั้งค่าสำหรับพัฒนา ทุกอย่างไปยัง USB stderr ที่ระดับ INFO

import logging

logging.basicConfig(level=logging.INFO)

การตั้งค่าสำหรับการผลิต ทุกอย่างไปยังไฟล์บนการ์ด SD พร้อมรูปแบบที่มี timestamp:

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 -- timestamp ที่จัดรูปแบบจาก time.localtime() รูปแบบเริ่มต้นคือ %Y-%m-%d %H:%M:%S ส่ง datefmt= เพื่อแทนที่

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

• %(name)s -- ชื่อของ logger (ดูส่วนถัดไป)

• %(message)s -- ข้อความที่จัดรูปแบบแล้วของเรคอร์ด

• %(msecs)d -- ส่วนมิลลิวินาทีของ timestamp ของเรคอร์ด

รูปแบบเริ่มต้นหากไม่มีการกำหนดคือ %(levelname)s:%(name)s:%(message)s -- ซึ่งเพียงพอสำหรับการตั้งค่าพัฒนาแต่ไม่เพียงพอสำหรับบันทึกในภาคสนาม ซึ่ง timestamp คือสิ่งที่ทำให้ไฟล์มีประโยชน์หลายสัปดาห์ต่อมา

basicConfig() ไม่มีผลกระทบใดในการเรียกครั้งถัดไป เว้นแต่จะส่ง force=True กำหนดค่าครั้งเดียวในการเริ่มต้น อย่าเรียกมันอีกเพื่อ "สลับปลายทาง" ระหว่างการทำงาน

Note

logging ของกล้องไม่มี dictConfig() หรือ fileConfig() การกำหนดค่าเป็นแบบโปรแกรมเสมอ -- helper setup_logging() หนึ่งตัวที่เรียกครั้งเดียวจาก main.py คือแนวทางปฏิบัติ

14.3.1.4. Named logger แยกตามโมดูล

โค้ดแอปพลิเคชันไม่ควรเรียกใช้ shortcut ระดับโมดูล (logging.info(), logging.warning(), และอื่นๆ) เนื่องจากทั้งหมดถูกส่งผ่าน root logger และเรคอร์ด log ที่ได้มีชื่อว่า 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())

ทุกเรคอร์ดจะมี app.detector ใน %(name)s และบรรทัด log บอกว่าใครส่งออกมา

logging ของกล้องแตกต่างจาก CPython ในด้านสำคัญหนึ่งประการ: namespace ของ logger เป็น แบบแบน getLogger('app') และ getLogger('app.detector') เป็น logger อิสระที่ไม่มีความสัมพันธ์ parent / child -- การตั้งระดับบน app ไม่ ส่งต่อไปยัง app.detector กลไกที่ใช้งานได้: logger ที่มีชื่อแต่ไม่มี handler ของตัวเองจะยืม handler และระดับของ root logger นั่นคือวิธีที่การเรียก basicConfig() ครั้งเดียวบน root ตั้งค่าการเรียก getLogger() ทุกครั้งในแอปพลิเคชัน

14.3.1.5. การจัดรูปแบบอาร์กิวเมนต์แบบ Lazy %-arg

เขียนว่า:

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

ไม่ใช่:

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

รูปแบบ %-arg ให้ logger แทรกค่าอาร์กิวเมนต์ หลังจาก ตัวกรองระดับตัดสินใจว่าจะส่งออกเรคอร์ดหรือไม่ การเรียก DEBUG ที่ถูกกรองออกในลูปที่รันถี่ไม่เสียค่าใช้จ่ายใดๆ สำหรับสตริงรูปแบบ f-string จะถูกประเมินก่อน ทุกครั้ง ก่อนที่การเรียกจะไปถึง logger

คีย์เวิร์ด extra= ของ CPython สำหรับฟิลด์ที่มีโครงสร้างไม่ได้รับการสนับสนุนบนกล้อง ส่งค่าเป็นอาร์กิวเมนต์ข้อความแทน

14.3.1.6. การบันทึก exception

ภายในบล็อก except Logger.exception() บันทึกข้อความที่ระดับ ERROR และ ต่อท้าย traceback ของ exception ปัจจุบันไปยังเรคอร์ด:

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

traceback ถูกจับภาพผ่าน sys.print_exception() ซึ่งเป็นสิ่งที่ให้บล็อก Traceback (most recent call last): หลายบรรทัดในบันทึก exception นี่คือเครื่องมือที่เหมาะสมสำหรับการจัดการ exception ระดับสูงสุด -- จับ, บันทึก, และดำเนินต่อ

14.3.1.7. หลาย handler

การแยกในการผลิตที่กล่าวถึงตอนต้น -- ทุกอย่างไปยังไฟล์ที่ระดับ DEBUG ส่วนสำคัญไปยัง stderr ที่ระดับ WARNING -- คือ handler สองตัวที่ติดกับ logger เดียวกัน แต่ละตัวมีระดับและ 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)

ระดับของ root 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() หนึ่งครั้งต่อการวนซ้ำของ main loop การตรวจสอบพาธมีต้นทุนต่ำและการสลับจะเกิดขึ้นเฉพาะที่ขอบเขตชั่วโมง ต้องมีไดเรกทอรีก่อนที่ FileHandler จะเปิดไฟล์ได้

14.3.1.9. การ flush สำหรับการใช้งานที่ไวต่อไฟฟ้า

การเขียนของ FileHandler ผ่านการบัฟเฟอร์ Python ของออบเจ็กต์ไฟล์พื้นฐาน การสูญเสียไฟฟ้าระหว่างการเขียนและการ flush จะทำให้เรคอร์ดท้ายสูญหาย สำหรับการใช้งานที่ใช้แบตเตอรี่หรือถอดปลั๊กโดยตรง ให้เรียก flush() บน stream ของ handler หลังเรคอร์ดที่สำคัญ หรือตาม timer

helper เล็กๆ ที่ flush ทุก handler ที่ติดกับ root logger:

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()

เพื่อความปลอดภัยในเบื้องหลัง ให้เรียกจาก main loop ตามความถี่ที่สมดุลระหว่างความสดของบันทึกกับการสึกหรอของแฟลช -- หนึ่งครั้งต่อวินาทีโดยปกติเพียงพอ Logger.critical() ไม่ ทริกเกอร์การ flush เอง

14.3.1.10. การวินิจฉัยเมื่อบูต

บันทึกภาคสนามที่ไม่มีบริบทแทบไม่มีประโยชน์ เรคอร์ดแรกในการบูตเย็นทุกครั้งควรระบุว่าเป็นกล้อง ตัวไหน บิลด์ไหน กำลังทำงาน และ อย่างไร กล้องมาถึงการบูตนี้ สามแหล่งบนอุปกรณ์ครอบคลุมทั้งหมดนั้น:

• omv -- เวอร์ชัน firmware ของ OpenMV

• os.uname() -- เวอร์ชัน MicroPython, ชื่อบอร์ด + MCU และแท็ก git และวันที่บิลด์ของซอร์สที่สร้าง firmware

• machine -- ID ซิลิกอนที่ไม่ซ้ำกันของ MCU และสาเหตุการรีเซ็ตที่ทำให้เกิดการบูตนี้

• os.listdir() กับแต่ละจุด mount -- ระบบไฟล์ที่เริ่มต้นทำงานได้จริง

helper ที่ดึงข้อมูลทั้งหมดนั้นไปยังเรคอร์ดแรกของบันทึก:

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

แปดบรรทัดเข้าสู่ทุกไฟล์บันทึก ผู้ปฏิบัติงานทราบหน่วยทางกายภาพ, สายพันธุ์ firmware, สาเหตุที่กล้องบูต และพื้นที่จัดเก็บที่เริ่มทำงาน unique id คือหมายเลขซีเรียลซิลิกอนที่โรงงานโปรแกรมไว้ของ MCU มันเหมือนกันแม้จะ reflash หรือเปลี่ยนการ์ด SD build คือแท็ก git และวันที่ของ firmware tree ที่สร้าง image -- ฟิลด์เดียวที่บอกว่า "นี่คือไบนารีที่ส่งไปยังหน่วยนี้ ณ จุดในเวลานั้นอย่างแน่นอน"

14.3.1.11. รวมทุกอย่างเข้าด้วยกัน

การตั้งค่า logging สำหรับการผลิตที่สมบูรณ์ แบ่งเป็น helper ที่ 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__)

และได้รับผลลัพธ์ที่กำหนดค่าไว้โดยไม่ต้องทำอะไรเพิ่ม -- ไฟล์พร้อมรายละเอียดครบถ้วน, stream พร้อมคำเตือน, เรคอร์ดที่มีชื่อ, formatter ที่มี timestamp และบันทึกการบูตทุกครั้งที่บูตเย็น