【騰訊Bugly乾貨分享】微信mars 的高性能日誌模塊 xlog

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

Dev Club 是一個交流移動開發技術，結交朋友，擴展人脈的社羣，成員都是通過審覈的移動開發工程師。每週都會舉行嘉賓分享，話題討論等活動。

本期，咱們邀請了 騰訊 WXG Android 高級工程師「閆國躍」，爲你們分享《微信mars 的高性能日誌模塊 xlog》。

---

你們好 我是來自騰訊微信的閆國躍，很榮幸能給你們作這個分享，我今天主要給你們分享微信mars 的高性能日誌模塊 xlog 

1. Mars 簡介

首先介紹一下mars 是什麼。

mars 是微信官方的終端基礎組件，是一個使用 C++ 編寫的業務性無關，平臺性無關的基礎組件。 

能夠看一下mars 簡單的架構圖：

從圖中就能夠看出它主要包括如下幾個部分：

1. comm：能夠獨立使用的公共庫，包括 socket、線程、消息隊列、協程等
2. xlog：能夠獨立使用的日誌模塊
3. sdt：能夠獨立使用的網絡診斷模塊
4. stn：能夠獨立使用的信令分發網絡模塊

目前接入平臺：Android、iOS、Mac、Windows、WP等 。現正在籌備開源中。能夠這麼說，接入 mars 以後，開發一個應用只須要把開發重心放在業務層和 UI 層上，底層的日誌模塊和網絡模塊在 mars 中都已經提供。

在使用用戶數上有月活躍8億的微信用戶幫忙背書(數據來源於財報)。 在數據監控上，純網絡監控，長鏈接有18項 短鏈接7項。

接下來我重點講今天的主角mars的 xlog 部分。咱們先來思考一下爲何須要日誌，日誌何時能顯示其做用。

2. 爲何須要 xlog

咱們來看一下微信早期跟進問題的流程是怎麼樣的： 

當用戶反饋或者咱們發現問題時，咱們須要聯繫用戶，用戶答應配合後，而後修改代碼打開日誌從新編包讓用戶試圖重現問題，重現以後才能繼續排查。這個流程是由當時使用的日誌方案所決定的。例如 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 回寫的時機對應用層來講又是不可控的，因此性能瓶頸就出現了。

並且相對於機械硬盤，SSD 存儲還有一個「寫入放大」的問題。這個問題主要和 SSD 存儲的物理結構有關。當 SSD被所有寫過一遍以後，再寫入的數據是不能夠直接更新，只能夠經過覆蓋重寫，在覆蓋以前須要先擦除數據。但寫入的最小單位是 Page，擦除的最小單位是 Block，而 Block 遠大於 Page，因此在寫入新數據時就須要先把Block 上的數據讀出來和要寫入的數據合併在一塊兒，再把 Block 擦除，最後把讀出來的數據從新寫入到存儲上，這樣致使實際寫入的數據可能遠遠大於最開始須要寫入的數據。 

舉個最簡單的例子：

當要寫入一個 4KB 的數據時，最壞的狀況是一個塊裏已經沒有乾淨空間了，但有無效的數據能夠擦除，因此主控就把全部的數據讀到緩存，擦除塊，緩存裏 更新整個塊的數據，再把新數據寫回去，這個操做帶來的寫入放大就是: 實際寫 4K 的數據，形成了整個塊（共 512KB）的寫入操做，那就是放大了 128 倍。同時還帶來了本來只須要簡單一步寫入 4KB 的操做變成：閃存讀取 (512KB)→緩存改（4KB）→閃存擦除（512KB）→閃存寫入（512KB），共四步操做，形成延遲大大增長，速度變慢。 

只是簡單的寫文件就牽涉到這麼多的倒騰，這個時候咱們開始認識到一個高性能日誌模塊的重要性，既然每一個平臺都須要打印日誌，那爲何不開發一個通用的日誌模塊呢。 

在作以前，咱們要思考的一個比較重要的問題就是一個高性能日誌模塊須要實現什麼功能？須要有哪些方面的保證？是否已經有現有輪子可用了？

