微信終端跨平臺組件 mars 系列（一） - 高性能日誌模塊xlog

本文來自於騰訊bugly開發者社區，非經做者贊成，請勿轉載，原文地址：http://dev.qq.com/topic/57ff5...

本文來源： 微信客戶端開發團隊

前言

mars 是微信官方的終端基礎組件，是一個使用 C++ 編寫的業務性無關，平臺性無關的基礎組件。目前已接入微信 Android、iOS、Mac、Windows、WP 等客戶端。現正在籌備開源中，它主要包括如下幾個部分：

1. comm：能夠獨立使用的公共庫，包括 socket、線程、消息隊列等

2. xlog：能夠獨立使用的日誌模塊

3. sdt：能夠獨立使用的網絡診斷模塊

4. stn：能夠獨立使用的信令分發網路模塊

本文章是 mars 系列的第一篇：高性能跨平臺日誌模塊。

正文

對於移動開發者來講，最大的尷尬莫過於用戶反饋程序出現問題，但由於不能重現且沒有日誌沒法定位具體緣由。這樣看來客戶端日誌很有點「養兵千日，用兵一時」的感受，只有當出現問題且不容易重現時才能體現它的重要做用。爲了保證關鍵時刻有日誌可用，就須要保證程序整個生命週期內都要打日誌，因此日誌方案的選擇相當重要。

常規方案

方案描述: 對每一行日誌加密寫文件

例如 Android 平臺使用 java 實現日誌模塊，每有一句日誌就加密寫進文件。這樣在使用過程當中不只存在大量的 GC，更致命的是由於有大量的 IO 須要寫入，影響程序性能很容易致使程序卡頓。選擇這種方案，在 release 版本只能選擇把日誌關掉。當有用戶反饋時，就須要給用戶從新編一個打開日誌的安裝包，用戶從新安裝重現後再經過日誌來定位問題。不只定位問題的效率低下，並且並不能保證每一個須要定位的問題都能重現。這個方案能夠說主要是爲程序發佈前服務的。

來看一下直接寫文件爲何會致使程序卡頓

當寫文件的時候，並非把數據直接寫入了磁盤，而是先把數據寫入到系統的緩存(dirty page)中，系統通常會在下面幾種狀況把 dirty page 寫入到磁盤：

• 定時回寫，相關變量在/proc/sys/vm/dirty_writeback_centisecs和/proc/sys/vm/dirty_expire_centisecs中定義。

• 調用 write 的時候，發現 dirty page 佔用內存超過系統內存必定比例，相關變量在/proc/sys/vm/dirty_background_ratio（ 後臺運行不阻塞 write）和/proc/sys/vm/dirty_ratio（阻塞 write）中定義。

• 內存不足。

數據從程序寫入到磁盤的過程當中，其實牽涉到兩次數據拷貝：一次是用戶空間內存拷貝到內核空間的緩存，一次是回寫時內核空間的緩存到硬盤的拷貝。當發生回寫時也涉及到了內核空間和用戶空間頻繁切換。
dirty page 回寫的時機對應用層來講又是不可控的，因此性能瓶頸就出現了。

這個方案存在的最主要的問題：由於性能影響了程序的流暢性。對於一個 App 來講，流暢性尤其重要，由於流暢性直接影響用戶體驗，最基本的流暢性的保證是使用了日誌不會致使卡頓，可是流暢性不只包括了系統沒有卡頓，還要儘可能保證沒有 CPU 峯值。因此一個優秀的日誌模塊必須保證流暢性：

• 不能影響程序的性能。最基本的保證是使用了日誌不會致使程序卡頓

我以爲絕大部分人不會選擇這一個方案。

進一步思考

在上個方案中，由於要寫入大量的 IO 致使程序卡頓，那是否能夠先把日誌緩存到內存中，當到必定大小時再加密寫進文件，爲了進一步減小須要加密和寫入的數據，在加密以前能夠先進行壓縮。至於 Android 下存在頻繁 GC 的問題，可使用 C++ 來實現進行避免，並且經過 C++ 能夠實現一個平臺性無關的日誌模塊。

方案描述：把日誌寫入到做爲 log 中間 buffer 的內存中，達到必定條件後壓縮加密寫進文件。

這個方案的總體的流程圖：

這個方案基本能夠解決 release 版本由於流暢性不敢打日誌的問題，而且對於流暢性解決了最主要的部分：因爲寫日誌致使的程序卡頓的問題。可是由於壓縮不是 realtime compress，因此仍然存在 CPU 峯值。但這個方案卻存在一個致命的問題：丟日誌。

理想中的狀況：當程序 crash 時， crash 捕捉模塊捕捉到 crash， 而後調用日誌接口把內存中的日誌刷到文件中。可是實際使用中會發現程序被系統殺死不會有事件通知，並且不少異常退出，crash 捕捉模塊並不必定能捕捉到。而這兩種狀況偏偏是平時跟進的重點，由於沒有 crash 堆棧輔助定位問題，因此丟日誌的問題這個時候顯得尤其凸顯。

