日誌收集系統在大搜車的探索和實踐

摘要：提前創建索引：業務日誌每到晚上零點的時候，都會堆積數據。首先分析下業務日誌的場景，大家基本上只查看自己應用的日誌，痛點是可能分佈在不同的機器上，經常使用的姿勢是根據關鍵字全文匹配。

引言

大搜車日誌分爲兩種：業務日誌和鏈路日誌。

業務日誌是業務開發人員在代碼裏面自己打印的日誌，爲方便開發人員快速查閱分佈在多臺機器上的日誌，我們提供了業務日至平臺，供開發自助接入。目前接入的系統 400+，每天產生的日誌量 7 億 +，高峯時期每秒要處理 5W+ 的日誌。

鏈路日誌對應的則是鏈路追蹤平臺（trace），通過 traceID 把跨系統調用的所有下游系統串聯起來，想要了解詳細的話可以參考開源的 pinpoint 。鏈路日誌每天日誌量 30 億 +，高峯每秒要處理 8W+ 的日誌。我們只保留七天的數據，大概 45T。

開源社區有很多優秀的日誌收集組件，如 logkit,logstack,flume 等。我們公司因爲早前就在其它場景下使用過 flume，運維同學也積累了豐富的運維經驗，所以採集組件直接使用的 flume。個人感覺而已，logkit 和 logstack 更輕量，作爲採集端更合適~

下面開始進入正題，介紹下我們的整體架構以及遇到的坑，還有就是根據自身的業務特點做的特殊優化~

整體架構圖

詳細說明

如上圖所示，整體上分爲四個模塊：日誌採集，日誌處理，日誌存儲以及展示和應用，下面開始詳細介紹每個模塊。

日誌採集

日誌採集最大的難題就是業務日誌在機器山存放的路徑以及文件名稱並不統一 (運維最開始沒有制定標準)，而且日誌格式和滾動策略等都是業務開發人員自己配置的。所以接入我們的系統需要使用方自己錄入日誌存放目錄以及通過 正則表達式 指定日誌格式 (如下圖)。配置好日誌目錄和格式，系統會把這些配置推送給 flume(開源版本不支持該推送配置的功能，我們修改了開源版本使其支持)，日誌採集就開始了。

第一步我就遇到了一個大坑，先說現象：有的應用莫名其妙的最新日誌就收集不上來了，登錄到機器上查看，發現採集進程還在，用 top 命令查看，發現日誌採集進程佔用 cpu 達到 100%

cpu100% 問題排查我就不詳訴了, 可以點超鏈接自行查看。通過線程堆棧，可以看到是正則表達式在搞鬼。這裏需要引入正則表達式的執行原理：

傳統的 NFA 引擎運行所謂的“貪婪的”匹配回溯算法（longest-leftmost），以指定順序測試正則表達式的所有可能的擴展並接受第一個匹配項。傳統的 NFA 回溯可以訪問完全相同的狀態多次，在最壞情況下，它的執行速度可能 非常慢 ，但它 支持子匹配 。代表性有： GNU Emacs,Java,ergp,less,more,.NET 語言, PCRE library,Perl,PHP,Python,Ruby,sed,vi 等，一般高級語言都採用該模式。

在通過下面這個實例理解下：

源字符 DEF, 匹配正則表達式是：/D\w+F/

匹配開始：

第一步，/D 正確匹配到 D, 而\w+ 會貪婪的匹配最長的字符串，也就是 EF。然後 F 因爲匹配不到任何字符，導致匹配失敗。

第二步，因爲上面的匹配失敗了，回溯算法往後退一位， /D 正確匹配到 D, 而\w+ 匹配到 E,F 匹配到 F, 匹配成功。

上面的例子因爲源字符串比較短，正則表達式也不復雜，所以只回溯了一次。但是我們的真實場景一條業務日誌長度幾百設置上千，而用戶寫的正則可能不止有\w+，還會有.+ 等等。所以這也就造成了上面的問題，最新日誌收集不上來（解析日誌耗費的時間太長了），而且 CPU100%（因爲一直在運算，並不是卡住）。

明確了問題直接上解決方案吧，不想鋪墊了。。。

第一步就是要快速失敗，如果解析一條日誌超過 100ms，就應該把它歸類爲解析失敗，繼續後面的日誌處理。所以可以把日誌解析丟到異步線程池中，主線程通過拿到的 Future 控制超時時間。

第二步就是如果超時了，要能夠中斷正在匹配的正則表達式。這個時候遇到的問題是正則表達式本身是不響應中斷，不過好在天無絕人之路，觀察發現正則表達式源字符串要求傳入的類型是 CharSequence ，而每次回溯時，都會調用 charAt 方法，所以可以通過創建一個新的類，實現 CharSequence ，並且在 charAt 中判斷是否被中斷。這樣的話，就可以讓正則表達式的解析過程響應中斷了~~， CharSequence 實現類代碼如下

 複製代碼

publicclassInterruptibleCharSequenceimplementsCharSequence{

CharSequence inner;

publicInterruptibleCharSequence(CharSequence inner){
super();
this.inner = inner;
}

@Override
publiccharcharAt(intindex){
if(Thread.currentThread().isInterrupted()) {
thrownewRuntimeException("Interrupted!");
}
returninner.charAt(index);
}

@Override
publicintlength(){
returninner.length();
}

@Override
publicCharSequencesubSequence(intstart,intend){
returnnewInterruptibleCharSequence(inner.subSequence(start, end));
}

@Override
publicStringtoString(){
returninner.toString();
}
}

