作者：Hacker_ubN7WXjw
一、背景
伴魚少兒英語是目前飛速成長的網際網路線上英語教育品牌之一，特别在疫情這段時間内，業務增長近3-4倍。伴魚慢日志系統對于幫助我們及時發現資料庫性能問題和預防資料庫性能風險，起到了很大的作用。
目前，伴魚有10套TiDB資料庫，20+套mongodb資料庫，200+資料庫執行個體。日常資料庫性能問題處理，由于慢日志分散在多台機器，面臨日志查詢/分析/統計等各種不便。是以，我們的慢日志系統，需要滿足以下幾個要求：
1）慢日志集中準實時收集
2）日志查詢/分析/統計可視化
3）慢日志報表功能
4）慢日志及時告警
下面主要介紹下伴魚慢日志系統以及系統給我們帶來的實實在在的效果。
二、慢日志系統詳解
我們認為資料庫的性能問題，絕大部分原因都是由慢SQL導緻的，當然像資料庫bug、業務異常流量等情況，在伴魚還是比較少見的。是以，我們如何準實時收集分布式TiDB的慢日志、如何快速的做分析統計以及如何及時的告警，對于快速解決線上問題，甚至将性能風險扼殺在搖籃裡至關重要。
1）如何準實時收集慢日志
我們采用了業界比較成熟的開源日志采集、分析、存儲和展示架構，很好的解決了我們對慢日志的處理需求。
在上圖中，filebeat負責增量收集TiDB産生的慢日志，由于filebeat比較輕量，對線上性能基本無影響。采集配置如下，其中service用于區分資料來源，在logstash解析階段會用到；ip在filebeat部署階段自動補上，主要用于分析階段識别日志來源機器；exclude_lines排除掉非增删改查語句，便于後續解析。
原始慢日志(見下圖)經過filebeat采集階段簡單處理後，存儲到kafka。存儲到kafka的慢日志内容格式，如下圖所示。
原始日志格式
采集後的日志格式
然後logstash負責讀取kafka中的慢日志并進行解析，轉換成我們想要的kv鍵值對，如下圖所示。
最後解析後的資料入到es，供kibana查詢分析統計。
對于TiDB的慢日志，我們重點關注慢日志中的某些特定字段，比如：
index_name: 語句執行過程中是否用到索引
DB：表示執行語句時使用的database。
query_time：表示執行這個語句花費的時間。
total_keys：表示Coprocessor掃過的key的數量。
process_keys：表示Coprocessor處理的key的數量。相比total_keys，processed_keys不包含 MVCC的舊版本。
sql：執行的sql語句
2) 如何對慢日志進行分析統計
慢日志通過logstash解析後入到es，通過kibana，我們可以利用解析的字段作為查詢和聚合的條件，很友善的對資料進行分析統計。
比如我們經常有如下操作：
1）30分鐘内，慢請求分别按照db和table聚合
2）30分鐘内，Process_keys大于5000的慢請求
3）30分鐘内，query_time大于500ms的請求
當然分析統計遠不止這些，研發同學還可以在平台上定制所屬業務db的趨勢圖和告警等。同時基于慢日志資料，我們還開發了慢日志分析報表平台，從多種次元，比如叢集、庫、表、操作類型、慢日志數量、執行總時間、平均響應時間以及最大耗時等次元對慢日志進行分析統計，并産生報表定時發送給研發同學。
3）如何對慢日志進行告警
在伴魚，一個db對應一個服務，是以告警都是在特定db下設定規則。目前，我們告警粒度是一分鐘，主要基于以下三類預設規則告警。
a) 某個db下的請求時間達到100ms且慢日志達到一定數量則告警
b) 某個db下的請求時間達到500ms且慢日志達到一定數量則告警
c) 某個db下的請求Process_keys大于5000且慢日志達到一定數量則告警
當然告警規則的設定不是一蹴而就的，需要根據不同的業務場景，dba和研發不斷的調整，最終達到一個比較合理的閥值。
三、慢日志系統給伴魚帶來的收益
目前，我們10個TiDB叢集，有6個核心叢集請求過萬，見下圖。慢日志系統運作到現在，主要給我們帶來3個收益。
1）延時低，6個請求過萬核心叢集999線基本維持在16ms左右，見下圖
2）慢日志越來越少，tidb所有叢集的慢日志(大于200ms)，30分鐘内，高峰期條數基本維持在500以内
3）故障少，除一次tidb優化器bug導緻大表查詢故障，影響線上近10分鐘。近半年沒有tidb引發的線上故障。