首先來看一下比較流行的服務端日誌框架都提供了哪些功能，如 Log4j, LOGBack 支持socket讀寫 支持直接寫數據庫 使用XML配置 針對一種日誌抽象層實現(如 SLF4J) …… 

可是 因爲終端設備的碎片化，用戶的多元化，使用場景的複雜化，咱們須要的日誌組件：  首先是保證流暢性，使用過程當中不能影響程序的性能。由於對於一個 App 來講，流暢性尤其重要，流暢性直接影響用戶體驗，最基本的流暢性的保證是使用了日誌不會致使卡頓，可是流暢性不只包括了系統沒有卡頓，還要儘可能保證沒有 CPU 峯值。  並且要保證日誌的完整性，任什麼時候刻都有日誌可查。不能由於程序被操做系統殺掉或者發生了未捕捉到的 Crash 就丟了部分日誌。  還有比較強的容錯性，當日志文件中的部分日誌數據損壞時應該儘可能最小化對整個日誌文件的影響。  最後保證必要的安全性，日誌內容須要進行加密。 以上能夠總結咱們須要一個 保證流暢性的前提下，高完整性，強容錯性，必要的安全性的日誌組件。 

服務端日誌框架提供的功能和咱們須要的功能對比能夠看出，現有的日誌框架很難知足咱們終端設備的需求，因此咱們開始着手造輪子。爲了兼容多平臺，咱們選用了 C++進行開發，雖然並非全部的函數都在 Android、iOS、Windows 等系統上通用，但絕大多數接口實際上是通用的，咱們只須要封裝個別的平臺相關接口就好了。

3. xlog-V1.0 方案

還記得最簡單的日誌方案是什麼樣的：對每一行日誌加密寫文件。 在這個方案中由於要寫入大量的 IO 致使程序卡頓，那是否能夠先把日誌緩存到內存中，當到必定大小時再加密寫進文件，爲了進一步減小須要加密和寫入的數據，在加密以前能夠先進行壓縮。 

針對這個想法就提出了xlog V1.0的方案。

方案描述：把日誌寫入到做爲 log 中間 buffer 的內存中，達到必定條件後壓縮加密寫進文件。  這個方案的基本流程圖以下： 

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

但這個方案卻存在一個致命的問題：丟日誌。

理想中的狀況：

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

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

**因此這個方案仍然存在不足： **

• 若是損壞一部分數據雖然不會累及整個日誌文件但會影響整個壓縮塊。
• 個別狀況下仍然會丟日誌，並且集中壓縮會致使 CPU 短期飆高。 

這個方案微信使用了很長的時間，但隨着 Android系統的升級，該方案已經不能知足使用需求了。再回頭看前面兩個方案，直接寫文件雖然不會丟日誌但會影響性能，使用內存作中間 buffer 緩存日誌可能會丟日誌。 

4. xlog-V2.0 方案

若是能夠把這兩個方案的優勢糅合在一塊，就是咱們真正須要的一個完整的日誌方案了。一個既有直接寫內存的性能，又有直接寫文件的可靠性的方案。也就是微信目前在用的xlog的方案。

4.1 mmap

爲了兼顧流暢性和完整性，咱們引入了 mmap,mmap 是使用邏輯內存對磁盤文件進行映射，中間只是進行映射沒有任何拷貝操做，避免了寫文件的數據拷貝。 操做內存就至關於在操做文件，避免了內核空間和用戶空間的頻繁切換。 

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

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

• 內存不足
• 進程退出
• 調用 msync 或者 munmap
• 不設置 MAP_NOSYNC 狀況下 30s-60s(僅限FreeBSD) 

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

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

4.2 壓縮

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

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

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

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

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

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

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

4.3 xlog 方案總結

總結一下方案，也就是xlog 的最終日誌方案：

使用流式壓縮方式對單行日誌進行壓縮，壓縮加密後寫進做爲 log 中間 buffer的 mmap 中，當 mmap 中的數據到達必定大小後再寫進磁盤文件中

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

在架構設計上也考慮了擴展性，好比日誌頭部的結構體是能夠隨意修改的 