日誌處理

所有機器上的 flume 採集程序，收集到的日誌會先上報給單獨搭建的 flume 代理層集羣，這是因爲運維不希望太多的機器直連 kaka。代理層沒有做任何處理，直接把日誌丟到 kafka。

kafka 的性能和穩定性是經過歷史驗證的，所以選它作爲中間緩存層沒什麼爭議。當然，其它的 mq 也更有優勢，可以根據公司技術棧靈活選擇。像號稱下一代的 mq:pulsar 我們也打算調研試用下~

爲什麼不直接寫後端的 ES 呢？這是因爲需要緩衝層來削峯填谷，可能有點抽象，舉個實際的例子，我們的業務高峯期，日誌的產生速度高於 ES 的寫入速度。業務系統那邊基本都會配置了日誌文件翻滾，這樣就有可能造成還沒來得及收上來的日誌被沖掉了。

kafka 後面掛的是 flink 集羣，上面跑了四個 job:

業務日誌 Job: 負責存儲業務日誌

鏈路日誌的 Job：負責存儲鏈路日誌

監控報表的 Job: 主要是統計一些指標，如 qps，錯誤率等等，利用到了 flink 的窗口

報警中心的 Job：業務日誌可以根據用戶自定義的報警規則報警，而鏈路日誌則可以對框架層面的超時，錯誤報警，如 dubbo 調用超時~

日誌存儲

日誌存儲主要是把數據寫入 ES，單獨來講是因爲不同的產品存儲方式不同。這塊也是整個系統最大的短板，爲了優化寫入做了很多工作。

業務日誌存儲

首先分析下業務日誌的場景，大家基本上只查看自己應用的日誌，痛點是可能分佈在不同的機器上，經常使用的姿勢是根據關鍵字全文匹配。而且以前使用 kibana 的時候，因爲分詞導致查詢出來的結果不精確很不爽。

針對這個特點，我們設計的後端存儲方式是：每個應用每天一個索引，同時創建索引的時候通過 MappingTemplate 禁用掉分詞。

優缺點：這是設計方式是面向單應用查詢的，所以查詢速度比較快，而且是全文匹配的暴力查詢，用戶體驗比較好。但是也導致了 ES 集羣中索引的數量過多，會多佔用一些內存。

還有一個小坑，是關於限流功能的。我們想實現的功能是，針對打日誌特別多的應用，比如說一天打幾千萬條的日誌，超過閾值就自動限流該應用，後面的日誌就不採集了。統計應用每天的日誌量，是放在 flink 集羣做的，但是實際應用中發現，當 flink 統計到某個應用採集量已經達到上限，比如說 1000W，想要限流已經爲時已晚，因爲這時候這個應用可能已經有 5000W 日誌堆在 kafka 了。也就是說，在 flink 集羣統計有嚴重的滯後性，後來我們又在 flume 採集的時候增加了單機限流。

鏈路日誌存儲

鏈路日誌的數據量特別龐大，同時因爲經常需要跨系統查詢，所以不能按照系統的維度建索引。不過相對於業務日誌，因爲都是框架層面打印的，所以格式是統一的。針對這種特點，按照每小時建一個索引，保證索引數據量不會太大。Mapping 策略上，也是禁用分詞，提前解析出（應用，路徑，環境，線程）字段，讓 ES 索引起來。這樣用戶在界面上根據這些字段過濾就會有比較好的性能表現。

其它的寫入性能優化

在接入量快速增長的階段，ES 首先扛不住了，寫入性能無法滿足快速增長的日誌量。雖然可能通過加機器緩解問題，但成本也要控制，所以優化 ES 寫入性能迫在眉睫，下面列出的是實踐過程中最有效的方式，其它的可以自行百度~

增大刷盤時間 (refresh_interval): 默認是 1s，我們時間過程中調到了 5s。調大之後寫入性能上升還是比較明顯的，帶來的問題是日誌寫入 5s 之後才能被查詢到，不過 5s 延遲延遲業務上是完全可以接受的。
0 備份並且關掉事務日誌（“durability”: “async”）：這個對寫入性能的提高是大幅度的，幾乎是兩倍的提升，我們的集羣最高可以寫到 15W+。但是問題是無法保證可靠性，萬一掛了怎麼辦？我們的解決方式是 kafka 保存 12 小時的數據 + 低峯期（晚上）備份。首先 kafka 保存 12 小時的數據保證了即使 flink 掛了或者 ES 掛了，都可以通過重置消費位點把數據找回來。晚上備份的話，保證了十二小時之前的數據就不會丟了
提前創建索引：業務日誌每到晚上零點的時候，都會堆積數據。這是因爲這個時候在大量的創建索引，寫入速度自然受影響。解決思路就是提前把索引創建好
第三方冪等：首先說明這個我還沒嘗試過，因爲現在寫入性能夠了，就沒怎麼在折騰，思路寫出來供大家參考。我們爲了防止 ES 數據重複寫入，是通過指定 id 的方式實現了冪等。這個對 ES 性能消耗還是比較大的（大概 15%）。並且 index 的數據規模越大，性能越低，因爲它要判斷這個 id 是否已經存在。如果把這個冪等控制拿到外面去做，讓 ES 直接存就好了，性能肯定有進一步提升