1. 写在前面:为什么我在 MicroPython 里弃用了标准 logging
做了一段时间的 MicroPython 开发后,你会发现一个尴尬的事实:板子上跑着正经业务代码,结果日志系统反而是最先拖后腿的那个。官方标准库里的 logging 模块能用,但用起来总觉得别扭——它更像是在 PC 上写代码的思路,默认的 StreamHandler 在你的串口终端上打印没问题,但一旦你想把日志写到文件、限制文件大小、隔几天自动滚动,就得上各种额外的类,来回配置,代码量呼呼涨。
更麻烦的是内存和 flash 寿命。ESP32 这种开发板,RAM 本来就紧张,你要是配置一堆 Handler、Formatter,跑几分钟内存就见底了。而日志轮转(log rotation)这件事,在桌面平台上你用 RotatingFileHandler 很自然,在单片机上你根本没那么多内存去创建新对象、维护复杂状态。我做了一个偏门但很实际的调研:MicroPython 官方固件里,logging 模块的代码本身没什么问题,但轮转和过滤都得自己动手拼,拼出来的代码比业务代码还难维护。
后来我干脆自己写了一个日志模块,就叫 uLogLite。名字的意思很简单:ultra-lightweight log for MicroPython,但实际功能不只是“轻”,它把级别控制、轮转、过滤这三件最常用的事做到极简,代码量控制在百行左右,跑在任何 MicroPython 3.4+ 的板子上都顺畅。用了几个月,在 ESP32-C3、RP2040、STM32F407 几个平台上都验证过,踩了不少坑,也总结了不少心得,这次整理出来分享给需要的人。
这篇内容不是什么高端技术,就是一个非常实用的小工具,适合所有在 MicroPython 环境里做设备端开发、传感器采集、电池供电项目、或任何需要长期运行且日志较多的场景。如果你只是想在 REPL 里 print 两句调试,用不上它;但只要你的设备要跑几天、几周,日志要落盘、要做故障回放,这篇文章应该能帮你省下不少踩坑的时间。
2. 整体架构与设计思路:轻量到极致,扩展留给使用者
2.1 为什么“轻量优先”是嵌入式日志的第一原则
我先解释一下为什么我强调轻量。MicroPython 自身是一个解释器,跑在资源受限的 MCU 上,它的 Python 字节码和对象本身就有基础开销。如果你用的模块创建一个 Logger 实例要几十个字节,配置一个 Handler 又要几百个字节,再整个 Formatter,内存占用轻松超过 1KB。放在 PC 上这是零头,但在只有 320KB RAM 的 ESP32 上,1KB 可能就决定你还能不能开一个 WiFi 缓冲区。
我在设计 uLogLite 时给自己定的规矩:核心类只有两个,一个管理日志级别和过滤,一个管理输出目标和轮转。所有功能围绕这两个类展开,不搞复杂的类继承。用到什么功能就创建什么对象,不用就把引用删除。实测下来,完整的 uLogLite 模块源码加注释不到 120 行,运行时额外消耗的 RAM 约 300 到 500 字节,和标准库 logging 对比起码省了一半以上。
对比之下,标准 logging 的优势其实是功能全面,比如支持 Logger、Handler、Formatter、Filter 多级抽象,可以组合出非常灵活的结构。但在单片机上,这个“灵活”恰恰是负担。你想想,每个 Logger 要持有 Handler 列表,每次发射日志要遍历 Handler 列表、调用 filter、再格式化、再输出。这中间每一环都有方法调用开销、对象分配开销。在 PC 上完全无所谓,在 MCU 上积累起来就是卡顿和 RAM 耗尽。
uLogLite 的策略很简单:把最常用的写入路径压缩到最短。记录一条日志时,先做一次级别整数判断,再做一次过滤器字典查询,然后直接拼字符串写出。全程不创建新对象,不进行复杂格式化,除非你真的用了花括号占位符。
2.2 代码结构拆解:两个核心类怎么分工
我把整个模块拆成两个类,对应的职责非常清晰:
- ULog:负责日志级别管理、过滤规则、生成日志文本。
- LiteHandler:负责把日志输出到目标设备(串口、文件、socket),如果目标是文件,则负责文件轮转。
有人会问:为什么把输出逻辑单独拆出来?因为 MicroPython 的代码跑在不同的板子上,有的用 UART,有的用 I2C LCD,有的写到 SD 卡,有的发到 MQTT。输出方式千奇百怪,如果我把它固定在文件写死,就失去通用性了。拆出来之后,你只需要替换 LiteHandler 的输出目标,就能适配你的硬件。
下面的示例就是 ULog 的简化代码,你可以看到它的结构非常直接:
from machine import Pin, UART import os, time class ULog: DEBUG = 10 INFO = 20 WARNING = 30 ERROR = 40 CRITICAL = 50 _LEVEL_NAMES = { DEBUG: "DEBUG", INFO: "INFO", WARNING: "WARN", ERROR: "ERROR", CRITICAL: "CRIT", } def __init__(self, name="app", min_level=DEBUG): self.name = name self.min_level = min_level self.handlers = [] self.filters = {} # tag -> min_level def add_handler(self, handler): self.handlers.append(handler) return handler def set_level(self, level): self.min_level = level def set_filter(self, tag, level): self.filters[tag] = level def _should_log(self, level, tag): if level < self.min_level: return False if tag in self.filters and level < self.filters[tag]: return False return True def log(self, level, tag, msg, *args): if not self._should_log(level, tag): return text = self._format(level, tag, msg, args) for h in self.handlers: h.emit(text) def debug(self, tag, msg, *args): self.log(self.DEBUG, tag, msg, *args) # info / warning / error / critical 类似,省略你在实际项目里可以这么用:
log = ULog("gateway", ULog.INFO) log.add_handler(LiteHandler(uart=UART(1, 115200))) log.info("sensor", "read ok: temp=%.1f", 23.5)再看 LiteHandler 的简化版本:
class LiteHandler: def __init__(self, uart=None, file_path=None, max_size=1024*1024, backup=1): self.uart = uart self.file_path = file_path self.max_size = max_size self.backup = backup self._fd = None # 打开文件或确认 uart 就绪 def emit(self, text): if self.uart: self.uart.write(text + "\n") elif self._fd: self._fd.write(text + "\n") self._fd.flush() self._check_rotation() def _check_rotation(self): if self._fd.tell() >= self.max_size: self._rotate() def _rotate(self): # 具体的轮转逻辑,稍后详述 passLiteHandler 持有一个输出目标,要么是 UART 对象,要么是文件路径。很多初学者一开始想的是“能不能同时输出到串口和文件?”答案是能,但建议别在 Handler 里面做多个目标。正确做法是创建两个 LiteHandler 实例,分别指定 uart 和 file_path,然后都加到 ULog 上。这样代码更清晰,也方便你在发布固件时只保留文件输出而注释掉串口输出。
2.3 为什么建议使用整数级别而不是字符串级别
很多 MicroPython 初学者在写日志的时候习惯用字符串,比如 log.info("INFO: something"),然后判断的时候去比较字符串。这个问题在嵌入式环境里很严重:字符串比较慢、占内存,还特别容易打错大小写。uLogLite 使用整数级别,类似标准库的常量定义:DEBUG=10、INFO=20、WARNING=30、ERROR=40、CRITICAL=50。整数比较只是一条字节码指令,性能上完全没压力,而且方便做大小比较,比如“凡是 WARNING 以下的一律不记”。
有人会觉得整数不够直观,那在格式化输出时由 _LEVEL_NAMES 映射成字符串即可。映射表是固定字典,查询开销可以忽略不计。而且你还可以根据自己的业务需要扩展特殊级别,比如 15 代表“TRACE”,25 代表“AUDIT”,只要在 _LEVEL_NAMES 里加上对应的名称即可。
一个现实案例:我之前做一个电池供电的温湿度采集节点,晚上要休眠、早上 6 点才上报数据。整个日志需求就是“平时只记录 WARNING 和 ERROR,防止 flash 被无用 INFO 写满;调试阶段才把所有级别都打开”。启动时根据设备的配置标志决定 set_level(ULog.INFO) 还是 set_level(ULog.DEBUG)。这个逻辑用整数级别实现起来非常简单,就是你做阈值比较而已。如果用字符串级别,你还得写一段字符串映射函数,纯属自找麻烦。
3. 核心功能逐个拆解:级别、过滤、轮转的实现细节
3.1 日志级别机制:阈值判断到底判断什么
日志级别的核心就一句话:日志发出来的时候,先和阈值比较,低于阈值直接丢弃,不做字符串格式化,也不做输出。
阈值分为两层。第一层是 ULog 实例的全局阈值 min_level,对应代码里的 self.min_level。你可以理解为“这个模块级别的总闸”,低于这个闸门的日志一律不放行。第二层是 tag 级别的 filter,也就是 self.filters 字典里的配置。它可以对某个具体的业务标签单独设定阈值。比如你设置全局阈值是 INFO,但你特别关心 sensor 这个模块,就可以 set_filter("sensor", DEBUG),这样 sensor 模块的 DEBUG 日志也能出来,其他模块的 DEBUG 还是被拦。
这样设计的好处是灵活度和性能兼得。全局判断只要一次整数比较,绝大多数不相关的日志在第一步就被过滤掉。之后再过 filter 字典,因为字典查询也是 O(1) 操作,所以就算你配了十几个 tag,开销也不大。我在 RP2040 主频 133MHz 上简单测过,即使开了满级别的 DEBUG 日志,每秒钟记录上百条日志也不会导致主流程卡顿。
这里有个关键点值得解释:为什么不把 filter 做成“正则匹配”?很多学过 PC 开发的人会下意识想用正则来匹配日志标签。但 MicroPython 没有内置 re 模块(或者说 re 模块体积大且性能一般),在 MCU 上做正则匹配开销太大。uLogLite 的做法是用简单的字典精确匹配,遇到需要“前缀匹配”的场景(比如想把所有 sensor_xxx 的日志都提到 DEBUG),你可以自己在调用处设置 tag,或者用带通配符的简单匹配函数,但说实话,大部分场景下精确匹配已经够用了。
给一个配置示例:
# 全局只输出 INFO 及以上 log.set_level(ULog.INFO) # 但 sensor 模块的 debug 信息很重要,单独放行 log.set_filter("sensor", ULog.DEBUG) # 如果 network 模块老出问题,可以单独提高它的级别到 ERROR log.set_filter("network", ULog.ERROR) log.info("app", "booting...") log.debug("sensor", "measure start") log.error("network", "connection lost")在这个配置下,app 模块的 info 会输出,sensor 模块的 debug 会输出,network 模块的 error 会输出,而 network 模块的 info 会被丢弃,因为它的 filter 阈值是 ERROR。这样你就可以针对具体问题模块做精细的日志控制,而不用全局把所有日志级别放低,导致 flash 被海量日志淹没。
3.2 过滤机制:几个常见的过滤场景及实现
过滤不只是按 tag 过滤,还有几种很常见的场景,uLogLite 的思路是以 tag 为主、以消息内容为辅。
第一种就是标签级别的过滤,上面已经讲了。这个适合区分模块,比如 sensor、battery、network、ota 等子模块。每个模块打日志时都传入自己的 tag,日志系统就能按 tag 做精细化控制。
第二种是内容关键词过滤。有时候你想只记录包含特定关键词的日志,比如 “error” 或 “timeout”。在 uLogLite 中,这个可以通过在传入 msg 之前自行判断,也可以扩展 _should_log 方法。我给个扩展示例,你就能明白怎么在不破坏核心代码的前提下做自定义:
class KeyWordLog(ULog): def __init__(self, name="app", min_level=ULog.DEBUG, keywords=()): super().__init__(name, min_level) self.keywords = keywords def _should_log(self, level, tag): if not super()._should_log(level, tag): return False # 不能在这里判断消息内容,因为消息内容还没有拼出来 return True注意,_should_log 是在格式化之前调用的,所以这个时候拿不到消息内容。如果你一定要做内容关键字过滤,有两个方案:一是把过滤逻辑放在格式化之后、输出之前的 _format 结果上,但这意味着每条日志都要先格式化,浪费资源;二是我们通常推荐的方案,即在日志调用点做判断,比如if "timeout" in msg: log.warning("net", msg),这样只对少数需要过滤的地方生效,性能开销最小。
第三种是突发流量抑制。设备在某个异常场景下可能疯狂刷日志,比如 WiFi 重连失败时每秒打一条 ERROR。这种情况下即使级别过滤了,flash 写入量还是很大。uLogLite 的思路是你可以自己在 ULog 子类里加一个简单的“连续重复抑制器”,大概逻辑是:如果这一秒内相同 tag 相同 level 的日志已经出现过 N 次,就丢弃后续的那条,或者压缩成一条“上次日志重复了 N 次”。这个功能不在核心代码里,是为了保持核心代码的简洁,但它很容易基于 ULog 的扩展点实现。
from time import ticks_ms class RateLimitLog(ULog): def __init__(self, name="app", min_level=ULog.DEBUG, window_ms=1000, max_count=5): super().__init__(name, min_level) self.window_ms = window_ms self.max_count = max_count self._count = 0 self._first_ts = ticks_ms() def log(self, level, tag, msg, *args): if not self._should_log(level, tag): return now = ticks_ms() if now - self._first_ts >= self.window_ms: self._count = 0 self._first_ts = now if self._count >= self.max_count: return self._count += 1 super().log(level, tag, msg, *args)这个类就可以当作限流过滤。我实际测试过,在 ESP32 上如果日志无限刷,flash 的寿命会急剧下降,所以做设备固件时这个限流非常有必要。核心 ULog 不内置限流是为了通用性,但扩展点留好了,你想用就自己加,很简单。
3.3 日志轮转:文件大小与备份数量的博弈
轮转是日志模块里最容易被忽视又最容易出问题的功能。在桌面系统上,“轮转”指的是当日志文件超过一定大小后,把当前文件改名成 .1、.2,再新建一个当前文件,这样可以保留多份历史日志,防止单文件无限膨胀。在 MCU 上,这个逻辑一样适用,但有几点要特别注意。
先说标准轮转逻辑:
- 当日志文件大小达到 max_size 时触发轮转。
- 如果设置了 backup=1,则把当前日志文件改名为 .1,然后重新创建日志文件。
- 如果 backup=2,则先把 .1 改名为 .2,再把当前文件改名为 .1,依此类推。
- 通常删除最老的那份备份。
在 MicroPython 的 os 模块里,有 rename 和 remove 这两个函数,足够实现这个逻辑。代码实现如下:
def _rotate(self): # 关闭当前文件 if self._fd: self._fd.close() # 先删除最老的备份,然后依次改名 backup_path = self.file_path + ".{}".format(self.backup) try: os.remove(backup_path) except OSError: pass for i in range(self.backup - 1, 0, -1): src = self.file_path + ".{}".format(i) dst = self.file_path + ".{}".format(i + 1) try: os.rename(src, dst) except OSError: pass # 把当前日志文件改为 .1 os.rename(self.file_path, self.file_path + ".1") # 重新打开新文件 self._fd = open(self.file_path, "a")这个逻辑里最关键的一个细节:在 MicroPython 中,文件重命名之前必须先关闭文件句柄。如果你在 Windows 或 Linux PC 上编程,习惯了开着文件做 rename,换到 MCU 上就会遇到 OSError。我第一次实现时就踩过这个坑,在 REPL 里试了半天才意识到是文件没关闭的问题。
第二个关键细节是max_size的选取。这个值要跟你的 flash 剩余空间和 RAM 缓冲大小平衡。我曾经把 max_size 设成 2MB,结果发现 ESP32 的默认文件系统分区只有 1.4MB,日志写到一半直接撑爆,整个文件系统都出问题。一般来说,保守做法是 max_size 不要超过文件系统总容量的 1/4。在 ESP32 上,如果你用默认的 1.4MB 分区,建议 max_size 设为 256KB,backup 设为 2,这样总占用 768KB,留出余量给 OTA 固件缓存和其他数据。
第三个细节是,在移动文件之前,你最好在日志里写一条“文件已轮转”的记录。这个看起来多余,但实际排查问题时帮助很大。你能知道这条日志是写在哪个轮转文件里的,如果每个轮转文件首行都有时间戳,后面的排查时间会大幅缩短。
3.4 日志级别与轮转的联动问题
这里有个很多人没考虑到的点:日志级别设置会直接影响轮转频率。如果你把级别设成 DEBUG,日志量可能就是 INFO 级别的五六倍,原本能跑一天的轮转配置,半天就轮转好几次了。所以日志系统的参数不是孤立的,你要根据实际的业务日志产生速率去反推轮转参数。
比如你在做温湿度采集,每 30 秒上报一次,正常情况每分钟产生 2 条 INFO 日志,一条大约 80 字节,一天就是 230KB 左右。如果你的 max_size 是 128KB,那你一天要轮转两次,一个备份可能不够覆盖完整一天。如果设备要无人值守跑一周,你至少要 backup=5,总占用 768KB 才能保证数据不被覆盖。当然,如果你只是排查最近半天的故障,backup=1 或 2 就够了。
我个人习惯是先跑一个“容量测试脚本”,统计一段时间内日志文件的增长速度,再反推 max_size 和 backup。这个脚本很简单,就是用 uLogLite 输出 1000 条典型业务日志,看文件实际大小,然后乘上单位时间的日志条数,就能估算出一天的数据量。文档看十遍不如实际测一遍,这个建议对任何嵌入式项目都适用。
4. 实操过程:从零开始把 uLogLite 接入你的 MicroPython 项目
4.1 环境准备与文件部署
uLogLite 不依赖任何第三方 MicroPython 库,只需要 MicroPython 固件自带的 os 和 machine 模块。所以接入的步骤非常基础:
- 在项目目录下创建 uloglite.py 文件。
- 用 mpremote 或 ampy 将文件上传到开发板。
- 在你的 main.py 中 import 并初始化。
我常用的是 mpremote,因为它是 MicroPython 官方维护的,跨平台支持好。上传命令很简单:
mpremote connect /dev/ttyUSB0 cp uloglite.py :uloglite.py如果你用的是 ESP32-C3 这类板子,接口可能是 USB 串口,Linux 下设备名可能是 /dev/ttyACM0,Windows 下是 COMx,根据实际情况修改。
上传好之后,在 main.py 里写初始化逻辑:
import uloglite from uloglite import ULog, LiteHandler log = ULog("app", ULog.INFO) # 创建文件 handler,指定日志文件路径和大小限制 fh = LiteHandler(file_path="/logs/app.log", max_size=128*1024, backup=2) log.add_handler(fh) # 如果你想同时输出到 USB 串口,再创建一个 handler from machine import UART uart = UART(1, 115200, tx=33, rx=34) # 根据你的板子指定引脚 sh = LiteHandler(uart=uart) log.add_handler(sh)这里有个容易出错的点:日志目录 /logs 必须存在。如果文件系统里没有这个目录,open() 会失败。你可以在代码里添加一个目录检查,或者直接用根目录的 /log.txt 之类。我一般用一个简单的 helper 函数来确保目录存在:
def ensure_dir(path): try: os.mkdir(path) except OSError: pass4.2 常用配置模板:不同应用场景的参数推荐
根据我的实际项目经验,整理了三套配置模板可以参考:
第一个是“开发调试型配置”。特点是级别开到 DEBUG,输出到串口为主,不用轮转或者轮转不开太大。这种配置用于开发调试阶段,你能看到尽可能多的细节,在出问题时能快速定位。代码里只需要加一个串口 handler 就够了,不写文件,避免影响 flash 寿命。
第二个是“长期运行记录型配置”。级别设为 INFO 或 WARNING,输出到文件为主,开启轮转。这种配置适合需要无人值守长期运行、出故障后回来分析日志的场景。max_size 根据日志频率计算,backup 通常 2 到 5 个,确保能覆盖到上一次故障发生的时刻。
第三个是“低功耗监控型配置”。级别 WARNING 以上,输出到文件但打开后立即写、写完立即关闭,减少写 flash 的窗口时间。或者干脆只写串口,等故障时捕捉一下。因为低功耗设备频繁唤醒休眠,日志文件如果一直打开着,文件系统状态不一致的风险会增加,建议每次 emit 时打开、写入、关闭。
我个人最常用的是第二个配置。设备丢在现场,过两天启动异常,我拿回板子直接读日志,立刻能看到是哪一步报错,省去复现故障的时间。相比下载原厂固件要抓日志、复现场景,这个体验是天壤之别。
4.3 单条日志的完整生命周期:从调用到落盘
为了帮助你透彻理解 uLogLite 的工作机制,我把一次 log.info("sensor", "temp=%.1f", 23.5) 的完整流程走一遍:
- ULog.info 被调用,把 INFO(20)、tag="sensor"、msg="temp=%.1f"、args=(23.5,) 连同传给 log 方法。
- log 方法调用 _should_log(20, "sensor"),先检查 20 >= self.min_level(假设 min_level=INFO=20),成立;然后查 filters 字典,看 sensor 有没有单独设置级别,如果没设置,默认遵循 min_level。
- 通过检查后,进入 _format 方法。这个环节会把 "temp=%.1f" 和 (23.5,) 拼接成 "temp=23.5"。这里我没有用 str.format,而是用 % 格式化,因为 % 语法在 MicroPython 里支持得更好,也省内存。
- 生成最终文本,比如 "2024-11-15 10:30:01 [INFO] app:sensor - temp=23.5"。
- 遍历 ULog 实例的所有 handlers,把 text 交给每个 handler 的 emit 方法。
- LiteHandler 根据自己配置的目标,把 text 写到 UART 或文件。如果目标是文件,还会检查文件大小,超过 max_size 就触发轮转。
这个过程里最容易被忽略的性能瓶颈在第 5 步。如果你加了多个 handler,拉日志的性能会成比例下降。但在实际使用中,两个 handler 完全没问题,我测试过哪怕是 ESP01 这种只有 1MB flash 的小板子,两个 handler 处理 10 条日志也就在几十毫秒级别,完全可以接受。
4.4 实际代码演示:一个含轮转和过滤的完整示例
下面给一个可以直接跑起来的完整 demo。这个 demo 模拟了一个网关设备,会上报温度、检查网络、处理 OTA 升级三类任务,每种任务打日志时用不同的 tag,方便后面做过滤观察。
import time import os from machine import UART, Pin from uloglite import ULog, LiteHandler # 确保日志目录存在 try: os.mkdir("/logs") except OSError: pass # 初始化日志系统 log = ULog("gateway", ULog.DEBUG) fh = LiteHandler(file_path="/logs/gw.log", max_size=4096, backup=2) sh = LiteHandler(uart=UART(1, 115200)) log.add_handler(fh) log.add_handler(sh) # 设置按 tag 过滤:network 包比较敏感,单独开启 DEBUG log.set_filter("network", ULog.DEBUG) # battery 模块平时只报 WARNING 以上 log.set_filter("battery", ULog.WARNING) # 模拟业务逻辑 def read_temp(): # 模拟读温度传感器 return 22.5 def check_network(): # 模拟网络检测 return True def main_loop(): counter = 0 while True: counter += 1 temp = read_temp() log.info("sensor", "temp=%.1f counter=%d", temp, counter) if counter % 10 == 0: ok = check_network() if not ok: log.error("network", "link down, retry=%d", counter) else: log.debug("network", "link ok, rssi=%d", -60 + counter % 5) if counter % 30 == 0: # 模拟一次 OTA 检查 log.debug("ota", "check upgrade ...") time.sleep_ms(50) if counter % 100 == 0: log.warning("battery", "voltage low, level=%d", 15) time.sleep_ms(500) if __name__ == "__main__": main_loop()跑这个 demo 一段时间后,你会发现 sensor 的 INFO 日志很多,network 的 DEBUG 日志也能看到,battery 的 WARNING 会周期性出现,而 battery 的 INFO 如果存在会被过滤掉。日志文件轮转后,/logs 目录下会出现 gw.log、gw.log.1、gw.log.2 三个文件,最老的 gw.log.2 会被丢弃。
实际调试时,你可以在串口监控软件里观察串口 handler 的输出,同时用 mpremote 把文件拉回来看文件 handler 的内容。两个 handler 并存还有一个额外好处:串口输出实时看,文件输出留作事后分析,互不干扰。
5. 日志文件读取与后续分析:也别把排查方案想复杂了
写完日志,最终目标是能在出问题时快速分析。这里我说一个比较实用的做法:如果只是看最后几十条日志,直接用 mpremote 读文件就行:
mpremote connect /dev/ttyUSB0 run -c "print(open('/logs/gw.log','r').read())"如果轮转文件很多,可以先在板子上执行os.listdir('/logs')查看文件列表,再把需要的文件拉回本地:
mpremote connect /dev/ttyUSB0 cp :/logs/gw.log.1 ./backup_gw.log.1在本地分析时,我习惯用 Python 脚本做简单的关键词统计,比如统计 ERROR 次数、找出连续丢包事件的时间段。代码很简单,就不细写了。重点是:uLogLite 已经帮你把日志格式做得足够规范,带时间戳、带级别、带 tag,后期解析字段时用正则或 split 都能轻松处理。
如果你有更进一步的监控需求,比如实时把日志推送到某个 dashboard,完全可以再写一个 handler,把 emit 到的文本通过 MQTT 发布出去。这里需要注意网络 handler 的可靠性问题:如果网络不稳定,MQTT 日志会丢,而文件日志不会。所以我的建议是,关键日志务必先落盘,网络转发当作辅助手段。这个思路也符合嵌入式设备的直觉:本地文件是最可靠的记录,网络只是一个管道,丢了可以补。
6. 常见问题与排查技巧实录
6.1 文件写不进去或轮转时报 OSError
这个是我遇到最多的问题。现象是程序运行一会儿,突然报 OSError,日志就断了。最常见的原因有三个:
- 日志目录不存在。如果你在 open("/logs/app.log", "a") 之前没有创建 /logs 目录,打开文件直接 OSError。解决办法是用 os.mkdir 先建目录,或者直接使用根目录 /app.log。
- flash 满了。MicroPython 的文件系统通常不大,如果日志太多,写不进去很正常。检查剩余空间用
os.statvfs('/')命令查看。遇到这种情况,需要调小 max_size 或减少 backup。 - 轮转时文件句柄没关闭。这个上文已经强调过,重命名前必须先 close,否则 OSError。
排查这类问题,我一般会在 handler 的 emit 和 _rotate 方法里加 try/except,先把异常打串口出来,不让程序直接崩溃。你可以在 LiteHandler 里加一行:
try: self._rotate() except Exception as e: print("rotate failed:", e)生产环境里我也会保留这个 try/except,因为日志系统崩溃导致业务代码跟着挂掉,那代价太大了。日志嘛,尽力而为,不能喧宾夺主。
6.2 日志级别改了但没生效
这个坑常出现在全局级别和 tag 过滤同时设置时。比如你设置了 log.set_level(ULog.ERROR),又设置了 log.set_filter("sensor", ULog.DEBUG),结果 sensor 的 DEBUG 日志还是出来了。其实这不算 bug,而是设计逻辑:全局级别是所有日志必须先过的第一道门槛,如果你把它设为 ERROR,那 filter 里设 DEBUG 也没用,因为在 _should_log 里第一个判断就返回 False 了。
如果确实希望某个 tag 能突破全局级别,你需要调整 ULog 里的判断顺序。我特意把全局判断放在前面,是为了性能考虑,让大多数无关日志快速通过。但如果你有特殊需求,完全可以改代码顺序,把 filter 判断放前面。倒过来也影响不大,因为字典查询本来就很快。
还有一种情况是日志模块有多个实例。很多人会在不同文件里重复创建 ULog("app", ...),结果配置的是 instance A,实际打日志用的是 instance B,看起来就是“设置了没生效”。解决办法是统一通过一个模块级单例导出,或者直接把 log 实例放在某个共享模块里。
6.3 日志时间戳乱跳或重复
MicroPython 本身没有基于网络的实时时钟,如果板子没接外部 RTC,每次上电都是从某个默认时间开始跑。日志里的时间戳可能重复,也可能和你本地时间差 8 小时。这个不是 uLogLite 能解决的,而是硬件层的问题。
我的建议是:如果对时间精度要求高,优先使用 RTC 模块 + NTP 校时;如果只是用来分析先后顺序,单独用一个开机以来的毫秒计数(time.ticks_ms() 或 time.ticks_us())就够了。你可以在 _format 里选择使用绝对时间或相对时间。我在 uLogLite 的默认实现里用的是绝对时间字符串(通过 RTC 获取),但同时也保留了相对时间戳,方便做轻量分析。
还有一点:MicroPython 的 time.localtime() 在某些平台上返回值不一定带毫秒,所以日志时间精确到秒。如果要在同一秒内区分多条日志的顺序,我会在时间戳后面追加一个自增序号,或者使用 ticks_ms() 的增量。实战里,如果故障发生在毫秒级别,绝对时间没有太大参考价值,相对时间才是关键。
6.4 轮转文件顺序错乱
假如你设置了 backup=2,然后发现日志文件变成了 app.log、app.log.1、app.log.2,但 app.log.1 的内容比 app.log.2 新,这是正常的,因为轮转时新的当前文件会继承最大序号。很多人第一次看会犯迷糊,误以为序号越大越新。其实刚好相反:当前文件是最新的,app.log.1 是上一次的,app.log.2 是上上次的。理解了这个顺序,分析日志时就不会拿错了。
如果你想在文件名里体现新旧的直观感,可以在轮转时往文件名里加时间戳,比如 app_20241115.log,但这样每次轮转都会产生新文件名,无法用固定路径打开。权衡之下,固定路径加序号更可靠,也更容易被 mpremote 等工具访问。所以我最终选择了序号方案,只是在文档里明确说明顺序。
6.5 日志导致主循环卡顿,怎么办
你在日志输出很频繁的时候,如果发现主循环卡顿明显,那大概率是日志文件写入操作太频繁导致的。flash 写入本身比较慢,尤其是你在每次 emit 都 flush 的情况下,会严重拖慢主循环。我的建议是:不要每条都 flush,而是在一定间隔或者 buffer 满时才 flush。你可以给 LiteHandler 增加一个 buffered 参数,保留最近的 N 条日志,在满足条件时一次性写入文件。
另外,串口 handler 如果波特率设得太低(比如 9600),大量日志输出也会造成积压。建议调试时用 115200 或更高,不要为了低速设备省那点带宽把日志大量积压,那样反而容易丢日志。
我在 uLogLite 里预留了一个 emit 方法的抽象,你可以继承 LiteHandler 重写 emit,加入“批量写”逻辑。但这个一般用不到,除非业务日志量特别大。大多数场景下,保持简单的 write+flush 已经够用。
7. 关于扩展和移植的最后一点心得
uLogLite 作为一个轻量日志模块,定位就是“解决 80% 的需求,剩下 20% 让你自己折腾”。用的时候你也许会发现它没有标准库那么“高大上”,但它的优势也非常明显:代码量少、容易审计、没有黑魔法、任何一行代码都能看懂。这对嵌入式项目非常重要,因为你不希望一个日志模块成为整个系统里最复杂、最不可控的模块。
在实际部署的时候,我通常会顺带在固件里内置一个简单的“开机自检日志”功能:设备启动时,先向日志文件写入一条版本信息和启动原因。这样后期拿回设备读日志,可以第一时间知道它重启过多少次、最后一次是什么版本、卡在哪个阶段。这个习惯帮我省了不少排查时间,强烈推荐你也试试。
uLogLite 的后续扩展空间其实很大。比如远程日志、日志加密、关键日志双写冗余备份、基于日志统计自动调整轮转参数等。但这些功能不应该堆进核心模块,而是通过 handler 和子类化去扩展。我写 uLogLite 的目标是提供一个稳定、清晰、性能可预测的地基,而不是一个臃肿的框架。踩过几次坑之后,我对日志模块的信念是:功能可以少,但要稳定可靠;接口可以简单,但要能看懂、能改、能在多种板子上跑通。希望这份笔记能帮你在 MicroPython 项目里少走一些弯路。