ARTICLE · INTELLIGENCE

战地情报 · 详情页

来自尧图项目组的一线实战观察与深度解析

MicroPython轻量日志模块uLogLite:分级过滤与文件轮转实战

MicroPython轻量日志模块uLogLite:分级过滤与文件轮转实战 1. 别等代码炸了才想起日志MicroPython 项目为什么需要一套正经日志模块做 MicroPython 开发的人十有八九都有过这样的经历程序在开发板上跑得好好的一部署到现场就出幺蛾子。这时候你手头只有一个串口终端print 打了一堆东西但关键信息早就被淹没在滚动的输出里了。更扎心的是设备重启之后那些 print 输出的现场数据全没了你只能对着空气猜问题。我自己在做一个温湿度采集节点的时候就被坑过一次。设备放在室外每隔几分钟断线一次我拿着电脑蹲在设备旁边盯串口输出盯了半天发现是网络重连逻辑里一个边界条件触发了异常。当时要是有一条带时间戳、带级别、能落盘还带轮转的日志我根本不用亲自跑现场直接看日志文件就能定位。从那天起我就彻底告别了“print 走天下”的野路子开始认真折腾 MicroPython 下的日志方案。这篇博文想跟你分享的是我自己整理并实际验证过的一套轻量日志模块 uLogLite。它做的事情概括起来就三件日志分级、日志过滤、日志轮转。听起来不复杂但真正在 MicroPython 这种内存以 KB 计、Flash 写入次数有限、没有完整操作系统的环境里落地你会发现坑比想象中多得多。我会把设计思路、完整代码、参数选择和实测踩坑一次讲清楚内容适合刚入门 MicroPython 的新手也给已经写了段时间业务代码、想优化调试体验的朋友一些可直接抄作业的参考。2. 整体设计思路uLogLite 到底在解决什么问题2.1 print 不是不能用而是不够用先说个务实的结论如果你的代码总量不超过几百行跑一次就完事print 完全够用。但项目一旦进入迭代期print 的短板就非常明显了。第一print 没有级别。调试信息、正常运行的提示、警告、错误全部混在一起。代码多了以后串口输出刷屏重要错误被淹没你想从里面捞一条有用的信息眼睛都快看瞎。第二print 没有过滤能力。设备正常运行时的状态信息可能每秒钟输出好几条但只有特定条件下才会出现的调试细节你却看不到。你不能在运行中动态调整输出粒度只能改代码、重新烧录这个调试成本在嵌入式开发里是很高的。第三print 写不长久。Micropython 的设备通常没有磁盘日志只能写在 Flash 文件系统里。Flash 写入次数不是无限的而且空间也小。如果日志无节制地追加几天就能把空间写满到时候设备直接挂掉。uLogLite 的定位就是解决这三点用最小的资源开销提供分级、过滤、轮转这三个在实际项目中真正用得上的能力。它不追求完整程度不跟 CPython 的 logging 模块比功能而是把精力放在“够用”和“不拖垮设备”上。2.2 为什么选“小而精”而不是“大而全”我在一开始也想过直接把 CPython 标准库里的 logging 移植过来。但实测下来发现完整版 logging 在多数 MicroPython 板子上是跑不动的引用链太长内存占用太高还依赖了一些 MicroPython 里没有实现的特性。后来我参照了社区里一些轻量日志库的做法再结合我自己的使用习惯定了几个硬性目标纯 Python 实现不依赖任何固件特殊接口确保能在官方固件、支持 USB Host 的定制固件、各类第三方固件上跑。内存占用控制在几百字节到 2KB 左右。日志对象创建后不能随随便便吃掉一个字典对象的开销。支持级别过滤、标签过滤保证“平时安静关键时刻话多”。支持按文件大小轮转且轮转逻辑不能因为写满 Flash 而把系统整崩溃。API 尽量贴近常规日志库习惯方便从 print 迁移过来时降低心智负担。最后做出来的代码结构非常精简核心就一个类加几个辅助函数整份代码不到 150 行。但它能覆盖我在真实项目中 95% 以上的日志需求。2.3 日志模块的“为什么”硬件受限环境下的取舍逻辑有朋友问我既然 MicroPython 资源这么紧张为什么不用现成的固件级日志功能非要自己写一个这个问题问到了点子上。固件级日志功能确实存在但它属于底层系统级别普通应用层代码调用不到而且你没法随意定制输出格式和过滤规则。自己写模块核心目的就是获得“可控性”——我要往哪里写、写多细、写多满都由自己的业务需求决定而不是被底层逻辑绑架。这里面有一条很重要的取舍原则能用简单字符串比较搞定的绝不动用正则能用整数级别判断的绝不搞等级对象能延迟拼串的绝不提前把完整日志内容构造出来。这条原则贯穿了 uLogLite 整个设计过程。3. 从零实现uLogLite 核心代码与关键参数解析3.1 基础框架日志级别、格式化与输出通道先看第一版基础框架这部分负责日志级别定义、消息格式化和标准输出。我把它单独拎出来讲是因为后续的过滤逻辑和轮转逻辑都是建立在它之上的。import sys import utime import os LEVELS { DEBUG: 10, INFO: 20, WARNING: 30, ERROR: 40, CRITICAL: 50, } class ULogLite: def __init__(self, nameapp, levelINFO, fmt[{time}] [{level}] [{name}] {message}): self.name name self.level self._parse_level(level) self.fmt fmt self.handlers [] self.filters [] staticmethod def _parse_level(level): if isinstance(level, str): return LEVELS.get(level.upper(), 20) return int(level) def _format(self, level_name, message): t utime.localtime() time_str {:04d}-{:02d}-{:02d} {:02d}:{:02d}:{:02d}.format( t[0], t[1], t[2], t[3], t[4], t[5]) return self.fmt.format(timetime_str, levellevel_name, nameself.name, messagemessage) def _write(self, level_name, message): line self._format(level_name, message) for h in self.handlers: h.write(line \n)初始化里最值得留意的是level参数。它不是装饰品而是所有日志是否输出的总闸门。判断逻辑非常朴素如果当前日志级别数值小于总闸门数值直接丢弃连格式化都省了。这个顺序很重要很多新手会在先拼接字符串再判断级别白白浪费性能。在 MicroPython 的utime.localtime()返回结果里前六个元素分别对应年、月、日、时、分、秒。使用字符串的format方法时要注意一点fmt模板里的花括号字段名要和元组索引或关键字对得上我这里的写法是全部用关键字参数可读性更高。3.2 输出通道设计StreamHandler 与 FileHandler只有_write还不够总得把内容写到某个具体地方。我设计了两类 handler一个是串口或标准输出一个是文件。先看代码class StreamHandler: def __init__(self, streamNone): self.stream stream if stream is not None else sys.stdout def write(self, data): self.stream.write(data) # 串口输出建议即时 flush防止调试时数据积压 try: self.stream.flush() except AttributeError: pass class FileHandler: def __init__(self, filename, max_bytes0, backup_count0): self.filename filename self.max_bytes max_bytes self.backup_count backup_count self._check_rotation max_bytes 0 def write(self, data): try: with open(self.filename, a) as f: f.write(data) f.flush() self._maybe_rotate(f) except OSError as e: # 文件系统满了或者路径不存在至少让错误在串口可见 sys.stderr.write(Log write failed: {}\n.format(e))StreamHandler的flush是个小型保险。MicroPython 的sys.stdout在部分板子上并不保证每次写操作都立即输出不 flush 的话数据可能滞留在临时缓冲区里造成日志顺序错乱。文件写入时的flush同样重要它保证日志落盘不是“假写成功”对现场排查很关键。这里用with open而不是一次性打开文件保持句柄是深思熟虑后的决定。MicroPython 底层文件系统对长时间占用的写句柄支持不是特别完善频繁开关文件虽然有一点性能损耗但换取的是更高的稳定性和更低的掉电损坏概率。日志写入本身就是低频低量操作这种损耗完全可以接受。3.3 级别过滤与标签过滤让日志该安静时安静该啰嗦时啰嗦接下来进入过滤部分。过滤是整个模块里让我觉得最“值钱”的功能。它的核心思想很简单不是每一条日志都值得记录也不是每一个模块的日志都需要在同一粒度上输出。def set_level(self, level): self.level self._parse_level(level) def add_filter(self, tagNone, min_levelNone, max_levelNone): # 每条过滤规则可单独指定标签和级别范围 self.filters.append({ tag: tag, min_level: self._parse_level(min_level) if min_level else None, max_level: self._parse_level(max_level) if max_level else None, }) def _pass_filters(self, tag, level): if not self.filters: return True for flt in self.filters: if flt[tag] is not None and flt[tag] ! tag: continue if flt[min_level] is not None and level flt[min_level]: continue if flt[max_level] is not None and level flt[max_level]: continue return True return False def log(self, level_name, tag, message): level self._parse_level(level_name) if level self.level: return if not self._pass_filters(tag, level): return # 延迟到此刻才拼接字符串避免无效日志消耗内存 line self._format(level_name, [ tag ] message) for h in self.handlers: h.write(line \n)看到这里可能有朋友会想这跟电脑上抓包工具 fiddler 按域名过滤包是一个思路。你只想看某个域名的请求就过滤掉其他所有流量这里你只想看某个模块的调试信息就给它加一条标签规则其他模块的日志继续保持安静。概念上完全一致只不过嵌入式环境里我们得做得更省内存、更省 CPU。关于过滤条件默认支持按“标签”和“级别区间”两个维度。比如你有一个wifi模块平时只关心它报错那就可以写add_filter(tagwifi, min_levelERROR)如果某天你想排查 wifi 模块的完整连接过程临时改一下级别就行。运行中动态调整非常方便。3.4 轮转是怎么“转”起来的核心算法与参数计算日志轮转是很多人觉得玄乎的地方。其实说穿了就是三件事什么时候转、转的时候怎么处理旧文件、保留几份旧文件。我采用的方案是按文件大小轮转这是嵌入式场景下最直接也最容易控制的策略。核心逻辑如下def _file_size(self, path): try: stat os.stat(path) return stat[6] if len(stat) 6 else 0 except OSError: return 0 def _maybe_rotate(self, f): if not self._check_rotation: return size self._file_size(self.filename) if size self.max_bytes: # 先释放文件句柄再执行更名 f.flush() # 这里不能直接操作 with 块内的文件对象做更名 # 所以我们在 write 内部处理 self._rotate_files() def _rotate_files(self): # 从最老的备份开始删除避免中间缺少文件名导致链断裂 for i in range(self.backup_count - 1, 0, -1): src {}.{}.format(self.filename, i) dst {}.{}.format(self.filename, i 1) try: os.remove(dst) except OSError: pass try: os.rename(src, dst) except OSError: pass # 当前的日志文件变成 .1然后重新创建新文件 try: os.remove(self.filename .1) except OSError: pass os.rename(self.filename, self.filename .1)轮转参数max_bytes和backup_count怎么选是有点讲究的。我建议结合 Flash 剩余空间和设备预期运行时长来算。假设你的设备 Flash 剩余空间是 1MB你希望日志至少保留 7 天平均每天产生 20KB 日志那总共需要 140KB。如果给日志目录留 256KB 上限那么max_bytes * (backup_count 1)必须小于 256KB。比如max_bytes64KBbackup_count3总占用峰值就是 256KB。留一点余量实际可以设max_bytes48KBbackup_count2峰值 144KB。有人问为什么轮转要倒序删除和更名。这是因为文件系统不支持一步把.1变成.2的同时让原来的主文件变成.1你必须先腾出最旧的位置避免中途改名失败导致文件名覆盖冲突。顺序错了轮转链条就会断日志可能写进了一个已经不存在或名字混乱的文件里。3.5 完整代码串联一个可以直接用的 uLogLite 示例把上面几块组合起来再加上几个快捷方法就是一个完整可用的模块了。下面这份代码我在 ESP32-S3 和 RP2040 上都跑过直接用没问题。# uloglite.py import sys import utime import os LEVELS { DEBUG: 10, INFO: 20, WARNING: 30, ERROR: 40, CRITICAL: 50, } class StreamHandler: def __init__(self, streamNone): self.stream stream if stream is not None else sys.stdout def write(self, data): self.stream.write(data) try: self.stream.flush() except AttributeError: pass class FileHandler: def __init__(self, filename, max_bytes0, backup_count0): self.filename filename self.max_bytes max_bytes self.backup_count backup_count self._check_rotation max_bytes 0 and backup_count 0 def write(self, data): try: with open(self.filename, a) as f: f.write(data) f.flush() if self._check_rotation: self._maybe_rotate(f) except OSError: pass def _file_size(self, path): try: stat os.stat(path) return stat[6] if len(stat) 6 else 0 except OSError: return 0 def _maybe_rotate(self, f): if self._file_size(self.filename) self.max_bytes: f.flush() self._rotate_files() def _rotate_files(self): for i in range(self.backup_count - 1, 0, -1): src {}.{}.format(self.filename, i) dst {}.{}.format(self.filename, i 1) try: os.remove(dst) except OSError: pass try: os.rename(src, dst) except OSError: pass try: os.remove(self.filename .1) except OSError: pass try: os.rename(self.filename, self.filename .1) except OSError: pass class ULogLite: def __init__(self, nameapp, levelINFO, fmt[{time}] [{level}] [{name}] {message}): self.name name self.level self._parse_level(level) self.fmt fmt self.handlers [] self.filters [] staticmethod def _parse_level(level): if isinstance(level, str): return LEVELS.get(level.upper(), 20) return int(level) def add_handler(self, handler): self.handlers.append(handler) def set_level(self, level): self.level self._parse_level(level) def add_filter(self, tagNone, min_levelNone, max_levelNone): self.filters.append({ tag: tag, min_level: self._parse_level(min_level) if min_level else None, max_level: self._parse_level(max_level) if max_level else None, }) def _pass_filters(self, tag, level): if not self.filters: return True for flt in self.filters: if flt[tag] is not None and flt[tag] ! tag: continue if flt[min_level] is not None and level flt[min_level]: continue if flt[max_level] is not None and level flt[max_level]: continue return True return False def _format(self, level_name, message): t utime.localtime() time_str {:04d}-{:02d}-{:02d} {:02d}:{:02d}:{:02d}.format( t[0], t[1], t[2], t[3], t[4], t[5]) return self.fmt.format(timetime_str, levellevel_name, nameself.name, messagemessage) def log(self, level_name, tag, message): level self._parse_level(level_name) if level self.level: return if not self._pass_filters(tag, level): return line self._format(level_name, [ tag ] message) for h in self.handlers: h.write(line \n) def debug(self, tag, message): self.log(DEBUG, tag, message) def info(self, tag, message): self.log(INFO, tag, message) def warning(self, tag, message): self.log(WARNING, tag, message) def error(self, tag, message): self.log(ERROR, tag, message) def critical(self, tag, message): self.log(CRITICAL, tag, message)调用方式from uloglite import ULogLite, StreamHandler, FileHandler log ULogLite(namesensor_node, levelINFO) log.add_handler(StreamHandler()) log.add_handler(FileHandler(/flash/logs/app.log, max_bytes8192, backup_count2)) log.add_filter(tagwifi, min_levelDEBUG) log.info(main, system boot) log.debug(wifi, scan start) log.error(sensor, read timeout)运行后串口输出类似这样[2025-01-18 10:24:31] [INFO] [sensor_node] [main] system boot [2025-01-18 10:24:31] [ERROR] [sensor_node] [sensor] read timeout因为默认级别是INFO所以debug那条即使过了 wifi 标签过滤也过不了全局级别闸门。这里体现的就是两层过滤的协作关系全局级别管整体粒度标签过滤管局部细化。4. 参数怎么选几个你可能没认真想过的配置细节4.1 日志级别选择不是越低越好我见过不少人图省事把level直接设成DEBUG觉得日志越多越好。在开发阶段没问题但部署到现场之后调试日志会源源不断地写进 Flash。别小看这个消耗一天可能多写几百 KBFlash 很快就被耗尽轮转文件也随之变多系统性能肉眼可见地下降。我的建议是部署前把级别调成WARNING或ERROR保留关键错误信息。遇到要远程排查的问题时再通过某个管理指令动态把级别降到INFO或DEBUG。这个用 uLogLite 的set_level方法配合串口指令或者远程命令实现非常容易。4.2 大小阈值计算不要等到文件写满再轮转轮转阈值max_bytes不要设成跟 Flash 剩余空间一样大。文件系统在接近满的时候写入速度会变慢而且碎片化严重。我习惯的做法是轮转后的总日志占用不超过分区容量的 60% 到 70%。如果日志量大宁可缩小max_bytes或者减少backup_count也不要让 Flash 长期处于高水位运行。拿计算过程举个例子假设剩余 1MB设置max_bytes64KBbackup_count4峰值占用 320KB占比不到 1/3很安全。如果日志量特别大比如每天 100KB那只有 3 天左右的保留量这时你就得考虑换更大的 Flash、压缩日志内容或者把日志通过网络直接上报不要全部存在本地。4.3 过滤规则数量少即是多别给运行时添堵过滤规则不是越多越好。每加一条规则_pass_filters就要多跑一次循环。在 MicroPython 这种执行效率并不高的环境里日志量大的时候性能影响是实打实的。我自己的经验是过滤规则控制在 5 条以内能合并的规则尽量合并。比如两个模块都用同一套级别区间就让它们共用一个标签而不是给每个模块都单独建规则。这里顺便说一句我看到网络热词里有人聊“硬件级过滤”和“软件过滤”的区别。在嵌入式日志场景中uLogLite 的过滤本质上是软件过滤也就是消息还没格式化之前先用整数比较把它拦截掉。硬件级过滤通常指 SPI、I2C 等外设信号层面的滤波跟日志没关系。但思想是相通的越早拦截浪费越少。所以我把过滤逻辑放在字符串拼接之前就是这个原因。5. 实测踩坑记录MicroPython 日志模块最容易翻车的几个地方5.1 时间戳全是 1970 年排查现场直接懵了这个问题出现得非常高频。板子没有 RTC 电池或者 RTC 没有初始化utime.localtime()返回的是固件编译时的默认时间。日志打出来一片 1970 年根本没法用来定位问题。我的解决办法是两段式兜底如果有 RTC 或 NTP 对时功能那就让utime正常走如果设备刚开机还没联网成功就使用utime.ticks_ms()记录开机以来的毫秒数。uLogLite 里其实可以加一个time_func参数允许外部传入时间函数这样你可以在应用层决定用的是本地时间还是 uptime。示例如下log ULogLite(namenode, levelINFO, fmt[{time}] [{level}] [{name}] {message}) log.time_func lambda: [uptime {}ms].format(utime.ticks_ms())只要在_format里把utime.localtime()替换成调用self.time_func()灵活度就上来了。这个方法是我实际项目中一直在用的效果很好。5.2 目录不存在日志静默消失第一次用FileHandler的时候我在/flash/logs/app.log这个路径上直接翻车。/flash/logs/目录根本不存在open直接抛OSError。如果不在FileHandler.write里做兜底程序会当场崩溃如果做了兜底但没有提示日志就神不知鬼不觉地丢了。排查这种问题有个笨但有效的方法程序启动后先测试一下日志文件路径可写不行就在串口打一条警告。我还建议在启动时主动创建目录try: os.mkdir(/flash/logs) except OSError: pass这行代码虽然简单但能避免掉 80% 的“日志不见了”问题。另外要注意区分 MicroPython 的 flash 挂载路径官方固件一般是/flash某些定制固件可能是/或者其他路径最好用os.getcwd()确认当前工作目录。5.3 轮转文件序列错乱日志链断裂轮转逻辑最让人头疼的坑是主文件还没来得及改名为.1新的.1文件已经存在了然后覆盖关系全乱套。我的解决思路是严格按照“从最老到最新”的顺序操作先删最后一个备份再逐个把i改名成i1最后才处理当前主文件。这个顺序不能反过来否则中途断电或异常退出文件链就会断。还有一个细节是os.rename在目标已存在时的行为。MicroPython 不同版本和不同移植上行为不完全一致有的会覆盖有的会报错。这也是为什么我在_rotate_files里先执行os.remove(dst)再执行os.rename双保险。5.4 写入频繁导致 Flash 寿命堪忧有一个我早期没意识到的问题日志文件每次写入都做一次open、write、flush、close。看似没问题但如果你每条日志都往 Flash 写而设备 24 小时运行、每分钟好几条日志Flash 擦写寿命很快就消耗光了。优化思路有两个方向。第一个方向是降低直接落盘频率比如只在级别达到WARNING及以上时才立即 flush普通信息日志可以攒几秒再写一次。第二个方向是减少文件开关次数把 FileHandler 改成长驻句柄配合定期 flush。代价是掉电时可能丢最近几秒的日志。具体选哪个取决于你的设备允许多大程度的数据丢失。对我自己的项目而言我选了“错误日志立即写普通日志延迟写”的折中方案。5.5 日志内容里有特殊字符转义和截断怎么处理MicroPython 的字符串对象和 Python 3 差别不大但也有一个容易踩的坑当你的日志内容里带有花括号{}时直接丢进self.fmt.format会报KeyError或IndexError。因为format会把花括号当作替换字段处理。我一般会在传入log()之前把消息里的{和}替换成全角字符或者用str.replace先做一次简单转义。截断也是一个值得考虑的点。有些传感器返回的数据特别长整条塞进日志文件会占用大量空间。我会在 uLogLite 外面包一层业务层的truncate_msg函数超过指定长度比如 256 字节就截断并加省略标记。这个不放进模块内部是因为截断规则跟业务强相关模块保持通用比较好。6. 进阶玩法把 uLogLite 接到更多场景里6.1 串口终端日志与文件日志并存我的标准配置是同时挂两个 handler一个StreamHandler(sys.stdout)用于实时观察一个FileHandler用于落盘回看。开发调试的时候主要看串口遇到需要回溯的复杂问题就看文件。这种模式的唯一风险是日志量大的时候串口输出会拖慢系统。所以生产环境我建议StreamHandler只保留WARNING以上级别或者干脆不挂串口 handler只留文件。uLogLite 是多个 handler 并行你可以给每个 handler 单独配一套过滤条件。虽然模块内部目前没有给单 handler 配过滤但这个问题其实可以靠给不同日志级别调用不同写路径来解决或者简单一点直接不挂那位 handler需要的时候再动态装配。6.2 网络上报把日志发到远端服务器如果你有联网需求uLogLite 的 handler 机制很容易扩展出一个SocketHandler。只要实现write(data)方法把数据通过 socket 发出去就行。有了网络上报本地 Flash 就不需要保留太多日志max_bytes和backup_count可以调小主要依赖远端日志系统做长期存储和聚合分析。远程日志有一点要提醒网络不稳定时socket.send可能会阻塞。所以SocketHandler.write里一定要做超时处理不能因为日志上报把主业务卡死。6.3 与异常处理搭配记录完整的 tracebackMicroPython 里打印异常信息不能用traceback模块标准做法是sys.print_exception(exception)。用 uLogLite 时你可以这样封装try: do_something() except Exception as e: log.error(main, exception: {}.format(e))但这样看不到具体是在哪一行抛的异常。更好的办法是临时捕获异常并输出到日志文件的 handler 里import sys try: do_something() except Exception: sys.print_exception(sys.exc_info()[1])不过sys.print_exception默认打给 stderr如果你想让异常也进日志文件可以配合重定向或者在捕获里把异常对象传给str再写入。uLogLite 的 FileHandler 没有直接接管 stderr所以我一般在 catch 块里手动记录一次异常类型和参数再把sys.print_exception的内容输出到串口。这样文件里便于搜索串口里能看到堆栈。7. 小项目用不上我来说说真实的使用心得大概会有人觉得自己做的就是个几百行的采集脚本搞这套是不是杀鸡用牛刀。我在初期也这么想过但后来体会到一件事日志模块的价值不在代码行数而在系统行为的事后可复盘性。哪怕是几百行的脚本如果部署在外地设备上出了问题不能现场调试唯一能依赖的就是设备上留下的日志。我踩过几次坑之后现在所有 MicroPython 项目的骨架都是同一个套路初始化日志模块 → 设置过滤规则 → 注册退出钩子把缓冲日志强行落盘 → 业务代码只负责调用log.info或log.error。业务逻辑和日志逻辑彻底分离调试体验提升一个档次。最后再分享一个我最近在用的技巧把 uLogLite 的轮转文件作为设备健康状态的一个参考指标。如果日志文件频繁轮转说明设备日志量偏大可能有死循环或者异常重试在刷屏如果很久都不轮转说明设备可能进入了一个静默异常状态连日志都不写了。这两类情况都能通过轮转文件的修改时间和大小变化提前发现算是日志模块带给我的意外收获吧。
RELATED READING

延伸阅读

更多一线实战笔记与深度复盘,助您持续精进