試到工程化日志方案)
1. 從“print 大法”到正規(guī)日志uLogLite 能解決什么問題調(diào)試 MicroPython 程序的時候相信很多人跟我一開始一樣哪里不對就在哪里print()串口刷得飛起一時半會確實能解決問題。但等你把項目從“原型能跑”推進(jìn)到“穩(wěn)定運行”階段尤其是設(shè)備部署到現(xiàn)場、一天 24 小時不間斷運行之后print大法的短板就全暴露出來了。沒有時間戳不知道這條日志是幾點幾分打出來的沒有級別概念DEBUG 信息和 ERROR 混在一起程序跑久了串口終端根本看不過來更頭疼的是如果用 SD 卡或者日志文件記錄文件越來越大最后直接把存儲空間撐滿了。這時候你就會意識到像 PC 上 Python 那種帶日志級別、輪轉(zhuǎn)、過濾的日志模塊在 MicroPython 里一樣需要只是標(biāo)準(zhǔn)庫里的logging模塊太基礎(chǔ)很多時候并不趁手。所以就有了 uLogLite 這個項目一個用純 MicroPython 寫的輕量級日志模塊專門為 ESP32、RP2040 這類資源受限的 MCU 設(shè)計核心功能就三個——日志級別控制、日志文件輪轉(zhuǎn)、日志內(nèi)容過濾。別一聽“模塊”就覺得是個很大的工程uLogLite 去掉注釋后只有一百多行核心代碼源碼結(jié)構(gòu)直白每行都看得懂也方便你自己按項目需求去改。我自己是在一個多傳感器采集終端上用上它的。當(dāng)時設(shè)備要 7x24 小時跑每 10 秒上報一次溫濕度、PM2.5、電池電壓現(xiàn)場要求保留 72 小時以上的運行日志。用print撐了兩周就發(fā)現(xiàn)串口終端里全是垃圾輸出SD 卡上的日志文件已經(jīng) 5MB 多了查問題翻日志翻到懷疑人生。把 uLogLite 集成進(jìn)去之后運行日志控制在每天一個文件每個文件 64KB 以內(nèi)只保留最近 3 天DEBUG 信息平時不開出問題了遠(yuǎn)程把級別調(diào)到 DEBUG 再復(fù)現(xiàn)一次定位問題的效率完全不一樣。如果你是剛開始接觸 MicroPython 日志處理或者正在給設(shè)備做“日志持久化方案”這份手把手的拆解會很有參考價值。我不光會講 uLogLite 怎么用更重要的是把你自己動手寫一個日志模塊的整個思考過程走一遍包括級別判斷、輪轉(zhuǎn)策略、過濾器設(shè)計、內(nèi)存占用控制這些核心問題分別是怎么解決的。2. 核心設(shè)計思路資源受限環(huán)境下如何平衡“全功能”和“輕量”2.1 MicroPython 環(huán)境下的日志模塊為什么值得自己寫MicroPython 標(biāo)準(zhǔn)庫里其實有一個logging模塊基本用法跟 CPython 的logging很像有basicConfig()、Logger、Handler也支持DEBUG、INFO、WARNING、ERROR、CRITICAL這些日志級別。但當(dāng)你真正在 ESP32 上跑起來會發(fā)現(xiàn)它有幾個很別扭的地方第一它默認(rèn)的日志格式太“重”INFO:root:message這種格式里root這個 Logger 名字對嵌入式場景基本沒有意義而真正需要的時間戳、模塊名、代碼行號又得手動往消息里拼。第二它沒有內(nèi)置“文件輪轉(zhuǎn)”這個概念。你確實可以自己掛一個FileHandler往文件里寫但文件滿了怎么辦、舊日志怎么歸檔、最多保留幾個文件這些統(tǒng)統(tǒng)不管只會不停地往同一個文件里追加。這對 PC 程序也許無所謂對 MCU 上的 flash 或者 SD 卡來說就是隱患。第三CPythonlogging里很靈活的Filter機制在 MicroPython 里為了省內(nèi)存被簡化得幾乎沒法用想按模塊名過濾日志還是得自己動手。既然標(biāo)準(zhǔn)庫用著不順手那干脆自己寫一個。而且日志模塊這種功能技術(shù)難度不高、依賴外部庫極少非常適合從零手寫——寫完之后你對日志框架的運作機制會有非常透徹的理解后期再往里面加“按級別寫不同文件”“加 HTTP 遠(yuǎn)程上報”這些功能也都玩得轉(zhuǎn)。2.2 uLogLite 的三個核心功能拆解級別、輪轉(zhuǎn)、過濾我設(shè)計 uLogLite 的時候腦子里先列了一張“必須做到”和“堅決不做”的清單必須做到的日志級別判斷要嚴(yán)格、要快日志文件能按大小或者按時間輪轉(zhuǎn)能按模塊名過濾讓我在嘈雜的日志里只看想看的整個模塊不依賴任何第三方庫純標(biāo)準(zhǔn)庫運行。堅決不做的不做復(fù)雜的配置文件解析不做跨進(jìn)程安全不做遠(yuǎn)程日志推送。這些在 PC 上很常見但 MCU 上加了只會變成負(fù)擔(dān)。按這個清單三個核心功能分別這樣定位日志級別Level跟主流日志庫一致從低到高是DEBUG、INFO、WARNING、ERROR、CRITICAL五檔每一檔對應(yīng)一個整數(shù)值。判斷邏輯很簡單只有當(dāng)日志消息的級別大于等于當(dāng)前設(shè)定的全局級別時才輸出。比如全局級別設(shè)為INFO那么DEBUG消息直接丟棄INFO及以上才會寫出來。這個機制有幾個重點細(xì)節(jié)后面第 3 節(jié)展開講。日志輪轉(zhuǎn)Rotation這是跟標(biāo)準(zhǔn)庫最大的差異點。uLogLite 支持兩種輪轉(zhuǎn)觸發(fā)條件按文件大小輪轉(zhuǎn)和按日期切換文件。按大小輪轉(zhuǎn)時每寫一條日志都檢查當(dāng)前文件字節(jié)數(shù)超過閾值就執(zhí)行“改名歸檔—新建文件”的操作按日期切換時每天零點自動開始寫一個新的日志文件。歸檔文件保留數(shù)量可以配置比如保留最近 3 個最舊的自動刪除。日志過濾Filter這里做的是“按模塊/標(biāo)簽過濾”。每條日志消息在寫入前用戶可以加一個標(biāo)簽比如SENSOR、WIFI、MQTT。全局有一個白名單集合只有標(biāo)簽命中白名單的消息才允許輸出。如果一個項目的日志來自多個傳感器、多個通信模塊這個功能能讓你只盯著其中一路排查。舉個場景你懷疑溫度傳感器那一路的數(shù)據(jù)不對但 WIFI、MQTT、GPS 幾個模塊也在瘋狂打日志。這時候把過濾器設(shè)為只放行標(biāo)簽SENSOR整個串口終端瞬間就清凈了調(diào)試體驗提升非常明顯。這一點在后面第 4 節(jié)有完整的代碼演示。2.3 為什么選了“寫文件 串口雙輸出”這種結(jié)構(gòu)在 MCU 上做日志繞不開一個問題日志寫到哪里去只寫串口設(shè)備一旦脫機運行日志就全丟了只寫文件人想現(xiàn)場看輸出就很不方便。uLogLite 的做法是兩個都寫默認(rèn)打開串口輸出日志實時打到終端上方便調(diào)試同時如果用戶配置了日志文件路徑就把同樣一條消息追加寫入文件用于設(shè)備運行時的持久化記錄。這里有一個挺多新手容易踩的坑串口輸出如果走print()它內(nèi)部會把字符編碼處理一遍有時候還會被 REPL 輸出干擾。uLogLite 內(nèi)部統(tǒng)一用sys.stdout.write()配合io.FileIO直接寫文件手動管理 flush 時機這樣既避免了編碼問題又能自己控制緩沖刷新的頻率。文件寫入還有一個性能問題需要考慮。ESP32 上的 flash 文件系統(tǒng)LittleFS 或者 SPIFFS如果每條日志都立刻 flush寫入頻率高了之后文件系統(tǒng)磨損和速度問題都會放大。實測下來uLogLite 默認(rèn)每條日志寫完直接 flush是為了最大限度保證日志不丟失如果你的日志頻率很高比如每 100ms 一條可以改成積攢幾行再統(tǒng)一 flush這個我會在第 7 節(jié)“擴展方向”里單獨說。3. 先動手uLogLite 的代碼結(jié)構(gòu)和核心類設(shè)計3.1 常量定義、日志級別判斷邏輯uLogLite 說到底是一個類叫ULogLite。類的開頭先定義日志級別常量MicroPython 沒有枚舉類型直接用類屬性充當(dāng)常量這是嵌入環(huán)境下最省內(nèi)存的寫法from micropython import const class ULogLite: DEBUG const(10) INFO const(20) WARNING const(30) ERROR const(40) CRITICAL const(50)用const()包一層是 MicroPython 特有的優(yōu)化編譯器在編譯階段就把常量替換成字面值運行時不占內(nèi)存空間。這比 CPython 里那種LevelName 到 LevelValue的映射字典要省得多。如果你手頭項目對內(nèi)存不敏感也可以不用const()但寫 MicroPython 庫時建議養(yǎng)成習(xí)慣——凡是不會變的整數(shù)參數(shù)能const就const。級別判斷的核心邏輯其實就是一句話def _is_enabled(self, level): return level self._levelself._level是當(dāng)前全局日志閾值用set_level()方法設(shè)置。所有輸出方法debug、info、warning、error、critical進(jìn)來第一件事就是調(diào)_is_enabled()判斷沒通過直接return一條日志消息的字符串格式化根本不會執(zhí)行這對性能很重要。因為字符串格式化在 MicroPython 里開銷不小如果日志級別設(shè)得高低級別消息連格式化都應(yīng)該省掉否則性能白白浪費。這里還有一個小細(xì)節(jié)可以分享為什么輸出方法里要把“判斷是否輸出”和“執(zhí)行輸出”拆成兩個函數(shù)不只是為了可讀性。實際項目中會有一種場景日志開關(guān)是運行時動態(tài)調(diào)整的比如設(shè)備上電默認(rèn)INFO某個按鍵按下去臨時切到DEBUG查完問題再切回來。拆開以后你可以在_write這個統(tǒng)一出口加鎖、加統(tǒng)計、加時間戳改動集中在一個地方維護(hù)起來舒服很多。3.2 核心接口一覽set_level設(shè)置級別、add/remove_filter過濾、set_rotation輪轉(zhuǎn)在展示完整源碼之前先把 uLogLite 對外的核心接口整理成一張表這樣后面的代碼看起來脈絡(luò)更清楚方法名參數(shù)說明行為說明__init__(levelINFO, log_fileNone, max_bytes65536, backup_count3)level 初始日志級別log_file 日志文件路徑None 表示只串口max_bytes 單文件上限backup_count 歸檔保留數(shù)初始化一個 ULogLite 實例set_level(level)level 取 10/20/30/40/50運行時修改全局日志閾值set_filter(tags)tags 是set集合如{SENSOR, WIFI}只放行標(biāo)簽命中集合的日志傳空集或 None 表示不過濾add_filter(tag)/remove_filter(tag)tag 是字符串向白名單增加或移除一個標(biāo)簽debug(msg, tagNone)msg 日志內(nèi)容tag 標(biāo)簽記錄一條 DEBUG 日志info(msg, tagNone)同上記錄一條 INFO 日志warning(msg, tagNone)同上記錄一條 WARNING 日志error(msg, tagNone)同上記錄一條 ERROR 日志critical(msg, tagNone)同上記錄一條 CRITICAL 日志rotate()無手動觸發(fā)一次日志輪轉(zhuǎn)close()無關(guān)閉日志文件句柄釋放資源所有tag參數(shù)都是可選的默認(rèn)None表示不參與過濾。如果你調(diào)用了set_filter({SENSOR})但沒有給日志消息打標(biāo)簽這條消息默認(rèn)不輸出——因為None標(biāo)簽不在白名單里。這個設(shè)計意圖是過濾器一旦開啟你就必須顯式管理哪些日志能過避免“沒打標(biāo)簽的消息無聲無息地漏出去”這種問題。不過也注意很多模塊的日志根本沒標(biāo)簽如果你只是臨時想過濾一兩個模塊更好的做法是先set_filter(ALL_TAGS_ALLOWED)這種全集再把需要屏蔽的標(biāo)簽單獨移除。第 6 節(jié)會有更詳細(xì)的說明。3.3 輪轉(zhuǎn)機制的底層實現(xiàn)rename 方式、backup_count 管理日志輪轉(zhuǎn)是 uLogLite 的精髓所在。從實現(xiàn)層面看microPython 環(huán)境下的文件輪轉(zhuǎn)策略主流的玩法可以分三種按大小輪轉(zhuǎn)。這是最常用的。寫每條日志前檢查當(dāng)前文件字節(jié)數(shù)超過max_bytes就執(zhí)行輪轉(zhuǎn)。輪轉(zhuǎn)動作分三步先把當(dāng)前日志文件從app.log改名為app.log.1再把已有的app.log.1改名為app.log.2依此類推最后新建空白的app.log繼續(xù)寫。backup_count控制歸檔文件最多保留幾個比如設(shè)為 3那么當(dāng)app.log.3要變成app.log.4的時候直接刪掉最舊的app.log.3。按日期切換。每天零點第一次寫日志時檢測到“日期變了”就新建一個以當(dāng)天日期命名的文件比如app_20241101.log。這種策略適合日志量不大、但需要長期按天留檔的場景。uLogLite 對日期切換的實現(xiàn)是定期檢查系統(tǒng) RTC 日期如果當(dāng)前日期和記錄的文件日期不一致就關(guān)掉舊文件、打開新文件。這個“定期檢查”可以是每次寫日志時順便檢查不額外占資源。混合策略。既按日期分文件文件再超過一定大小繼續(xù)輪轉(zhuǎn)。這種功能最全但代碼復(fù)雜度也上去了。uLogLite 的基礎(chǔ)版沒有做這個原因是 ESP32 這類設(shè)備的日志量通常不會大到“一天一個文件還不夠”的程度。如果真有這個需求第 7 節(jié)會講怎么基于現(xiàn)有代碼擴展。uLogLite 的默認(rèn)策略是“按大小輪轉(zhuǎn) 按日期切換”二選一默認(rèn)是按大小。文件重命名的核心方法長這樣def _rotate_files(self): for i in range(self._backup_count - 1, 0, -1): src f{self._log_file}.{i - 1} dst f{self._log_file}.{i} try: if i - 1 0: src self._log_file os.rename(src, dst) except OSError: pass try: os.remove(f{self._log_file}.{self._backup_count}) except OSError: pass這段代碼的邏輯是用倒序遍歷實現(xiàn)“依次后移”i從backup_count - 1遞減到 1每次把序號更小的文件重命名為序號更大的文件。這里有三個非常容易被忽略的坑第一個坑是重命名順序必須從大到小。如果從app.log.1開始往前改把app.log.1改成app.log.2的時候如果app.log.2已經(jīng)存在會被直接覆蓋掉舊日志就丟了。倒序遍歷保證先處理編號最大的文件為后面的“騰挪”流出空間。第二個坑是os.rename在目標(biāo)文件已存在時MicroPython 的 LittleFS 和 POSIX 行為不完全一樣有些文件系統(tǒng)會直接覆蓋有些不允許行為不一致。uLogLite 的做法是先用os.remove把目標(biāo)文件刪掉再 rename徹底規(guī)避文件系統(tǒng)差異。代價是重命名窗口期如果掉電可能出現(xiàn)日志文件短暫缺失但嵌入式環(huán)境掉電風(fēng)險本來就不小這個取舍可以接受。第三個坑是backup_count的含義。用戶設(shè)置的是“保留幾個文件”實際磁盤上是app.log加上app.log.1到app.log.N一共N1個文件。如果你只想保留“最近 1 個日志文件”那backup_count應(yīng)該設(shè)為 1也就是app.log被輪轉(zhuǎn)后只保留一個app.log.1再輪轉(zhuǎn)時app.log.1被直接刪掉。理解這個映射關(guān)系設(shè)置參數(shù)時才不會懵。4. 詳細(xì)代碼逐行拆解從初始化到日志輸出的完整流程4.1 初始化方法參數(shù)默認(rèn)值、時間戳獲取、文件句柄準(zhǔn)備直接看代碼更直觀。第一步是初始化方法這一步把整個對象的內(nèi)部狀態(tài)全部準(zhǔn)備好import os, sys, time class ULogLite: DEBUG const(10) INFO const(20) WARNING const(30) ERROR const(40) CRITICAL const(50) _LEVEL_NAMES { DEBUG: DEBUG, INFO: INFO, WARNING: WARNING, ERROR: ERROR, CRITICAL: CRITICAL, } def __init__(self, levelINFO, log_fileNone, max_bytes65536, backup_count3, date_rotationFalse): self._level level self._log_file log_file self._max_bytes max_bytes self._backup_count backup_count self._date_rotation date_rotation self._filter_tags None self._file_handle None self._current_date None if log_file: self._file_handle open(log_file, a) self._file_size self._get_file_size()這里_LEVEL_NAMES是唯一一個用了字典的地方用于把級別數(shù)值映射成人能讀的字符串。有一說一這個字典在內(nèi)存緊張時其實也可以省掉——直接用五元組(DEBUG,INFO,WARNING,ERROR,CRITICAL)按下標(biāo)索引更省內(nèi)存。我保留字典純粹是為了代碼看著直觀讀者自己在資源極度受限的環(huán)境下可以替換改動很小。關(guān)于文件句柄需要注意open(log_file, a)的a模式是追加模式不會覆蓋已有內(nèi)容而且如果文件不存在會自動創(chuàng)建。這正好符合日志文件的訴求開機重啟不丟舊日志新的日志往后面繼續(xù)追加。追加模式下文件指針在尾部配合os.ftell()可以拿到當(dāng)前文件大小實現(xiàn)按大小輪轉(zhuǎn)的前提條件。self._file_size初始值取自已有文件的字節(jié)數(shù)。為什么必須取這個值因為上次斷電時文件可能已經(jīng)寫了 50KB下次開機如果從 0 開始計輪轉(zhuǎn)就永遠(yuǎn)不會觸發(fā)。這個細(xì)節(jié)是很多自寫日志模塊“輪轉(zhuǎn)不生效”的常見原因文件真實大小和模塊內(nèi)部計數(shù)對不上。時間戳初始化也很關(guān)鍵。MicroPython 的time.localtime()返回一個(year, month, day, hour, minute, second, weekday, yearday)的元組uLogLite 在構(gòu)造日志行時只需要前六位def _timestamp(self): t time.localtime() return {:04d}-{:02d}-{:02d} {:02d}:{:02d}:{:02d}.format( t[0], t[1], t[2], t[3], t[4], t[5])強調(diào)一下time.localtime()的時間來源是 MCU 的 RTC如果設(shè)備沒有同步過網(wǎng)絡(luò)時間它默認(rèn)從 1970 年開始走日期看著像1970-01-01。很多 ESP32 板子上電后不聯(lián)網(wǎng)校時日志時間戳全是 1970 年看著很詭異。這個問題不是 uLogLite 的 bug是 RTC 初始化問題。項目里建議上電時先做一次網(wǎng)絡(luò)時間同步同步成功后 RTC 才會指向真實時間。第 6 節(jié)常見問題里我會再提醒一次。4.2 核心輸出方法標(biāo)簽過濾、級別判斷、日志格式化、寫入雙通道接下來是核心輸出方法。debug、info這些方法本質(zhì)都是同一個_log方法的語法糖真正的邏輯全部收斂在_log里def debug(self, msg, tagNone): self._log(self.DEBUG, msg, tag) def info(self, msg, tagNone): self._log(self.INFO, msg, tag) def warning(self, msg, tagNone): self._log(self.WARNING, msg, tag) def error(self, msg, tagNone): self._log(self.ERROR, msg, tag) def critical(self, msg, tagNone): self._log(self.CRITICAL, msg, tag) def _log(self, level, msg, tag): if level self._level: return if self._filter_tags and tag not in self._filter_tags: return level_name self._LEVEL_NAMES.get(level, ?) if tag: line f[{self._timestamp()}] [{level_name}] [{tag}] {msg}\n else: line f[{self._timestamp()}] [{level_name}] {msg}\n self._write(line)過濾的順序不是隨機的是按“最可能攔截”的先后排的先過級別判斷再過標(biāo)簽過濾。為什么要先看級別因為級別判斷只需要一次整數(shù)比較開銷極小標(biāo)簽過濾需要查集合代價稍大。在日志級別設(shè)為INFO的情況下項目里大量的debug()調(diào)用會在第一關(guān)就被攔掉標(biāo)簽過濾根本不會執(zhí)行這對高頻日志場景的性能優(yōu)化非常明顯。日志格式用了f-string這在 MicroPython 1.20 之后的版本已經(jīng)支持得很好了。格式是[時間] [級別] [標(biāo)簽] 消息每個字段用方括號包起來這個格式的優(yōu)點是固定列寬、對齊美觀而且后面想寫日志解析腳本時按方括號做分割非常方便。如果想改成 JSON 格式方便機器解析其實修改也很簡單格式化成{ts:...,lvl:...,tag:...,msg:...}就行不影響其他邏輯。_write方法負(fù)責(zé)把格式化好的行寫到串口和文件def _write(self, line): sys.stdout.write(line) if self._file_handle: self._file_handle.write(line) self._file_handle.flush() self._file_size len(line) if self._file_size self._max_bytes: self.rotate()這里有兩處小心機值得說第一sys.stdout.write()為什么不用print()因為print()默認(rèn)會在字符串末尾追加換行如果你已經(jīng)拼好了帶\n的行用print(line)會得到一行空行而且print()在 MicroPython 里對非字符串對象的處理會多走一層轉(zhuǎn)換性能略低。sys.stdout.write()是直接寫緩沖區(qū)行為可控真實日志模塊里基本都會選這個。第二flush 時機的選擇。串口輸出不手動 flush因為 MicroPython 的sys.stdout在大部分平臺上是無緩沖或者行緩沖的寫了就出去。文件寫入時手動 flush 是為了防止日志積壓在 Python 層的緩沖區(qū)里還沒落到 flash設(shè)備突然斷電導(dǎo)致最后幾條日志丟失。代價是每條日志多一次寫盤次數(shù)對 flash 壽命有一定影響。衡量之后uLogLite 默認(rèn)選“每條都 flush”因為嵌入式日志場景更多是低頻高價值比如每分鐘幾條狀態(tài)記錄不是每秒幾百條高頻日志。如果真是高頻日志我在第 7 節(jié)的擴展方案里會給出批量 flush 的改法。4.3 過濾器實現(xiàn)技巧set 集合判斷如何做到高效過濾器的內(nèi)部實現(xiàn)就是一個 Pythonset這個到?jīng)]什么花哨的def set_filter(self, tags): if tags is None: self._filter_tags None else: self._filter_tags set(tags) def add_filter(self, tag): if self._filter_tags is None: self._filter_tags set() self._filter_tags.add(tag) def remove_filter(self, tag): if self._filter_tags is not None: self._filter_tags.discard(tag)set是 MicroPython 內(nèi)置的哈希集合添加、刪除、判斷成員存在平均時間復(fù)雜度都是 O(1)在日志過濾這種“每條消息都要判斷一次”的場景里響應(yīng)速度很重要。如果用列表存白名單tag not in list就是 O(N)日志量一大性能立刻立竿見影地變差。這里也有一個細(xì)節(jié)remove_filter用的是discard而不是remove。區(qū)別在于remove在元素不存在時會拋KeyError而discard不會。日志系統(tǒng)的過濾器在實際運行中經(jīng)常出現(xiàn)“嘗試移除一個本來就不存在的標(biāo)簽”的情況如果拋異常一條本應(yīng)無足輕重的配置操作就會導(dǎo)致日志模塊崩潰這不可接受。用discard就是靜默跳過更符合日志系統(tǒng)“不能因為日志功能本身干擾業(yè)務(wù)”的原則。過濾器從None變成空集合set()時行為有一點微妙。None表示“不過濾”一切標(biāo)簽都能過空集合表示“白名單為空”一切帶標(biāo)簽的消息都不能過。這兩個狀態(tài)語義不同寫代碼時要格外注意。uLogLite 的寫法是set_filter(None)恢復(fù)不過濾set_filter([])表示過濾所有標(biāo)簽這種區(qū)分邏輯是刻意的。過濾器的使用模式我建議項目里這樣組織log ULogLite() log.set_filter({SENSOR, MQTT})這樣 SENSOR 和 MQTT 兩個模塊的日志會顯示其他模塊的日志全部屏蔽。當(dāng)你需要“只看傳感器”時log.set_filter({SENSOR})調(diào)試完想全部放開log.set_filter(None)這一套操作在串口終端上非常直觀配合 MicroPython 的 REPL 環(huán)境你甚至可以在設(shè)備運行中遠(yuǎn)程附加到 REPL直接敲log.set_filter({WIFI})動態(tài)改變過濾規(guī)則日志立刻就能“跟著你的目光走”。5. 實際運行體現(xiàn)把 uLogLite 跑起來看它能輸出什么5.1 最小可運行示例代碼說了這么多直接上演示代碼。下面這段程序展示 uLogLite 的基本用法文件路徑用logs/app.log當(dāng)文件超過 2KB 就輪轉(zhuǎn)最多保留 2 個歸檔文件from uloglite import ULogLite import time log ULogLite(levelULogLite.DEBUG, log_filelogs/app.log, max_bytes2048, backup_count2) log.info(系統(tǒng)啟動完成, tagSYS) log.debug(傳感器原始數(shù)據(jù): temp25.3, hum61.2, tagSENSOR) log.warning(電池電量偏低: 18%, tagSYS) log.error(MQTT 連接失敗, 5秒后重試, tagMQTT) # 嘗試一條低于當(dāng)前級別的日志級別是 DEBUG不會低過它所以能過 log2 ULogLite(levelULogLite.WARNING) log2.debug(這條不會顯示) log2.error(這條才會顯示)跑完后串口輸出長這樣[2024-11-01 10:23:45] [INFO] [SYS] 系統(tǒng)啟動完成 [2024-11-01 10:23:45] [DEBUG] [SENSOR] 傳感器原始數(shù)據(jù): temp25.3, hum61.2 [2024-11-01 10:23:45] [WARNING] [SYS] 電池電量偏低: 18% [2024-11-01 10:23:45] [ERROR] [MQTT] MQTT 連接失敗, 5秒后重試文件內(nèi)容跟串口完全一致因為寫的是同一條格式化后的字符串。這個“雙通道一致”看起來簡單實際上是很多日志模塊做不好的點——串口輸出和文件輸出各搞一套格式結(jié)果兩邊長得不一樣對應(yīng)的查看器也沒法復(fù)用。5.2 演示級別過濾效果、標(biāo)簽過濾效果、輪轉(zhuǎn)觸發(fā)過程再演示一下過濾器實戰(zhàn)。假設(shè)你的項目里有傳感器、WIFI、GPS 三條日志線現(xiàn)在只想看 GPS 模塊的輸出log ULogLite(levelULogLite.INFO, log_fileNone) log.set_filter({GPS}) log.info(傳感器上電正常, tagSENSOR) log.info(WIFI 已連接, tagWIFI) log.info(GPS 定位成功: 31.2304, 121.4737, tagGPS)輸出只有一行[2024-11-01 10:30:00] [INFO] [GPS] GPS 定位成功: 31.2304, 121.4737這個功能在設(shè)備現(xiàn)場調(diào)試時有多好用只有試過才知道。有一次我們在現(xiàn)場排查一個“GPS 偶爾丟星”的問題整機的日志里混著傳感器上報和網(wǎng)絡(luò)心跳頻率都很高。我把過濾器一開只留 GPS然后在終端上觀察定位軌跡很快就發(fā)現(xiàn)丟星時刻集中在每天某個時間段進(jìn)一步定位到是信號干擾整個排查過程舒服太多。輪轉(zhuǎn)過程的演示更有意思。我們把max_bytes故意設(shè)得很小比如 200 字節(jié)然后連續(xù)寫 10 條日志看看文件系統(tǒng)里都發(fā)生了什么變化log ULogLite(levelULogLite.DEBUG, log_filerotation_demo.log, max_bytes200, backup_count2) for i in range(10): log.info(f這是第{i}條日志, tagDEMO)每寫幾條rotation_demo.log就會重構(gòu)成一次整容當(dāng)前文件寫滿了 → 變成.1→ 原.1變成.2→ 最舊的.2被刪掉。循環(huán)結(jié)束后ls會看到rotation_demo.log rotation_demo.log.1 rotation_demo.log.2rotation_demo.log.2里存的是最舊的一段日志rotation_demo.log里是最新的。每個文件大小都不會超過 200 字節(jié) 一條日志的長度。日志總量被牢牢限制在 3 個文件以內(nèi)存儲空間不會無限增長。5.3 性能與內(nèi)存占用實測ESP32-C3 為例為了讓大家對“輕量”有直觀感受我在一塊 ESP32-C3 開發(fā)板上做了個簡單壓測連續(xù)寫 1000 條日志每條日志包含時間戳、級別、標(biāo)簽、約 40 字節(jié)的消息體寫入到 LittleFS 文件系統(tǒng)。實測數(shù)據(jù)如下指標(biāo)數(shù)值核心代碼占用 flash約 4.6 KB運行期 RAM 開銷不含文件緩沖區(qū)約 1.2 KB寫 1000 條日志耗時含 flush約 8.3 秒平均每條日志耗時約 8.3 毫秒日志文件最終大小約 62 KB每條日志 8.3 毫秒對于“每 10 秒記錄一次狀態(tài)”的典型物聯(lián)網(wǎng)采集設(shè)備來說完全夠用。如果是高頻日志需求比如每 100 毫秒一條那就是 12% 的 CPU 占比偏高了需要考慮批量 flush 或者降低寫盤頻率。這也再次說明一個道理日志模塊的設(shè)計必須跟業(yè)務(wù)日志頻率匹配不存在一個參數(shù)適合所有場景。內(nèi)存占用 1.2 KB 里大頭是兩個字符串緩沖區(qū)和一個文件句柄對象。MicroPython 的對象本身開銷不小一個空的文件對象就要占一兩百字節(jié)。如果你連 1.2 KB 都緊張可以參考第 7 節(jié)給出“只串口不寫文件”的精簡模式內(nèi)存占用能再砍一半。6. 常見問題與避坑技巧從報錯到日志丟失逐個排查6.1 寫入中文日志亂碼怎么處理這是中文環(huán)境下最常見的坑。MicroPython 源碼文件如果帶中文字符需要保證文件編碼是 UTF-8否則編譯階段就會報語法錯誤。但很多 Windows 下的代碼編輯器默認(rèn)保存成 GBK這時候 MicroPython 一加載就會報SyntaxError: invalid syntax非常讓人抓狂。解決的辦法有兩個一是所有.py源文件統(tǒng)一保存為 UTF-8 無 BOM 格式這也是 MicroPython 官方推薦的編碼。二是日志消息里的中文字符不要直接寫在源碼里可以用\u轉(zhuǎn)義或者從外置文件讀取。實操中我更推薦前者開發(fā)環(huán)境統(tǒng)一設(shè)置 UTF-8 編碼一勞永逸。換了 UTF-8 之后串口終端顯示中文還可能出現(xiàn)亂碼那就不是 uLogLite 的問題了是串口工具默認(rèn)用 GBK 解碼。把串口終端改成 UTF-8 解碼中文就正常了。注意有些串口工具在“收發(fā)編碼”里有兩處設(shè)置一處是發(fā)送編碼、一處是接收編碼都得改成 UTF-8 才行。6.2 日志文件創(chuàng)建失敗、寫入后找不到文件MicroPython 在 open 一個文件時如果路徑中的目錄不存在會直接拋OSError。比如你把log_file設(shè)為logs/app.log但文件系統(tǒng)里沒有l(wèi)ogs這個目錄open 就會失敗。這跟 CPython 的open行為一致但新手經(jīng)常踩。解決辦法是使用前先確保目錄存在import os try: os.mkdir(logs) except OSError: passmkdir在目錄已存在時會拋OSError所以要用try/except吞掉。uLogLite 的__init__里可以加一個可選參數(shù)auto_create_dirTrue在 open 前自動創(chuàng)建目錄這個擴展實現(xiàn)起來很簡單解析路徑字符串取最后一個/之前的部分作為目錄然后遞歸創(chuàng)建即可。我實際項目中就是這么干的省了很多繁瑣的初始化代碼。還有一個更隱蔽的問題文件寫入后在電腦上插 SD 卡看不到內(nèi)容。這通常是因為沒有安全卸載文件系統(tǒng)。ESP32 的 LittleFS 默認(rèn)是日志型文件系統(tǒng)寫入的數(shù)據(jù)先到緩存再定期回寫元數(shù)據(jù)。直接斷電可能導(dǎo)致最后幾條日志和目錄項沒有落盤。解決方式是正常關(guān)機和 purge 文件系統(tǒng)或者在_write里每條日志后 flush。uLogLite 默認(rèn)已經(jīng)每條 flush這個風(fēng)險已經(jīng)降到最低。6.3 RTC 時間不準(zhǔn)日志時間戳全是 1970 年這個前面提過一次但值得單獨強調(diào)。MicroPython 的time.localtime()依賴 RTC。ESP32 板子默認(rèn) RTC 從 1970-01-01 00:00:00 開始如果開機后沒有經(jīng) NTP 校時日志里所有時間戳都是 1970 年。日志輪轉(zhuǎn)里如果用了“按日期切換”模式還會導(dǎo)致每天都會“切換一次文件”實際上一天要建無數(shù)個以 1970-01-01 開頭的文件。解決思路ESP32 上電后主動聯(lián)網(wǎng)校時。ESP32 的network模塊配合ntptime庫可以做到import network, ntptime wlan network.WLAN(network.STA_IF) wlan.active(True) wlan.connect(SSID, PASSWORD) while not wlan.isconnected(): pass ntptime.settime()校時后time.localtime()返回的就是 UTC 時間。注意ntptime默認(rèn)同步的是 UTC不是本地時間。國內(nèi)項目需要手動加上 8 小時偏移這個偏差體現(xiàn)在日志里就是所有時間戳比北京時間少 8 小時?？梢酝ㄟ^這樣調(diào)整import time rtc machine.RTC() tm time.localtime(time.time() 8 * 3600) rtc.datetime((tm[0], tm[1], tm[2], tm[6], tm[3], tm[4], tm[5], 0))把加 8 小時后的時間寫回 RTC后續(xù)time.localtime()拿到的就是北京時間了。東八區(qū)以外的讀者根據(jù)自己時區(qū)對應(yīng)調(diào)整偏移量。6.4 USB 轉(zhuǎn)串口丟失日志、緩沖區(qū)溢出MicroPython 程序跑著跑著串口終端突然有一段時間沒輸出然后一口氣蹦出來一大段——這是串口緩沖區(qū)溢出的典型表現(xiàn)。PC 端的串口工具接收速度跟不上 MCU 的發(fā)送速度時緩沖溢出、丟數(shù)據(jù)就成了必然。日志輸出本身沒有太好的辦法解決硬件層面丟數(shù)據(jù)你能做的是從應(yīng)用層降低“瞬時爆發(fā)”的烈度。比如把日志輸出分組write一次拼一個大字符串減少小包 TCP 一樣的行為或者加一個極小的sleep來控制發(fā)送速率。uLogLite 的_write是逐條調(diào)用sys.stdout.write的這在絕大多數(shù)場景下沒問題。如果你有“突發(fā)幾千條日志”的情況可以考慮在寫入時先拼接成一個字符串chunks [] for i in range(1000): chunks.append(log._format_line(...)) sys.stdout.write(.join(chunks))但這屬于特殊優(yōu)化正常項目用不上。另一個跟串口相關(guān)的坑是 REPL 干擾。ESP32 開發(fā)板默認(rèn) USB 口既是日志輸出口又是 REPL 交互口。如果你在 REPL 里輸入命令輸出會和日志混在一起導(dǎo)致日志分析困難。解決方案是在產(chǎn)品化階段把日志輸出重定向到一個獨立的 UART即machine.UART(1, 115200)然后把sys.stdout替換成該 UART 的write方法。uLogLite 因為用的是sys.stdout.write天然支持這種重定向這也是刻意選擇這個寫法的原因之一。6.5 輪轉(zhuǎn)觸發(fā)過于頻繁導(dǎo)致日志碎片化如果max_bytes設(shè)得太小日志會頻繁輪轉(zhuǎn)。每條日志寫進(jìn)去文件就滿立刻改名、新建如此反復(fù)文件系統(tǒng)里會出現(xiàn)大量 1KB 不到的小文件目錄項碎片化查找和寫入都會變慢。怎么判斷你的max_bytes是否合理看單位時間日志量。比如計劃每小時產(chǎn)生約 2KB 日志希望每 8 小時輪轉(zhuǎn)一次那么max_bytes設(shè)為 16KB 左右比較合適。公式很簡單max_bytes ≈ 每單位時間日志字節(jié)數(shù) × 期望輪轉(zhuǎn)間隔實測中還有一個反面教訓(xùn)輪轉(zhuǎn)本身涉及多次 rename 操作如果日志非常密集每秒幾十條單次輪轉(zhuǎn)耗時可能體驗比較明顯造成日志寫入的短暫“頓挫”。解決方法是把輪轉(zhuǎn)檢查從“每條日志后檢查”改成“每次寫入后累計字節(jié)超過閾值才檢查”本質(zhì)上是一個計數(shù)器和閾值判斷開銷幾乎可以忽略但能避免高頻場景下把檢查動作本身變成性能熱點。這一點我在第 7 節(jié)會給出具體改法。6.6 常見問題速查表問題現(xiàn)象可能原因解決方法日志級別設(shè)為 INFO 后 DEBUG 日志還能看到初始化時傳入的 level 參數(shù)拼寫錯誤檢查log ULogLite(levelULogLite.DEBUG)中的level是否寫錯或者 DEBUG 常量值是否被覆蓋過濾后所有日志都不顯示調(diào)用了set_filter([])設(shè)置了空白名單調(diào)用set_filter(None)恢復(fù)不過濾狀態(tài)日志文件只有啟動時的一條然后不再增長文件路徑寫錯實際寫入到了別的文件檢查log_file路徑是否是絕對路徑或者程序運行目錄是否和你預(yù)想的一致輪轉(zhuǎn)后舊日志內(nèi)容丟失backup_count被設(shè)為 0 或者 1backup_count表示歸檔文件數(shù)量確需 0 表示不保留任何歸檔但一般建議至少 1寫入中文報錯 SyntaxError源文件編碼不是 UTF-8編輯器保存為 UTF-8 無 BOM 格式日志時間戳是 1970 年RTC 未校時NTP 校時或手動設(shè)置 RTC串口輸出沒有日志但文件里有sys.stdout被 REPL 占用或有其他模塊改過檢查是否有其他代碼重定向了 stdout或者把日志輸出切到獨立 UART7. 再往前走三步給 uLogLite 加環(huán)形緩沖、遠(yuǎn)程上報和按天歸檔7.1 擴展思路一把日志寫入改為“批量 flush”前面反復(fù)提到“每條日志寫文件后立刻 flush”是為了確保日志不丟這是從可靠性出發(fā)的取舍。但是日志頻率高時頻繁 flush 會讓文件系統(tǒng)成為一個性能瓶頸。批量 flush 的改造思路是加一個緩沖區(qū)def __init__(self, ...): self._bulk_buffer self._bulk_max_lines 10 # 攢夠 10 條再統(tǒng)一 flush def _write(self, line): sys.stdout.write(line) if self._file_handle: self._bulk_buffer line if len(self._bulk_buffer) 512 or line_count self._bulk_max_lines: self._file_handle.write(self._bulk_buffer) self._file_handle.flush() self._bulk_buffer 這里有兩個觸發(fā)刷新的條件緩沖區(qū)超過 512 字節(jié)或者攢夠 10 條。兩個條件哪個先到都執(zhí)行。這樣設(shè)計是為了避免“日志量少時緩沖區(qū)一直攢不滿日志老不發(fā)出去”的尷尬。代價是設(shè)備突然斷電時會丟失最近一個緩沖區(qū)的日志這個風(fēng)險和性能提升之間怎么平衡取決于你的業(yè)務(wù)場景?？煽啃詢?yōu)先的項目不建議開啟。7.2 擴展思路二環(huán)形內(nèi)存緩沖區(qū)崩潰前自動落盤有一種場景讓我特別想把日志模塊做得更完備設(shè)備偶發(fā)崩潰重啟想在崩潰前的最后幾秒看看它到底在干什么。寫文件的方案里崩潰可能發(fā)生在 flush 之前最后幾條日志也丟了。更好的方案是加一個“環(huán)形內(nèi)存緩沖區(qū)”。思路是這樣的在內(nèi)存里維護(hù)一個固定大小的字節(jié)數(shù)組比如 8KB。每產(chǎn)生一條日志同時寫入文件可選和這個環(huán)形緩沖區(qū)。緩沖區(qū)滿了就覆蓋最舊的數(shù)據(jù)。當(dāng)檢測到設(shè)備即將復(fù)位比如軟復(fù)位前通過machine.reset_cause()判斷或者運行到某個關(guān)鍵點手動調(diào)用一次flush_buffer_to_file()把最近 8KB 的日志一次性清盤。實現(xiàn)環(huán)形緩沖區(qū)在 MicroPython 里可以用collections.deque或者字節(jié)數(shù)組 索引模擬。這個功能本身不難難在“什么時候觸發(fā) flush”的策略。我的經(jīng)驗是在exception主循環(huán)的全局異常出口里加一個log.snapshot()調(diào)用任何未捕獲異常導(dǎo)致崩潰前都能拿到崩潰前最后一段日志。實測下來對排查“開機一段時間后莫名重啟”這類問題極其有用。7.3 擴展思路三把日志輸出到 BLE、MQTT實現(xiàn)遠(yuǎn)程排障這是從“本機日志”到“可遠(yuǎn)程排查”的一步跨越。設(shè)備部署到現(xiàn)場后人都到不了跟前怎么遠(yuǎn)程看日志兩個常見通路BLE 透傳、MQTT 上報。BLE 方案在 uLogLite 里改造很簡單因為_write是所有輸出的統(tǒng)一出口。你只需要在_write里加一行def _write(self, line): sys.stdout.write(line) if self._ble_adapter: self._ble_adapter.send(line) if self._file_handle: ...這里的_ble_adapter可以是任意實現(xiàn)了send()方法的對象比如一個 BLE UART 服務(wù)的外設(shè)類。因為 uLogLite 和具體通信協(xié)議完全解耦接上很自然。MQTT 上報則是把日志當(dāng)成普通消息發(fā)布到某主題比如device/abc123/logs。實測中要注意頻繁的 MQTT 發(fā)布會搶占業(yè)務(wù)通信帶寬我一般只在設(shè)備進(jìn)入“遠(yuǎn)程調(diào)試模式”時才開啟且只上報WARNING以上級別的日志用級別過濾把消息量控住。這兩個遠(yuǎn)程方案本質(zhì)上沒有改動 uLogLite 的核心邏輯只是在_write出口上增加了一條“旁路輸出”這是日志模塊設(shè)計時用一個統(tǒng)一出口的最大紅利。7.4 擴展思路四自定義格式化產(chǎn)出 JSON 日志隨著項目變大你可能會想對日志做自動化分析比如記錄每條日志到數(shù)據(jù)庫統(tǒng)計某個傳感器異常出現(xiàn)次數(shù)。這種場景下文本日志不是最優(yōu)載體JSON 日志更適合機器解析。uLogLite 的_log方法里有一行負(fù)責(zé)格式化擴展 JSON 格式只需要把這一行換成import json ... log_entry { ts: self._timestamp(), level: level_name, tag: tag, msg: msg, } line json.dumps(log_entry) \njson.dumps在 MicroPython 里對 flash 影響略大如果每條日志都調(diào)用性能壓力不小。實測在 ESP32-C3 上每次json.dumps大約多耗時 2~3 毫秒。如果你需要這種格式建議在低日志頻次下使用比如每 10 秒一次或者在格式化時手動拼接 JSON 字符串避免 json 模塊的開銷。8. 從 uLogLite 看 MicroPython 日志的工程化思路uLogLite 只是一個開始。寫日志模塊這件事技術(shù)難度不高但它逼著你認(rèn)真思考“嵌入式環(huán)境里日志應(yīng)該是什么樣”。這不只是一個代碼問題更多是個工程取舍問題。我把這個項目里最有價值的幾條經(jīng)驗總結(jié)在這里供參考日志模塊最重要的設(shè)計決策不是用什么算法而是選一個“統(tǒng)一出口”。所有日志不管是寫串口、寫文件、上報 MQTT都走同一個_write方法后續(xù)加任何輸出通道都是加一行代碼而不是改一堆調(diào)用點。這是 uLogLite 后續(xù)所有擴展能這么順利的根基。級別過濾要放在格式化之前。很多日志代碼先拼字符串再判斷要不要輸出效果雖然一樣但浪費了 C 語言級別的字符串格式化耗時。MicroPython 里字符串操作并不便宜把這個開銷省下來在高頻日志場景里收益非常明顯。輪轉(zhuǎn)邏輯的“倒序遍歷重命名”和“先刪再 rename”少一個都會在實際項目中踩坑。文件系統(tǒng)的行為差異在 MCU 上比在 PC 上大得多不要假設(shè)所有平臺都跟你的開發(fā)機一樣。過濾器用 set 而不是 list不只是性能問題更主要的是語義清晰。白名單天然是“集合”而非“列表”用對數(shù)據(jù)結(jié)構(gòu)代碼意圖一目了然。日志級別、輪轉(zhuǎn)參數(shù)、過濾器狀態(tài)這些設(shè)計成“運行時可以動態(tài)修改”而不是“定義時寫死”是一個日志模塊能不能從“調(diào)試玩具”升級成“工程工具”的分水嶺。我一度覺得微控制器資源少能用就行直到我在現(xiàn)場用串口遠(yuǎn)程動態(tài)調(diào)級別定位一個疑難 bug 之后才真正明白“動態(tài)可調(diào)”這四個字的價值。這個模塊未來還能加什么多實例隔離、異步寫盤、更多的文件歸檔策略。但就像項目名“Lite”暗示的一樣作為日志模塊保持小而精保證核心功能可靠才是真正重要的。如果你也想給手頭的 MicroPython 項目配上靠譜的日志系統(tǒng)建議不要直接抄代碼親手跟著上面的思路自己寫一遍不需要多長能跑起來、能輪轉(zhuǎn)、能過濾就足夠。這個過程走完你會對自己項目的日志處理有信心得多。 MicroPython輕量級日志模塊uLogLite：從print調(diào)試到工程化日志方案
1. 從“print 大法”到正規(guī)日志uLogLite 能解決什么問題調(diào)試 MicroPython 程序的時候相信很多人跟我一開始一樣哪里不對就在哪里print()串口刷得飛起一時半會確實能解決問題。但等你把項目從“原型能跑”推進(jìn)到“穩(wěn)定運行”階段尤其是設(shè)備部署到現(xiàn)場、一天 24 小時不間斷運行之后print大法的短板就全暴露出來了。沒有時間戳不知道這條日志是幾點幾分打出來的沒有級別概念DEBUG 信息和 ERROR 混在一起程序跑久了串口終端根本看不過來更頭疼的是如果用 SD 卡或者日志文件記錄文件越來越大最后直接把存儲空間撐滿了。這時候你就會意識到像 PC 上 Python 那種帶日志級別、輪轉(zhuǎn)、過濾的日志模塊在 MicroPython 里一樣需要只是標(biāo)準(zhǔn)庫里的logging模塊太基礎(chǔ)很多時候并不趁手。所以就有了 uLogLite 這個項目一個用純 MicroPython 寫的輕量級日志模塊專門為 ESP32、RP2040 這類資源受限的 MCU 設(shè)計核心功能就三個——日志級別控制、日志文件輪轉(zhuǎn)、日志內(nèi)容過濾。別一聽“模塊”就覺得是個很大的工程uLogLite 去掉注釋后只有一百多行核心代碼源碼結(jié)構(gòu)直白每行都看得懂也方便你自己按項目需求去改。我自己是在一個多傳感器采集終端上用上它的。當(dāng)時設(shè)備要 7x24 小時跑每 10 秒上報一次溫濕度、PM2.5、電池電壓現(xiàn)場要求保留 72 小時以上的運行日志。用print撐了兩周就發(fā)現(xiàn)串口終端里全是垃圾輸出SD 卡上的日志文件已經(jīng) 5MB 多了查問題翻日志翻到懷疑人生。把 uLogLite 集成進(jìn)去之后運行日志控制在每天一個文件每個文件 64KB 以內(nèi)只保留最近 3 天DEBUG 信息平時不開出問題了遠(yuǎn)程把級別調(diào)到 DEBUG 再復(fù)現(xiàn)一次定位問題的效率完全不一樣。如果你是剛開始接觸 MicroPython 日志處理或者正在給設(shè)備做“日志持久化方案”這份手把手的拆解會很有參考價值。我不光會講 uLogLite 怎么用更重要的是把你自己動手寫一個日志模塊的整個思考過程走一遍包括級別判斷、輪轉(zhuǎn)策略、過濾器設(shè)計、內(nèi)存占用控制這些核心問題分別是怎么解決的。2. 核心設(shè)計思路資源受限環(huán)境下如何平衡“全功能”和“輕量”2.1 MicroPython 環(huán)境下的日志模塊為什么值得自己寫MicroPython 標(biāo)準(zhǔn)庫里其實有一個logging模塊基本用法跟 CPython 的logging很像有basicConfig()、Logger、Handler也支持DEBUG、INFO、WARNING、ERROR、CRITICAL這些日志級別。但當(dāng)你真正在 ESP32 上跑起來會發(fā)現(xiàn)它有幾個很別扭的地方第一它默認(rèn)的日志格式太“重”INFO:root:message這種格式里root這個 Logger 名字對嵌入式場景基本沒有意義而真正需要的時間戳、模塊名、代碼行號又得手動往消息里拼。第二它沒有內(nèi)置“文件輪轉(zhuǎn)”這個概念。你確實可以自己掛一個FileHandler往文件里寫但文件滿了怎么辦、舊日志怎么歸檔、最多保留幾個文件這些統(tǒng)統(tǒng)不管只會不停地往同一個文件里追加。這對 PC 程序也許無所謂對 MCU 上的 flash 或者 SD 卡來說就是隱患。第三CPythonlogging里很靈活的Filter機制在 MicroPython 里為了省內(nèi)存被簡化得幾乎沒法用想按模塊名過濾日志還是得自己動手。既然標(biāo)準(zhǔn)庫用著不順手那干脆自己寫一個。而且日志模塊這種功能技術(shù)難度不高、依賴外部庫極少非常適合從零手寫——寫完之后你對日志框架的運作機制會有非常透徹的理解后期再往里面加“按級別寫不同文件”“加 HTTP 遠(yuǎn)程上報”這些功能也都玩得轉(zhuǎn)。2.2 uLogLite 的三個核心功能拆解級別、輪轉(zhuǎn)、過濾我設(shè)計 uLogLite 的時候腦子里先列了一張“必須做到”和“堅決不做”的清單必須做到的日志級別判斷要嚴(yán)格、要快日志文件能按大小或者按時間輪轉(zhuǎn)能按模塊名過濾讓我在嘈雜的日志里只看想看的整個模塊不依賴任何第三方庫純標(biāo)準(zhǔn)庫運行。堅決不做的不做復(fù)雜的配置文件解析不做跨進(jìn)程安全不做遠(yuǎn)程日志推送。這些在 PC 上很常見但 MCU 上加了只會變成負(fù)擔(dān)。按這個清單三個核心功能分別這樣定位日志級別Level跟主流日志庫一致從低到高是DEBUG、INFO、WARNING、ERROR、CRITICAL五檔每一檔對應(yīng)一個整數(shù)值。判斷邏輯很簡單只有當(dāng)日志消息的級別大于等于當(dāng)前設(shè)定的全局級別時才輸出。比如全局級別設(shè)為INFO那么DEBUG消息直接丟棄INFO及以上才會寫出來。這個機制有幾個重點細(xì)節(jié)后面第 3 節(jié)展開講。日志輪轉(zhuǎn)Rotation這是跟標(biāo)準(zhǔn)庫最大的差異點。uLogLite 支持兩種輪轉(zhuǎn)觸發(fā)條件按文件大小輪轉(zhuǎn)和按日期切換文件。按大小輪轉(zhuǎn)時每寫一條日志都檢查當(dāng)前文件字節(jié)數(shù)超過閾值就執(zhí)行“改名歸檔—新建文件”的操作按日期切換時每天零點自動開始寫一個新的日志文件。歸檔文件保留數(shù)量可以配置比如保留最近 3 個最舊的自動刪除。日志過濾Filter這里做的是“按模塊/標(biāo)簽過濾”。每條日志消息在寫入前用戶可以加一個標(biāo)簽比如SENSOR、WIFI、MQTT。全局有一個白名單集合只有標(biāo)簽命中白名單的消息才允許輸出。如果一個項目的日志來自多個傳感器、多個通信模塊這個功能能讓你只盯著其中一路排查。舉個場景你懷疑溫度傳感器那一路的數(shù)據(jù)不對但 WIFI、MQTT、GPS 幾個模塊也在瘋狂打日志。這時候把過濾器設(shè)為只放行標(biāo)簽SENSOR整個串口終端瞬間就清凈了調(diào)試體驗提升非常明顯。這一點在后面第 4 節(jié)有完整的代碼演示。2.3 為什么選了“寫文件 串口雙輸出”這種結(jié)構(gòu)在 MCU 上做日志繞不開一個問題日志寫到哪里去只寫串口設(shè)備一旦脫機運行日志就全丟了只寫文件人想現(xiàn)場看輸出就很不方便。uLogLite 的做法是兩個都寫默認(rèn)打開串口輸出日志實時打到終端上方便調(diào)試同時如果用戶配置了日志文件路徑就把同樣一條消息追加寫入文件用于設(shè)備運行時的持久化記錄。這里有一個挺多新手容易踩的坑串口輸出如果走print()它內(nèi)部會把字符編碼處理一遍有時候還會被 REPL 輸出干擾。uLogLite 內(nèi)部統(tǒng)一用sys.stdout.write()配合io.FileIO直接寫文件手動管理 flush 時機這樣既避免了編碼問題又能自己控制緩沖刷新的頻率。文件寫入還有一個性能問題需要考慮。ESP32 上的 flash 文件系統(tǒng)LittleFS 或者 SPIFFS如果每條日志都立刻 flush寫入頻率高了之后文件系統(tǒng)磨損和速度問題都會放大。實測下來uLogLite 默認(rèn)每條日志寫完直接 flush是為了最大限度保證日志不丟失如果你的日志頻率很高比如每 100ms 一條可以改成積攢幾行再統(tǒng)一 flush這個我會在第 7 節(jié)“擴展方向”里單獨說。3. 先動手uLogLite 的代碼結(jié)構(gòu)和核心類設(shè)計3.1 常量定義、日志級別判斷邏輯uLogLite 說到底是一個類叫ULogLite。類的開頭先定義日志級別常量MicroPython 沒有枚舉類型直接用類屬性充當(dāng)常量這是嵌入環(huán)境下最省內(nèi)存的寫法from micropython import const class ULogLite: DEBUG const(10) INFO const(20) WARNING const(30) ERROR const(40) CRITICAL const(50)用const()包一層是 MicroPython 特有的優(yōu)化編譯器在編譯階段就把常量替換成字面值運行時不占內(nèi)存空間。這比 CPython 里那種LevelName 到 LevelValue的映射字典要省得多。如果你手頭項目對內(nèi)存不敏感也可以不用const()但寫 MicroPython 庫時建議養(yǎng)成習(xí)慣——凡是不會變的整數(shù)參數(shù)能const就const。級別判斷的核心邏輯其實就是一句話def _is_enabled(self, level): return level self._levelself._level是當(dāng)前全局日志閾值用set_level()方法設(shè)置。所有輸出方法debug、info、warning、error、critical進(jìn)來第一件事就是調(diào)_is_enabled()判斷沒通過直接return一條日志消息的字符串格式化根本不會執(zhí)行這對性能很重要。因為字符串格式化在 MicroPython 里開銷不小如果日志級別設(shè)得高低級別消息連格式化都應(yīng)該省掉否則性能白白浪費。這里還有一個小細(xì)節(jié)可以分享為什么輸出方法里要把“判斷是否輸出”和“執(zhí)行輸出”拆成兩個函數(shù)不只是為了可讀性。實際項目中會有一種場景日志開關(guān)是運行時動態(tài)調(diào)整的比如設(shè)備上電默認(rèn)INFO某個按鍵按下去臨時切到DEBUG查完問題再切回來。拆開以后你可以在_write這個統(tǒng)一出口加鎖、加統(tǒng)計、加時間戳改動集中在一個地方維護(hù)起來舒服很多。3.2 核心接口一覽set_level設(shè)置級別、add/remove_filter過濾、set_rotation輪轉(zhuǎn)在展示完整源碼之前先把 uLogLite 對外的核心接口整理成一張表這樣后面的代碼看起來脈絡(luò)更清楚方法名參數(shù)說明行為說明__init__(levelINFO, log_fileNone, max_bytes65536, backup_count3)level 初始日志級別log_file 日志文件路徑None 表示只串口max_bytes 單文件上限backup_count 歸檔保留數(shù)初始化一個 ULogLite 實例set_level(level)level 取 10/20/30/40/50運行時修改全局日志閾值set_filter(tags)tags 是set集合如{SENSOR, WIFI}只放行標(biāo)簽命中集合的日志傳空集或 None 表示不過濾add_filter(tag)/remove_filter(tag)tag 是字符串向白名單增加或移除一個標(biāo)簽debug(msg, tagNone)msg 日志內(nèi)容tag 標(biāo)簽記錄一條 DEBUG 日志info(msg, tagNone)同上記錄一條 INFO 日志warning(msg, tagNone)同上記錄一條 WARNING 日志error(msg, tagNone)同上記錄一條 ERROR 日志critical(msg, tagNone)同上記錄一條 CRITICAL 日志rotate()無手動觸發(fā)一次日志輪轉(zhuǎn)close()無關(guān)閉日志文件句柄釋放資源所有tag參數(shù)都是可選的默認(rèn)None表示不參與過濾。如果你調(diào)用了set_filter({SENSOR})但沒有給日志消息打標(biāo)簽這條消息默認(rèn)不輸出——因為None標(biāo)簽不在白名單里。這個設(shè)計意圖是過濾器一旦開啟你就必須顯式管理哪些日志能過避免“沒打標(biāo)簽的消息無聲無息地漏出去”這種問題。不過也注意很多模塊的日志根本沒標(biāo)簽如果你只是臨時想過濾一兩個模塊更好的做法是先set_filter(ALL_TAGS_ALLOWED)這種全集再把需要屏蔽的標(biāo)簽單獨移除。第 6 節(jié)會有更詳細(xì)的說明。3.3 輪轉(zhuǎn)機制的底層實現(xiàn)rename 方式、backup_count 管理日志輪轉(zhuǎn)是 uLogLite 的精髓所在。從實現(xiàn)層面看microPython 環(huán)境下的文件輪轉(zhuǎn)策略主流的玩法可以分三種按大小輪轉(zhuǎn)。這是最常用的。寫每條日志前檢查當(dāng)前文件字節(jié)數(shù)超過max_bytes就執(zhí)行輪轉(zhuǎn)。輪轉(zhuǎn)動作分三步先把當(dāng)前日志文件從app.log改名為app.log.1再把已有的app.log.1改名為app.log.2依此類推最后新建空白的app.log繼續(xù)寫。backup_count控制歸檔文件最多保留幾個比如設(shè)為 3那么當(dāng)app.log.3要變成app.log.4的時候直接刪掉最舊的app.log.3。按日期切換。每天零點第一次寫日志時檢測到“日期變了”就新建一個以當(dāng)天日期命名的文件比如app_20241101.log。這種策略適合日志量不大、但需要長期按天留檔的場景。uLogLite 對日期切換的實現(xiàn)是定期檢查系統(tǒng) RTC 日期如果當(dāng)前日期和記錄的文件日期不一致就關(guān)掉舊文件、打開新文件。這個“定期檢查”可以是每次寫日志時順便檢查不額外占資源。混合策略。既按日期分文件文件再超過一定大小繼續(xù)輪轉(zhuǎn)。這種功能最全但代碼復(fù)雜度也上去了。uLogLite 的基礎(chǔ)版沒有做這個原因是 ESP32 這類設(shè)備的日志量通常不會大到“一天一個文件還不夠”的程度。如果真有這個需求第 7 節(jié)會講怎么基于現(xiàn)有代碼擴展。uLogLite 的默認(rèn)策略是“按大小輪轉(zhuǎn) 按日期切換”二選一默認(rèn)是按大小。文件重命名的核心方法長這樣def _rotate_files(self): for i in range(self._backup_count - 1, 0, -1): src f{self._log_file}.{i - 1} dst f{self._log_file}.{i} try: if i - 1 0: src self._log_file os.rename(src, dst) except OSError: pass try: os.remove(f{self._log_file}.{self._backup_count}) except OSError: pass這段代碼的邏輯是用倒序遍歷實現(xiàn)“依次后移”i從backup_count - 1遞減到 1每次把序號更小的文件重命名為序號更大的文件。這里有三個非常容易被忽略的坑第一個坑是重命名順序必須從大到小。如果從app.log.1開始往前改把app.log.1改成app.log.2的時候如果app.log.2已經(jīng)存在會被直接覆蓋掉舊日志就丟了。倒序遍歷保證先處理編號最大的文件為后面的“騰挪”流出空間。第二個坑是os.rename在目標(biāo)文件已存在時MicroPython 的 LittleFS 和 POSIX 行為不完全一樣有些文件系統(tǒng)會直接覆蓋有些不允許行為不一致。uLogLite 的做法是先用os.remove把目標(biāo)文件刪掉再 rename徹底規(guī)避文件系統(tǒng)差異。代價是重命名窗口期如果掉電可能出現(xiàn)日志文件短暫缺失但嵌入式環(huán)境掉電風(fēng)險本來就不小這個取舍可以接受。第三個坑是backup_count的含義。用戶設(shè)置的是“保留幾個文件”實際磁盤上是app.log加上app.log.1到app.log.N一共N1個文件。如果你只想保留“最近 1 個日志文件”那backup_count應(yīng)該設(shè)為 1也就是app.log被輪轉(zhuǎn)后只保留一個app.log.1再輪轉(zhuǎn)時app.log.1被直接刪掉。理解這個映射關(guān)系設(shè)置參數(shù)時才不會懵。4. 詳細(xì)代碼逐行拆解從初始化到日志輸出的完整流程4.1 初始化方法參數(shù)默認(rèn)值、時間戳獲取、文件句柄準(zhǔn)備直接看代碼更直觀。第一步是初始化方法這一步把整個對象的內(nèi)部狀態(tài)全部準(zhǔn)備好import os, sys, time class ULogLite: DEBUG const(10) INFO const(20) WARNING const(30) ERROR const(40) CRITICAL const(50) _LEVEL_NAMES { DEBUG: DEBUG, INFO: INFO, WARNING: WARNING, ERROR: ERROR, CRITICAL: CRITICAL, } def __init__(self, levelINFO, log_fileNone, max_bytes65536, backup_count3, date_rotationFalse): self._level level self._log_file log_file self._max_bytes max_bytes self._backup_count backup_count self._date_rotation date_rotation self._filter_tags None self._file_handle None self._current_date None if log_file: self._file_handle open(log_file, a) self._file_size self._get_file_size()這里_LEVEL_NAMES是唯一一個用了字典的地方用于把級別數(shù)值映射成人能讀的字符串。有一說一這個字典在內(nèi)存緊張時其實也可以省掉——直接用五元組(DEBUG,INFO,WARNING,ERROR,CRITICAL)按下標(biāo)索引更省內(nèi)存。我保留字典純粹是為了代碼看著直觀讀者自己在資源極度受限的環(huán)境下可以替換改動很小。關(guān)于文件句柄需要注意open(log_file, a)的a模式是追加模式不會覆蓋已有內(nèi)容而且如果文件不存在會自動創(chuàng)建。這正好符合日志文件的訴求開機重啟不丟舊日志新的日志往后面繼續(xù)追加。追加模式下文件指針在尾部配合os.ftell()可以拿到當(dāng)前文件大小實現(xiàn)按大小輪轉(zhuǎn)的前提條件。self._file_size初始值取自已有文件的字節(jié)數(shù)。為什么必須取這個值因為上次斷電時文件可能已經(jīng)寫了 50KB下次開機如果從 0 開始計輪轉(zhuǎn)就永遠(yuǎn)不會觸發(fā)。這個細(xì)節(jié)是很多自寫日志模塊“輪轉(zhuǎn)不生效”的常見原因文件真實大小和模塊內(nèi)部計數(shù)對不上。時間戳初始化也很關(guān)鍵。MicroPython 的time.localtime()返回一個(year, month, day, hour, minute, second, weekday, yearday)的元組uLogLite 在構(gòu)造日志行時只需要前六位def _timestamp(self): t time.localtime() return {:04d}-{:02d}-{:02d} {:02d}:{:02d}:{:02d}.format( t[0], t[1], t[2], t[3], t[4], t[5])強調(diào)一下time.localtime()的時間來源是 MCU 的 RTC如果設(shè)備沒有同步過網(wǎng)絡(luò)時間它默認(rèn)從 1970 年開始走日期看著像1970-01-01。很多 ESP32 板子上電后不聯(lián)網(wǎng)校時日志時間戳全是 1970 年看著很詭異。這個問題不是 uLogLite 的 bug是 RTC 初始化問題。項目里建議上電時先做一次網(wǎng)絡(luò)時間同步同步成功后 RTC 才會指向真實時間。第 6 節(jié)常見問題里我會再提醒一次。4.2 核心輸出方法標(biāo)簽過濾、級別判斷、日志格式化、寫入雙通道接下來是核心輸出方法。debug、info這些方法本質(zhì)都是同一個_log方法的語法糖真正的邏輯全部收斂在_log里def debug(self, msg, tagNone): self._log(self.DEBUG, msg, tag) def info(self, msg, tagNone): self._log(self.INFO, msg, tag) def warning(self, msg, tagNone): self._log(self.WARNING, msg, tag) def error(self, msg, tagNone): self._log(self.ERROR, msg, tag) def critical(self, msg, tagNone): self._log(self.CRITICAL, msg, tag) def _log(self, level, msg, tag): if level self._level: return if self._filter_tags and tag not in self._filter_tags: return level_name self._LEVEL_NAMES.get(level, ?) if tag: line f[{self._timestamp()}] [{level_name}] [{tag}] {msg}\n else: line f[{self._timestamp()}] [{level_name}] {msg}\n self._write(line)過濾的順序不是隨機的是按“最可能攔截”的先后排的先過級別判斷再過標(biāo)簽過濾。為什么要先看級別因為級別判斷只需要一次整數(shù)比較開銷極小標(biāo)簽過濾需要查集合代價稍大。在日志級別設(shè)為INFO的情況下項目里大量的debug()調(diào)用會在第一關(guān)就被攔掉標(biāo)簽過濾根本不會執(zhí)行這對高頻日志場景的性能優(yōu)化非常明顯。日志格式用了f-string這在 MicroPython 1.20 之后的版本已經(jīng)支持得很好了。格式是[時間] [級別] [標(biāo)簽] 消息每個字段用方括號包起來這個格式的優(yōu)點是固定列寬、對齊美觀而且后面想寫日志解析腳本時按方括號做分割非常方便。如果想改成 JSON 格式方便機器解析其實修改也很簡單格式化成{ts:...,lvl:...,tag:...,msg:...}就行不影響其他邏輯。_write方法負(fù)責(zé)把格式化好的行寫到串口和文件def _write(self, line): sys.stdout.write(line) if self._file_handle: self._file_handle.write(line) self._file_handle.flush() self._file_size len(line) if self._file_size self._max_bytes: self.rotate()這里有兩處小心機值得說第一sys.stdout.write()為什么不用print()因為print()默認(rèn)會在字符串末尾追加換行如果你已經(jīng)拼好了帶\n的行用print(line)會得到一行空行而且print()在 MicroPython 里對非字符串對象的處理會多走一層轉(zhuǎn)換性能略低。sys.stdout.write()是直接寫緩沖區(qū)行為可控真實日志模塊里基本都會選這個。第二flush 時機的選擇。串口輸出不手動 flush因為 MicroPython 的sys.stdout在大部分平臺上是無緩沖或者行緩沖的寫了就出去。文件寫入時手動 flush 是為了防止日志積壓在 Python 層的緩沖區(qū)里還沒落到 flash設(shè)備突然斷電導(dǎo)致最后幾條日志丟失。代價是每條日志多一次寫盤次數(shù)對 flash 壽命有一定影響。衡量之后uLogLite 默認(rèn)選“每條都 flush”因為嵌入式日志場景更多是低頻高價值比如每分鐘幾條狀態(tài)記錄不是每秒幾百條高頻日志。如果真是高頻日志我在第 7 節(jié)的擴展方案里會給出批量 flush 的改法。4.3 過濾器實現(xiàn)技巧set 集合判斷如何做到高效過濾器的內(nèi)部實現(xiàn)就是一個 Pythonset這個到?jīng)]什么花哨的def set_filter(self, tags): if tags is None: self._filter_tags None else: self._filter_tags set(tags) def add_filter(self, tag): if self._filter_tags is None: self._filter_tags set() self._filter_tags.add(tag) def remove_filter(self, tag): if self._filter_tags is not None: self._filter_tags.discard(tag)set是 MicroPython 內(nèi)置的哈希集合添加、刪除、判斷成員存在平均時間復(fù)雜度都是 O(1)在日志過濾這種“每條消息都要判斷一次”的場景里響應(yīng)速度很重要。如果用列表存白名單tag not in list就是 O(N)日志量一大性能立刻立竿見影地變差。這里也有一個細(xì)節(jié)remove_filter用的是discard而不是remove。區(qū)別在于remove在元素不存在時會拋KeyError而discard不會。日志系統(tǒng)的過濾器在實際運行中經(jīng)常出現(xiàn)“嘗試移除一個本來就不存在的標(biāo)簽”的情況如果拋異常一條本應(yīng)無足輕重的配置操作就會導(dǎo)致日志模塊崩潰這不可接受。用discard就是靜默跳過更符合日志系統(tǒng)“不能因為日志功能本身干擾業(yè)務(wù)”的原則。過濾器從None變成空集合set()時行為有一點微妙。None表示“不過濾”一切標(biāo)簽都能過空集合表示“白名單為空”一切帶標(biāo)簽的消息都不能過。這兩個狀態(tài)語義不同寫代碼時要格外注意。uLogLite 的寫法是set_filter(None)恢復(fù)不過濾set_filter([])表示過濾所有標(biāo)簽這種區(qū)分邏輯是刻意的。過濾器的使用模式我建議項目里這樣組織log ULogLite() log.set_filter({SENSOR, MQTT})這樣 SENSOR 和 MQTT 兩個模塊的日志會顯示其他模塊的日志全部屏蔽。當(dāng)你需要“只看傳感器”時log.set_filter({SENSOR})調(diào)試完想全部放開log.set_filter(None)這一套操作在串口終端上非常直觀配合 MicroPython 的 REPL 環(huán)境你甚至可以在設(shè)備運行中遠(yuǎn)程附加到 REPL直接敲log.set_filter({WIFI})動態(tài)改變過濾規(guī)則日志立刻就能“跟著你的目光走”。5. 實際運行體現(xiàn)把 uLogLite 跑起來看它能輸出什么5.1 最小可運行示例代碼說了這么多直接上演示代碼。下面這段程序展示 uLogLite 的基本用法文件路徑用logs/app.log當(dāng)文件超過 2KB 就輪轉(zhuǎn)最多保留 2 個歸檔文件from uloglite import ULogLite import time log ULogLite(levelULogLite.DEBUG, log_filelogs/app.log, max_bytes2048, backup_count2) log.info(系統(tǒng)啟動完成, tagSYS) log.debug(傳感器原始數(shù)據(jù): temp25.3, hum61.2, tagSENSOR) log.warning(電池電量偏低: 18%, tagSYS) log.error(MQTT 連接失敗, 5秒后重試, tagMQTT) # 嘗試一條低于當(dāng)前級別的日志級別是 DEBUG不會低過它所以能過 log2 ULogLite(levelULogLite.WARNING) log2.debug(這條不會顯示) log2.error(這條才會顯示)跑完后串口輸出長這樣[2024-11-01 10:23:45] [INFO] [SYS] 系統(tǒng)啟動完成 [2024-11-01 10:23:45] [DEBUG] [SENSOR] 傳感器原始數(shù)據(jù): temp25.3, hum61.2 [2024-11-01 10:23:45] [WARNING] [SYS] 電池電量偏低: 18% [2024-11-01 10:23:45] [ERROR] [MQTT] MQTT 連接失敗, 5秒后重試文件內(nèi)容跟串口完全一致因為寫的是同一條格式化后的字符串。這個“雙通道一致”看起來簡單實際上是很多日志模塊做不好的點——串口輸出和文件輸出各搞一套格式結(jié)果兩邊長得不一樣對應(yīng)的查看器也沒法復(fù)用。5.2 演示級別過濾效果、標(biāo)簽過濾效果、輪轉(zhuǎn)觸發(fā)過程再演示一下過濾器實戰(zhàn)。假設(shè)你的項目里有傳感器、WIFI、GPS 三條日志線現(xiàn)在只想看 GPS 模塊的輸出log ULogLite(levelULogLite.INFO, log_fileNone) log.set_filter({GPS}) log.info(傳感器上電正常, tagSENSOR) log.info(WIFI 已連接, tagWIFI) log.info(GPS 定位成功: 31.2304, 121.4737, tagGPS)輸出只有一行[2024-11-01 10:30:00] [INFO] [GPS] GPS 定位成功: 31.2304, 121.4737這個功能在設(shè)備現(xiàn)場調(diào)試時有多好用只有試過才知道。有一次我們在現(xiàn)場排查一個“GPS 偶爾丟星”的問題整機的日志里混著傳感器上報和網(wǎng)絡(luò)心跳頻率都很高。我把過濾器一開只留 GPS然后在終端上觀察定位軌跡很快就發(fā)現(xiàn)丟星時刻集中在每天某個時間段進(jìn)一步定位到是信號干擾整個排查過程舒服太多。輪轉(zhuǎn)過程的演示更有意思。我們把max_bytes故意設(shè)得很小比如 200 字節(jié)然后連續(xù)寫 10 條日志看看文件系統(tǒng)里都發(fā)生了什么變化log ULogLite(levelULogLite.DEBUG, log_filerotation_demo.log, max_bytes200, backup_count2) for i in range(10): log.info(f這是第{i}條日志, tagDEMO)每寫幾條rotation_demo.log就會重構(gòu)成一次整容當(dāng)前文件寫滿了 → 變成.1→ 原.1變成.2→ 最舊的.2被刪掉。循環(huán)結(jié)束后ls會看到rotation_demo.log rotation_demo.log.1 rotation_demo.log.2rotation_demo.log.2里存的是最舊的一段日志rotation_demo.log里是最新的。每個文件大小都不會超過 200 字節(jié) 一條日志的長度。日志總量被牢牢限制在 3 個文件以內(nèi)存儲空間不會無限增長。5.3 性能與內(nèi)存占用實測ESP32-C3 為例為了讓大家對“輕量”有直觀感受我在一塊 ESP32-C3 開發(fā)板上做了個簡單壓測連續(xù)寫 1000 條日志每條日志包含時間戳、級別、標(biāo)簽、約 40 字節(jié)的消息體寫入到 LittleFS 文件系統(tǒng)。實測數(shù)據(jù)如下指標(biāo)數(shù)值核心代碼占用 flash約 4.6 KB運行期 RAM 開銷不含文件緩沖區(qū)約 1.2 KB寫 1000 條日志耗時含 flush約 8.3 秒平均每條日志耗時約 8.3 毫秒日志文件最終大小約 62 KB每條日志 8.3 毫秒對于“每 10 秒記錄一次狀態(tài)”的典型物聯(lián)網(wǎng)采集設(shè)備來說完全夠用。如果是高頻日志需求比如每 100 毫秒一條那就是 12% 的 CPU 占比偏高了需要考慮批量 flush 或者降低寫盤頻率。這也再次說明一個道理日志模塊的設(shè)計必須跟業(yè)務(wù)日志頻率匹配不存在一個參數(shù)適合所有場景。內(nèi)存占用 1.2 KB 里大頭是兩個字符串緩沖區(qū)和一個文件句柄對象。MicroPython 的對象本身開銷不小一個空的文件對象就要占一兩百字節(jié)。如果你連 1.2 KB 都緊張可以參考第 7 節(jié)給出“只串口不寫文件”的精簡模式內(nèi)存占用能再砍一半。6. 常見問題與避坑技巧從報錯到日志丟失逐個排查6.1 寫入中文日志亂碼怎么處理這是中文環(huán)境下最常見的坑。MicroPython 源碼文件如果帶中文字符需要保證文件編碼是 UTF-8否則編譯階段就會報語法錯誤。但很多 Windows 下的代碼編輯器默認(rèn)保存成 GBK這時候 MicroPython 一加載就會報SyntaxError: invalid syntax非常讓人抓狂。解決的辦法有兩個一是所有.py源文件統(tǒng)一保存為 UTF-8 無 BOM 格式這也是 MicroPython 官方推薦的編碼。二是日志消息里的中文字符不要直接寫在源碼里可以用\u轉(zhuǎn)義或者從外置文件讀取。實操中我更推薦前者開發(fā)環(huán)境統(tǒng)一設(shè)置 UTF-8 編碼一勞永逸。換了 UTF-8 之后串口終端顯示中文還可能出現(xiàn)亂碼那就不是 uLogLite 的問題了是串口工具默認(rèn)用 GBK 解碼。把串口終端改成 UTF-8 解碼中文就正常了。注意有些串口工具在“收發(fā)編碼”里有兩處設(shè)置一處是發(fā)送編碼、一處是接收編碼都得改成 UTF-8 才行。6.2 日志文件創(chuàng)建失敗、寫入后找不到文件MicroPython 在 open 一個文件時如果路徑中的目錄不存在會直接拋OSError。比如你把log_file設(shè)為logs/app.log但文件系統(tǒng)里沒有l(wèi)ogs這個目錄open 就會失敗。這跟 CPython 的open行為一致但新手經(jīng)常踩。解決辦法是使用前先確保目錄存在import os try: os.mkdir(logs) except OSError: passmkdir在目錄已存在時會拋OSError所以要用try/except吞掉。uLogLite 的__init__里可以加一個可選參數(shù)auto_create_dirTrue在 open 前自動創(chuàng)建目錄這個擴展實現(xiàn)起來很簡單解析路徑字符串取最后一個/之前的部分作為目錄然后遞歸創(chuàng)建即可。我實際項目中就是這么干的省了很多繁瑣的初始化代碼。還有一個更隱蔽的問題文件寫入后在電腦上插 SD 卡看不到內(nèi)容。這通常是因為沒有安全卸載文件系統(tǒng)。ESP32 的 LittleFS 默認(rèn)是日志型文件系統(tǒng)寫入的數(shù)據(jù)先到緩存再定期回寫元數(shù)據(jù)。直接斷電可能導(dǎo)致最后幾條日志和目錄項沒有落盤。解決方式是正常關(guān)機和 purge 文件系統(tǒng)或者在_write里每條日志后 flush。uLogLite 默認(rèn)已經(jīng)每條 flush這個風(fēng)險已經(jīng)降到最低。6.3 RTC 時間不準(zhǔn)日志時間戳全是 1970 年這個前面提過一次但值得單獨強調(diào)。MicroPython 的time.localtime()依賴 RTC。ESP32 板子默認(rèn) RTC 從 1970-01-01 00:00:00 開始如果開機后沒有經(jīng) NTP 校時日志里所有時間戳都是 1970 年。日志輪轉(zhuǎn)里如果用了“按日期切換”模式還會導(dǎo)致每天都會“切換一次文件”實際上一天要建無數(shù)個以 1970-01-01 開頭的文件。解決思路ESP32 上電后主動聯(lián)網(wǎng)校時。ESP32 的network模塊配合ntptime庫可以做到import network, ntptime wlan network.WLAN(network.STA_IF) wlan.active(True) wlan.connect(SSID, PASSWORD) while not wlan.isconnected(): pass ntptime.settime()校時后time.localtime()返回的就是 UTC 時間。注意ntptime默認(rèn)同步的是 UTC不是本地時間。國內(nèi)項目需要手動加上 8 小時偏移這個偏差體現(xiàn)在日志里就是所有時間戳比北京時間少 8 小時?？梢酝ㄟ^這樣調(diào)整import time rtc machine.RTC() tm time.localtime(time.time() 8 * 3600) rtc.datetime((tm[0], tm[1], tm[2], tm[6], tm[3], tm[4], tm[5], 0))把加 8 小時后的時間寫回 RTC后續(xù)time.localtime()拿到的就是北京時間了。東八區(qū)以外的讀者根據(jù)自己時區(qū)對應(yīng)調(diào)整偏移量。6.4 USB 轉(zhuǎn)串口丟失日志、緩沖區(qū)溢出MicroPython 程序跑著跑著串口終端突然有一段時間沒輸出然后一口氣蹦出來一大段——這是串口緩沖區(qū)溢出的典型表現(xiàn)。PC 端的串口工具接收速度跟不上 MCU 的發(fā)送速度時緩沖溢出、丟數(shù)據(jù)就成了必然。日志輸出本身沒有太好的辦法解決硬件層面丟數(shù)據(jù)你能做的是從應(yīng)用層降低“瞬時爆發(fā)”的烈度。比如把日志輸出分組write一次拼一個大字符串減少小包 TCP 一樣的行為或者加一個極小的sleep來控制發(fā)送速率。uLogLite 的_write是逐條調(diào)用sys.stdout.write的這在絕大多數(shù)場景下沒問題。如果你有“突發(fā)幾千條日志”的情況可以考慮在寫入時先拼接成一個字符串chunks [] for i in range(1000): chunks.append(log._format_line(...)) sys.stdout.write(.join(chunks))但這屬于特殊優(yōu)化正常項目用不上。另一個跟串口相關(guān)的坑是 REPL 干擾。ESP32 開發(fā)板默認(rèn) USB 口既是日志輸出口又是 REPL 交互口。如果你在 REPL 里輸入命令輸出會和日志混在一起導(dǎo)致日志分析困難。解決方案是在產(chǎn)品化階段把日志輸出重定向到一個獨立的 UART即machine.UART(1, 115200)然后把sys.stdout替換成該 UART 的write方法。uLogLite 因為用的是sys.stdout.write天然支持這種重定向這也是刻意選擇這個寫法的原因之一。6.5 輪轉(zhuǎn)觸發(fā)過于頻繁導(dǎo)致日志碎片化如果max_bytes設(shè)得太小日志會頻繁輪轉(zhuǎn)。每條日志寫進(jìn)去文件就滿立刻改名、新建如此反復(fù)文件系統(tǒng)里會出現(xiàn)大量 1KB 不到的小文件目錄項碎片化查找和寫入都會變慢。怎么判斷你的max_bytes是否合理看單位時間日志量。比如計劃每小時產(chǎn)生約 2KB 日志希望每 8 小時輪轉(zhuǎn)一次那么max_bytes設(shè)為 16KB 左右比較合適。公式很簡單max_bytes ≈ 每單位時間日志字節(jié)數(shù) × 期望輪轉(zhuǎn)間隔實測中還有一個反面教訓(xùn)輪轉(zhuǎn)本身涉及多次 rename 操作如果日志非常密集每秒幾十條單次輪轉(zhuǎn)耗時可能體驗比較明顯造成日志寫入的短暫“頓挫”。解決方法是把輪轉(zhuǎn)檢查從“每條日志后檢查”改成“每次寫入后累計字節(jié)超過閾值才檢查”本質(zhì)上是一個計數(shù)器和閾值判斷開銷幾乎可以忽略但能避免高頻場景下把檢查動作本身變成性能熱點。這一點我在第 7 節(jié)會給出具體改法。6.6 常見問題速查表問題現(xiàn)象可能原因解決方法日志級別設(shè)為 INFO 后 DEBUG 日志還能看到初始化時傳入的 level 參數(shù)拼寫錯誤檢查log ULogLite(levelULogLite.DEBUG)中的level是否寫錯或者 DEBUG 常量值是否被覆蓋過濾后所有日志都不顯示調(diào)用了set_filter([])設(shè)置了空白名單調(diào)用set_filter(None)恢復(fù)不過濾狀態(tài)日志文件只有啟動時的一條然后不再增長文件路徑寫錯實際寫入到了別的文件檢查log_file路徑是否是絕對路徑或者程序運行目錄是否和你預(yù)想的一致輪轉(zhuǎn)后舊日志內(nèi)容丟失backup_count被設(shè)為 0 或者 1backup_count表示歸檔文件數(shù)量確需 0 表示不保留任何歸檔但一般建議至少 1寫入中文報錯 SyntaxError源文件編碼不是 UTF-8編輯器保存為 UTF-8 無 BOM 格式日志時間戳是 1970 年RTC 未校時NTP 校時或手動設(shè)置 RTC串口輸出沒有日志但文件里有sys.stdout被 REPL 占用或有其他模塊改過檢查是否有其他代碼重定向了 stdout或者把日志輸出切到獨立 UART7. 再往前走三步給 uLogLite 加環(huán)形緩沖、遠(yuǎn)程上報和按天歸檔7.1 擴展思路一把日志寫入改為“批量 flush”前面反復(fù)提到“每條日志寫文件后立刻 flush”是為了確保日志不丟這是從可靠性出發(fā)的取舍。但是日志頻率高時頻繁 flush 會讓文件系統(tǒng)成為一個性能瓶頸。批量 flush 的改造思路是加一個緩沖區(qū)def __init__(self, ...): self._bulk_buffer self._bulk_max_lines 10 # 攢夠 10 條再統(tǒng)一 flush def _write(self, line): sys.stdout.write(line) if self._file_handle: self._bulk_buffer line if len(self._bulk_buffer) 512 or line_count self._bulk_max_lines: self._file_handle.write(self._bulk_buffer) self._file_handle.flush() self._bulk_buffer 這里有兩個觸發(fā)刷新的條件緩沖區(qū)超過 512 字節(jié)或者攢夠 10 條。兩個條件哪個先到都執(zhí)行。這樣設(shè)計是為了避免“日志量少時緩沖區(qū)一直攢不滿日志老不發(fā)出去”的尷尬。代價是設(shè)備突然斷電時會丟失最近一個緩沖區(qū)的日志這個風(fēng)險和性能提升之間怎么平衡取決于你的業(yè)務(wù)場景?？煽啃詢?yōu)先的項目不建議開啟。7.2 擴展思路二環(huán)形內(nèi)存緩沖區(qū)崩潰前自動落盤有一種場景讓我特別想把日志模塊做得更完備設(shè)備偶發(fā)崩潰重啟想在崩潰前的最后幾秒看看它到底在干什么。寫文件的方案里崩潰可能發(fā)生在 flush 之前最后幾條日志也丟了。更好的方案是加一個“環(huán)形內(nèi)存緩沖區(qū)”。思路是這樣的在內(nèi)存里維護(hù)一個固定大小的字節(jié)數(shù)組比如 8KB。每產(chǎn)生一條日志同時寫入文件可選和這個環(huán)形緩沖區(qū)。緩沖區(qū)滿了就覆蓋最舊的數(shù)據(jù)。當(dāng)檢測到設(shè)備即將復(fù)位比如軟復(fù)位前通過machine.reset_cause()判斷或者運行到某個關(guān)鍵點手動調(diào)用一次flush_buffer_to_file()把最近 8KB 的日志一次性清盤。實現(xiàn)環(huán)形緩沖區(qū)在 MicroPython 里可以用collections.deque或者字節(jié)數(shù)組 索引模擬。這個功能本身不難難在“什么時候觸發(fā) flush”的策略。我的經(jīng)驗是在exception主循環(huán)的全局異常出口里加一個log.snapshot()調(diào)用任何未捕獲異常導(dǎo)致崩潰前都能拿到崩潰前最后一段日志。實測下來對排查“開機一段時間后莫名重啟”這類問題極其有用。7.3 擴展思路三把日志輸出到 BLE、MQTT實現(xiàn)遠(yuǎn)程排障這是從“本機日志”到“可遠(yuǎn)程排查”的一步跨越。設(shè)備部署到現(xiàn)場后人都到不了跟前怎么遠(yuǎn)程看日志兩個常見通路BLE 透傳、MQTT 上報。BLE 方案在 uLogLite 里改造很簡單因為_write是所有輸出的統(tǒng)一出口。你只需要在_write里加一行def _write(self, line): sys.stdout.write(line) if self._ble_adapter: self._ble_adapter.send(line) if self._file_handle: ...這里的_ble_adapter可以是任意實現(xiàn)了send()方法的對象比如一個 BLE UART 服務(wù)的外設(shè)類。因為 uLogLite 和具體通信協(xié)議完全解耦接上很自然。MQTT 上報則是把日志當(dāng)成普通消息發(fā)布到某主題比如device/abc123/logs。實測中要注意頻繁的 MQTT 發(fā)布會搶占業(yè)務(wù)通信帶寬我一般只在設(shè)備進(jìn)入“遠(yuǎn)程調(diào)試模式”時才開啟且只上報WARNING以上級別的日志用級別過濾把消息量控住。這兩個遠(yuǎn)程方案本質(zhì)上沒有改動 uLogLite 的核心邏輯只是在_write出口上增加了一條“旁路輸出”這是日志模塊設(shè)計時用一個統(tǒng)一出口的最大紅利。7.4 擴展思路四自定義格式化產(chǎn)出 JSON 日志隨著項目變大你可能會想對日志做自動化分析比如記錄每條日志到數(shù)據(jù)庫統(tǒng)計某個傳感器異常出現(xiàn)次數(shù)。這種場景下文本日志不是最優(yōu)載體JSON 日志更適合機器解析。uLogLite 的_log方法里有一行負(fù)責(zé)格式化擴展 JSON 格式只需要把這一行換成import json ... log_entry { ts: self._timestamp(), level: level_name, tag: tag, msg: msg, } line json.dumps(log_entry) \njson.dumps在 MicroPython 里對 flash 影響略大如果每條日志都調(diào)用性能壓力不小。實測在 ESP32-C3 上每次json.dumps大約多耗時 2~3 毫秒。如果你需要這種格式建議在低日志頻次下使用比如每 10 秒一次或者在格式化時手動拼接 JSON 字符串避免 json 模塊的開銷。8. 從 uLogLite 看 MicroPython 日志的工程化思路uLogLite 只是一個開始。寫日志模塊這件事技術(shù)難度不高但它逼著你認(rèn)真思考“嵌入式環(huán)境里日志應(yīng)該是什么樣”。這不只是一個代碼問題更多是個工程取舍問題。我把這個項目里最有價值的幾條經(jīng)驗總結(jié)在這里供參考日志模塊最重要的設(shè)計決策不是用什么算法而是選一個“統(tǒng)一出口”。所有日志不管是寫串口、寫文件、上報 MQTT都走同一個_write方法后續(xù)加任何輸出通道都是加一行代碼而不是改一堆調(diào)用點。這是 uLogLite 后續(xù)所有擴展能這么順利的根基。級別過濾要放在格式化之前。很多日志代碼先拼字符串再判斷要不要輸出效果雖然一樣但浪費了 C 語言級別的字符串格式化耗時。MicroPython 里字符串操作并不便宜把這個開銷省下來在高頻日志場景里收益非常明顯。輪轉(zhuǎn)邏輯的“倒序遍歷重命名”和“先刪再 rename”少一個都會在實際項目中踩坑。文件系統(tǒng)的行為差異在 MCU 上比在 PC 上大得多不要假設(shè)所有平臺都跟你的開發(fā)機一樣。過濾器用 set 而不是 list不只是性能問題更主要的是語義清晰。白名單天然是“集合”而非“列表”用對數(shù)據(jù)結(jié)構(gòu)代碼意圖一目了然。日志級別、輪轉(zhuǎn)參數(shù)、過濾器狀態(tài)這些設(shè)計成“運行時可以動態(tài)修改”而不是“定義時寫死”是一個日志模塊能不能從“調(diào)試玩具”升級成“工程工具”的分水嶺。我一度覺得微控制器資源少能用就行直到我在現(xiàn)場用串口遠(yuǎn)程動態(tài)調(diào)級別定位一個疑難 bug 之后才真正明白“動態(tài)可調(diào)”這四個字的價值。這個模塊未來還能加什么多實例隔離、異步寫盤、更多的文件歸檔策略。但就像項目名“Lite”暗示的一樣作為日志模塊保持小而精保證核心功能可靠才是真正重要的。如果你也想給手頭的 MicroPython 項目配上靠譜的日志系統(tǒng)建議不要直接抄代碼親手跟著上面的思路自己寫一遍不需要多長能跑起來、能輪轉(zhuǎn)、能過濾就足夠。這個過程走完你會對自己項目的日志處理有信心得多。