輸出到文件的主要實現是在 Appender 模塊也是可插拔的，若是對默認的策略不滿意能夠本身實現一套。 

xlog還存在一些其餘策略：

• 每次啓動的時候會清理日誌，防止佔用太多用戶磁盤空間
• 爲了防止 sdcard 被拔掉致使寫不了日誌，支持設置緩存目錄，當 sdcard 插上時會把緩存目錄裏的日誌寫入到 sdcard 上
• ……

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

• 類型安全檢測方式：%s %d 。例如：xinfo(「%s %d」, 「test」, 1)
• 序號匹配的方式：%0 %1 。例如：xinfo(TSF」%0 %1 %0」, 「test」, 1)
• 智能匹配的懶人模式：%_ 。例如：xinfo(TSF」%_ %_」, 「test」, 1) 

5. 總結

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

從前面能夠看出，一個優秀的終端日誌模塊不管怎麼設計都必須作到：

• 不能把用戶的隱私信息打印到日誌文件裏，不能把日誌明文打到日誌文件裏。
• 不能影響程序的性能。最基本的保證是使用了日誌不會致使程序卡頓。
• 不能由於程序被系統殺掉，或者發生了 crash，crash 捕捉模塊沒有捕捉到致使部分時間點沒有日誌， 要保證程序整個生命週期內都有日誌。
• 不能由於部分數據損壞就影響了整個日誌文件，應該最小化數據損壞對日誌文件的影響。

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

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

6. mars 開源計劃

mars 計劃在年末開源，目前在走審覈流程。運做模式上面，會保證開放出去的代碼和微信在使用的代碼是同源的。具體開源時間以微信終端官方公衆帳號爲準。

個人分享就到這裏，謝謝你們。

互動問答

Q1：crash捕捉模塊具體能解釋下嘛？

crash捕捉模塊不在mars開源之列，能夠線下交流，若是想捕捉C++ crash 建議看Android 源碼 backtrace和libunwind方面。 若是是Java的Crash 我不大擅長，就不做答了。

Q2：應用這個日誌對服務器端有什麼要求？

全部的日誌行爲都是在終端上，嚴格說來和服務端沒有任何關係。

Q3： 安卓上調用C++打日誌還有沒有JNI的性能問題呢

在早期的Android 系統上JNI的性能的確是有點問題的，可是隨着谷歌認識到C++高性能的特性一直在這方面作相關優化。 如今Java調用C++性能損耗基本能夠不考慮。並且其實Java的應用層接口調用到底層也基本都是C來實現的。

Q4：日誌頭部的magic number 有什麼做用？

這裏有兩個做用，1. 能夠看出日誌頭部是沒設置版本號的，因此是根據magic num作了版本區分。 2. 壓縮加密後的日誌存到文件裏，再去解壓，是要區分日誌起始位置，以及是否損壞的。

Q5：感謝嘉賓精彩分享，受益不少，個人問題是，日誌存儲到sdcard後還會發送到服務端嗎，若是發送在什麼時機，若是不發crash信息如何及時瞭解。

客戶端的日誌絕大部分時間應該安安靜靜的在用戶手機上等待超時被刪除，若是某個用戶有反饋，由於日誌自己是個文件，用戶能夠經過應用把這個文件主動上傳到服務器。 好比 微信 也有特定的指令用戶輸入後會觸發上報。 至於crash信息，crash捕捉模塊捕捉到 能夠crash的時候一樣打印到日誌文件裏，並且crash信息也應該獨立於日誌的一個模塊，這個應該是必須上報的。

Q6：這個log主要是存儲哪些重要信息，是否能夠自定義一些數據存儲？ 好比app有一些特殊的數據也想寫進log

不能夠的。 除非本身轉換成string的描述。即便一個對象 也能夠把對象裏的關鍵性屬性打印到日誌裏。 仍是強調的一個點：日誌規範很重要，不只在於安全還在於 只打有用的信息。

Q7：我想問下加密這個環節，是對（多條日誌壓縮後的結果）進行加密嗎，也就是說壓縮後的日誌要達到必定的大小纔會進行加密嗎？若是是crash的時候，壓縮後的日誌沒有達到這個大小，是怎麼處理的呢？