在實際實踐中，Android 可使用共享內存作中間 buffer 防止丟日誌，但其餘平臺並無太好的辦法，並且 Android 4.0 之後，大部分手機再也不有權限使用共享內存，即便在 Android 4.0 以前，共享內存也不是一個公有接口，使用時只能經過系統調用的方式來使用。因此這個方案仍然存在不足：

• 若是損壞一部分數據雖然不會累及整個日誌文件但會影響整個壓縮塊

• 個別狀況下仍然會丟日誌，並且集中壓縮會致使 CPU 短期飆高

經過這個方案，能夠看出日誌不只要保證程序的流暢性，還要保證日誌內容的完整性和容錯性：

• 不能由於程序被系統殺掉，或者發生了 crash， crash 捕捉模塊沒有捕捉到致使部分時間點沒有日誌， 要保證程序整個生命週期內都有日誌。

• 不能由於部分數據損壞就影響了整個日誌文件，應該最小化數據損壞對日誌文件的影響。

mars 的日誌模塊xlog

前面提到了使用內存作中間 buffer 作日誌可能會丟日誌，直接寫文件雖然不會丟日誌但又會影響性能。因此亟需一個既有直接寫內存的性能，又有直接寫文件的可靠性的方案，也就是 mars 在用的方案。

mmap

mmap 是使用邏輯內存對磁盤文件進行映射，中間只是進行映射沒有任何拷貝操做，避免了寫文件的數據拷貝。操做內存就至關於在操做文件，避免了內核空間和用戶空間的頻繁切換。

爲了驗證 mmap 是否真的有直接寫內存的效率，咱們寫了一個簡單的測試用例：把512 Byte的數據分別寫入150 kb大小的內存和 mmap，以及磁盤文件100w次並統計耗時

從上圖看出mmap幾乎和直接寫內存同樣的性能，並且 mmap 既不會丟日誌，回寫時機對咱們來講又基本可控。 mmap 的回寫時機：

• 內存不足

• 進程 crash

• 調用 msync 或者 munmap

• 不設置 MAP_NOSYNC 狀況下 30s-60s(僅限FreeBSD)

若是能夠經過引入 mmap 既能保證高性能又能保證高可靠性，那麼還存在的其餘問題呢？好比集中壓縮致使 CPU 短期飆高，這個問題從上個方案就一直存在。並且使用 mmap 後又引入了新的問題，能夠看一下使用 mmap 以後的流程：

前面已經介紹了，當程序被系統殺掉會把邏輯內存中的數據寫入到 mmap 文件中，這時候數據是明文的，很容易被窺探，可能會有人以爲那在寫進 mmap 以前先加密不就好了，可是這裏又須要考慮，是壓縮後再加密仍是加密後再壓縮的問題，很明顯先壓縮再加密效率比較高，這個順序不能改變。並且在寫入 mmap 以前先進行壓縮，也會減小所佔用的 mmap 的大小，進而減小 mmap 所佔用內存的大小。因此最終只能考慮：是否能在寫進邏輯內存以前就把日誌先進行壓縮，再進行加密，最後再寫入到邏輯內存中。問題明確了：就是怎麼對單行日誌進行壓縮，也就是其餘模塊每寫一行日誌日誌模塊就必須進行壓縮。

壓縮

比較通用的壓縮方案是先進行短語式壓縮， 短語式壓縮過程當中有兩個滑動窗口，歷史滑動窗口和前向緩存窗口，在前向緩存窗口中經過和歷史滑動窗口中的內容進行匹配從而進行編碼。

好比這句繞口令：吃葡萄不吐葡萄皮，不吃葡萄倒吐葡萄皮。中間是有兩塊重複的內容「吃葡萄」和「吐葡萄皮」這兩塊。第二個「吃葡萄」的長度是 3 和上個「吃葡萄」的距離是 10 ，因此能夠用 (10,3) 的值對來表示，一樣的道理「吐葡萄皮」能夠替換爲 (10,4 )

這些沒壓縮的字符經過 ascci 編碼其實也是 0-255 的整數，因此經過短語式壓縮獲得的結果實質上是一堆整數。對整數的壓縮最多見的就是 huffman 編碼。通用的壓縮方案也是這麼作的，固然中間還摻雜了遊程編碼，code length 的轉換。但其實這個不是關注的重點。咱們只須要明白整個壓縮過程當中，短語式壓縮也就是 LZ77 編碼完成最大的壓縮部分也是最重要的部分就好了，其餘模塊的壓縮實際上是對這個壓縮結果的進一步壓縮，進一步壓縮的方式主要使用 huffman 壓縮，因此這裏就須要基於數字出現的頻率進行統計編碼，也就是說若是滑動窗口大小沒上限的前提下，越多的數據集中壓縮，壓縮的效果就越好。日誌模塊使用這個方案時壓縮效果能夠達到 86.3%。

