本文來自於騰訊bugly開發者社區，非經作者同意，請勿轉載，原文地址：http://dev.qq.com/topic/57ff5932cde42f1f03de29b1
本文來源： 微信客戶端開發團隊
前言
mars 是微信官方的終端基礎組件，是一個使用 C++ 編寫的業務性無關，平台性無關的基礎組件。目前已接入微信 Android、iOS、Mac、Windows、WP 等客戶端。現正在籌備開源中，它主要包括以下幾個部分：
- comm：可以獨立使用的公共庫，包括 socket、線程、消息隊列等
- xlog：可以獨立使用的日志模塊
- sdt：可以獨立使用的網絡診斷模塊
- 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的微信公眾賬號：
騰訊 Bugly是一款專為移動開發者打造的質量監控工具，幫助開發者快速，便捷的定位線上應用崩潰的情況以及解決方案。智能合並功能幫助開發同學把每天上報的數千條 Crash 根據根因合並分類，每日日報會列出影響用戶數最多的崩潰，精准定位功能幫助開發同學定位到出問題的代碼行，實時上報可以在發布后快速的了解應用的質量情況，適配最新的 iOS, Android 官方操作系統，鵝廠的工程師都在使用，快來加入我們吧！