不是的 你可能理解錯了。你說的這個方案是xlog V1.0的方案，你說的那個狀況也正是這個方案被拋棄的緣由，在V2.0方案會每寫一行日誌都會直接壓縮加密寫進mmap中。

Q8：關於日誌的上傳，是否在此開源之中？關於上報日誌，有怎樣的思考？好比時間，傳輸優化，收到後的解壓等問題？

不在 畢竟外部也不可能把大家的日誌放心交給咱們。關於上報日誌，要考慮上報有失敗的可能，因此須要重試，可是牽涉到比較大的數據，因此重試要有上限。考慮到服務器接收到數據須要存儲，使用多線程上報速度會有所提高。由於數據量比較大 最好把文件分片後再上傳， 甚至能夠考慮斷點續傳。

Q9：請問下mars和bugly有什麼異同？各自有什麼優點？

Bugly目前主要是異常上報服務，就是Crash監控。這一塊是不包含在mars裏的。兩個是互補的關係。 mars主要包含的功能是 日誌 信令網絡通道，網絡檢測以及一些跨平臺C++的基礎庫。都是在微信內使用的源碼。

Q10：xlog log存儲到內存中，大小怎麼計算，會根據手機適配嗎？

目前分配內存150kb，不會根據手機進行適配。 這個計算方式是咱們根據以前的測試的壓縮數據來反推的。

Q11：對於xlog中的加密以及壓縮能夠單獨接口使用嗎？

加密部分我不但願你們關注，這也是我分享中沒有分享的緣由。由於自己咱們不該該把用戶的隱私數據打印到日誌裏。 因此最終開源咱們不提供加密算法，但會提供本身實現加密的接口。 這兩塊都不提供單獨的接口使用，壓縮除了極端狀況下並無這麼用的必要，畢竟大多數狀況下是已知數據以後才進行的要說。

Q12：xlog是平臺無關的，爲何介紹提到Android的優化

瞭解安卓和iOS兩個平臺的人會知道最難伺候的是安卓平臺，給後臺運行權限又保留隨時殺掉你的權利。 丟日誌在安卓平臺更爲頻繁。

Q13：請問下本地存儲日誌時能否選擇數據庫而不用文件？須要傳給服務器時再查詢數據庫？

不太建議客戶端的日誌存在數據庫裏，有些服務器的日誌放在數據庫是由於爲了後續分析使用。 可是咱們知道稍微大點的數據都不要放到數據庫 更況且是日誌文件呢。並且存到數據庫會致使有大量的數據庫操做，這個性能要考慮。 最後 一個日誌模塊 我還須要拖一個sqlite的源碼進去 o(╯□╰)o，咱們但願這個模塊精簡到無可精簡的地步， 目前xlog 的so大小是120kb

Q14：單行壓縮的第四個方案，說累積壓縮後到必定大小，做爲一個壓縮單位，是何意啊？mmap回寫 是系統的行爲？須要咱們也爲這個過程作些工做嗎？

前面有張圖說短語式壓縮實際上是有兩個滑動窗口，實際上是要根據歷史數據進行匹配。可是考慮到性能滑動窗口並非無限大，因此歷史數據也不必給太多。一個壓縮單位意思就是壓縮狀態初始化到結束。 回寫基本能夠所有交給系統，咱們須要作的每次啓動程序去讀取mmap文件看是否有上個程序生命週期沒寫進文件的數據

---

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

騰訊 Bugly是一款專爲移動開發者打造的質量監控工具，幫助開發者快速，便捷的定位線上應用崩潰的狀況以及解決方案。智能合併功能幫助開發同窗把天天上報的數千條 Crash 根據根因合併分類，每日日報會列出影響用戶數最多的崩潰，精準定位功能幫助開發同窗定位到出問題的代碼行，實時上報能夠在發佈後快速的瞭解應用的質量狀況，適配最新的 iOS, Android 官方操做系統，鵝廠的工程師都在使用，快來加入咱們吧！