既然 LZ77 編碼已經完成了大部分壓縮，那麼是否能夠弱化 huffman 壓縮部分，好比使用靜態 huffman 表，自定義字典等。因而咱們測試了四種方案：

這裏能夠看出來後兩種方案明顯優於前兩種，壓縮率均可以達到 83.7%。第三種是把整個 app 生命週期做爲一個壓縮單位進行壓縮，若是這個壓縮單位中有數據損壞，那麼後面的日誌也都解壓不出來。但其實在短語式壓縮過程當中，滑動窗口並非無限大的，通常是 32kb ，因此只須要把必定大小做爲一個壓縮單位就能夠了。這也就是第四個方案， 這樣的話即便壓縮單位中有部分數據損壞，由於是流式壓縮，並不影響這個單位中損壞數據以前的日誌的解壓，只會影響這個單位中這個損壞數據以後的日誌。

對於使用流式壓縮後，咱們採用了三臺安卓手機進行了耗時統計，和以前使用通用壓縮的的日誌方案進行了對比(耗時爲單行日誌的平均耗時):

經過橫向對比，能夠看出雖然使用流式壓縮的耗時是使用多條日誌同時壓縮的 2.5 倍左右，可是這個耗時自己就很小，是微秒級別的，幾乎不會對性能形成影響。最關鍵的，多條日誌同時壓縮會致使 CPU 曲線短期內極速升高，進而可能會致使程序卡頓，而流式壓縮是把時間分散在整個生命週期內，CPU 的曲線更平滑，至關於把壓縮過程當中使用的資源均分在整個 app 生命週期內。

xlog 方案總結

該方案的簡單描述：

使用流式方式對單行日誌進行壓縮，壓縮加密後寫進做爲 log 中間 buffer的 mmap 中

雖然使用流式壓縮並無達到最理想的壓縮率，但和 mmap 一塊兒使用能兼顧流暢性 完整性 容錯性 的前提下，83.7%的壓縮率也是能接受的。使用這個方案，除非 IO 損壞或者磁盤沒有可用空間，基本能夠保證不會丟失任何一行日誌。

在實現過程當中，各個平臺上也踩了很多坑，好比：

• iOS 鎖屏後，由於文件保護屬性的問題致使文件不可寫，須要把文件屬性改成 NSFileProtectionNone。

• boost 使用 ftruncate 建立的 mmap 是稀疏文件，當設備上無可用存儲時，使用 mmap 過程當中可能會拋出 SIGBUS 信號。經過對新建的 mmap 文件的內容全寫'0'來解決。

• ……

日誌模塊還存在一些其餘策略：

• 每次啓動的時候會清理日誌，防止佔用太多用戶磁盤空間

• 爲了防止 sdcard 被拔掉致使寫不了日誌，支持設置緩存目錄，當 sdcard 插上時會把緩存目錄裏的日誌寫入到 sdcard 上

• ……

在使用的接口方面支持多種匹配方式：

• 類型安全檢測方式：%s %d 。例如：xinfo(「%s %d」, 「test」, 1)

• 序號匹配的方式：%0 %1 。例如：xinfo(TSF」%0 %1 %0」, 「test」, 1)

• 智能匹配的懶人模式：%_ 。例如：xinfo(TSF」%_ %_」, 「test」, 1)

總結

對於終端設備來講，打日誌並不僅是把日誌信息寫到文件裏這麼簡單。除了前文提到的流暢性 完整性 容錯性，還有一個最重要的是安全性。基於不怕被破解，但也不能任何人都能破解的原則，對日誌的規範比加密算法的選擇更爲重要，因此本文並無討論這一點。

從前面的幾個方案中能夠看出，一個優秀的日誌模塊必須作到：

• 不能把用戶的隱私信息打印到日誌文件裏，不能把日誌明文打到日誌文件裏。

• 不能影響程序的性能。最基本的保證是使用了日誌不會致使程序卡頓。

• 不能由於程序被系統殺掉，或者發生了 crash，crash 捕捉模塊沒有捕捉到致使部分時間點沒有日誌， 要保證程序整個生命週期內都有日誌。

• 不能由於部分數據損壞就影響了整個日誌文件，應該最小化數據損壞對日誌文件的影響。

上面這幾點也即安全性 流暢性 完整性 容錯性， 它們之間存在着矛盾關係：

• 若是直接寫文件會卡頓，但若是使用內存作中間 buffer 又可能丟日誌

• 若是不對日誌內容進行壓縮會致使 IO 卡頓影響性能，但若是壓縮，部分損壞可能會影響整個壓縮塊，並且爲了增大壓縮率集中壓縮又可能致使 CPU 短期飆高。

mars 的日誌模塊 xlog 就是在兼顧這四點的前提下作到：高性能高壓縮率、不丟失任何一行日誌、避免系統卡頓和 CPU 波峯。

---

更多精彩內容歡迎關注bugly的微信公衆帳號：