作者介紹
魏彬,普翔科技 CTO,開源軟體愛好者,中國第一位 Elastic 認證工程師,《Elastic日報》和 《ElasticTalk》社群項目發起人,被 elastic 中國公司授予 2019 年度合作夥伴架構師特别貢獻獎。對 Elasticsearch、Kibana、Beats、Logstash、Grafana 等開源軟體有豐富的實踐經驗,為零售、金融、保險、證券、科技等衆多行業的客戶提供過咨詢和教育訓練服務,幫助客戶在實際業務中找準開源軟體的定位,實作從 0 到 1 的落地、從 1 到 N 的拓展,産生實際的業務價值。
Redis slowlog簡介
Redis 是目前最流行的緩存系統,因其豐富的資料結構和良好的性能表現,被各大公司廣泛使用。盡管 redis 性能極佳,但若不注意使用方法,極容易出現慢查詢,慢查詢多了或者一個 20s 的慢查詢會導緻操作隊列( redis 是單程序)堵塞,最終引起雪崩甚至整個服務不可用。對于慢查詢語句,redis 提供了相關的配置和指令。
配置有兩個:slowlog-log-slower-than 和 slowlog-max-len。slowlog-log-slower-than 是指當指令執行時間(不包括排隊時間)超過該時間時會被記錄下來,機關為微秒,比如通過下面的指令,就可以記錄執行時長超過 20ms 的指令了。
config set slowlog-log-slower-than 20000
slowlog-max-len 是指 redis 可以記錄的慢查詢指令的總數,比如通過下面的指令,就可以記錄最近 100 條慢查詢指令了。
config set slowlog-max-len 100
操作慢查詢的指令有兩個:slowlog get [len] 和 slowlog reset。slowlog get [len]指令擷取指定長度的慢查詢清單。
redis 127.0.0.1:6379> slowlog get 2
1) 1) (integer) 14
2) (integer) 1309448221
3) (integer) 15
4) 1) "ping"
2) 1) (integer) 13
2) (integer) 1309448128
3) (integer) 30
4) 1) "slowlog"
2) "get"
3) "100"
上面傳回了兩個慢查詢指令,其中每行的含義如下:
1、第一行是一個慢查詢id。該 id 是自增的,隻有在 redis server 重新開機時該id才會重置。
2、第二行是慢查詢指令執行的時間戳
3、第三行是慢查詢指令執行耗時,機關為微秒
4、第四行是慢查詢指令的具體内容。
slowlog reset 指令是清空慢日志隊列。
Elastic Stack
Elastic Stack 是 Elastic 公司 的一系列開源軟體産品,包括 Elasticsearch、Kibana、Logstash、Beats 等,當然你也可以選擇
阿裡雲 Elasticsearch,不僅100%相容開源,同時擁有完整雲上Elastic Stack生态,并提供免費 X-Pack(價值6000美金);在本次分析過程中,我們會用到 elasticsearch、kibana 和 beats 三款産品。elasticsearch用來存儲解析後的 redis slowlog,kibana 用于圖形化分析,beats 用于收集 redis slowlog。
這裡着重講一下 beats,它是一系列輕量級的資料收集産品統稱,目前官方提供了 filebeat、packetbeat、heartbeat、metricbeat 等,可以用來收集日志檔案、網絡包、心跳包、各類名額資料等。像我們這次要收集的redis slowlog,官方還沒有提供相關工具,需要我們自己實作,但借助beats的一系列腳手架工具,我們可以友善快速的建立自己的 rsbeat---redis slowlog beat。
rsbeat原理簡介
接下來我們先講解一下 rsbeat 的實作原理,一圖勝千言,我們先來看下它的工作流。

rsbeat工作流
我們由下往上分析:
1、最下面是我們要分析的 redis server 清單
2、再往上便是 rsbeat,它會與這些redis server建立連接配接并定期去拉取 slowlog。
3、在啟動時,rsbeat 會發送下面的指令到每一台 redis server,來完成 slowlog 的配置,這裡設定記錄最近執行時長超過 20ms 的 500 條指令。
config set slowlog-log-slower-than 20000
config set slowlog-max-len 500
slowlog reset
4、然後 rsbeat 會定時去拉取每台 redis server 的慢查詢指令
slowlog get 500
slowlog reset
注意之類 slowlog reset 是因為此次已經将所有的慢日志都取出了,下次擷取時取最新生成的,防止重複計算。
5、rsbeat 将解析的慢日志釋出到 elasticsearch 中進行存儲
6、通過kibana 進行 slowlog 的圖形化分析
rsbeat 的整個工作流到這裡已經介紹完畢了,是不是很簡單呢?下面我們來簡單看一下 rsbeat 的核心代碼實作。
sbeat核心代碼講解
rsbeat 已經在 github 上開源了,感興趣的同學可以自己去下下來使用。下面我們分析的代碼位于beater/rsbeat.go,這也是 rsbeat 的核心檔案。
func poolInit(server string, slowerThan int) *redis.Pool {
return &redis.Pool{
MaxIdle: 3,
MaxActive: 3,
IdleTimeout: 240 * time.Second,
Dial: func() (redis.Conn, error) {
c, err := redis.Dial("tcp", server, redis.DialConnectTimeout(3*time.Second), redis.DialReadTimeout(3*time.Second))
if err != nil {
logp.Err("redis: error occurs when connect %v", err.Error())
return nil, err
}
c.Send("MULTI")
c.Send("CONFIG", "SET", "slowlog-log-slower-than", slowerThan)
c.Send("CONFIG", "SET", "slowlog-max-len", 500)
c.Send("SLOWLOG", "RESET")
r, err := c.Do("EXEC")
if err != nil {
logp.Err("redis: error occurs when send config set %v", err.Error())
return nil, err
}
logp.Info("redis: config set %v", r)
return c, err
},
TestOnBorrow: func(c redis.Conn, t time.Time) error {
_, err := c.Do("PING")
logp.Info("redis: PING")
return err
},
}
}
poolInit 方法是 rsbeat 初始化時進行的操作,這裡也就是發送 slowlog 配置的地方,代碼很簡單,就不展開解釋了。
func (bt *Rsbeat) redisc(beatname string, init bool, c redis.Conn, ipPort string) {
defer c.Close()
logp.Info("conn:%v", c)
c.Send("SLOWLOG", "GET")
c.Send("SLOWLOG", "RESET")
logp.Info("redis: slowlog get. slowlog reset")
c.Flush()
reply, err := redis.Values(c.Receive()) // reply from GET
c.Receive() // reply from RESET
logp.Info("reply len: %d", len(reply))
for _, i := range reply {
rp, _ := redis.Values(i, err)
var itemLog itemLog
var args []string
redis.Scan(rp, &itemLog.slowId, &itemLog.timestamp, &itemLog.duration, &args)
argsLen := len(args)
if argsLen >= 1 {
itemLog.cmd = args[0]
}
if argsLen >= 2 {
itemLog.key = args[1]
}
if argsLen >= 3 {
itemLog.args = args[2:]
}
logp.Info("timestamp is: %d", itemLog.timestamp)
t := time.Unix(itemLog.timestamp, 0).UTC()
event := common.MapStr{
"type": beatname,
"@timestamp": common.Time(time.Now()),
"@log_timestamp": common.Time(t),
"slow_id": itemLog.slowId,
"cmd": itemLog.cmd,
"key": itemLog.key,
"args": itemLog.args,
"duration": itemLog.duration,
"ip_port": ipPort,
}
bt.client.PublishEvent(event)
}
}
redisc 方法實作了定時從 redis server 拉取最新的 slowlog 清單,并将它們轉化為 elasticsearch 中可以存儲的資料後,釋出到 elasticsearch 中。這裡重點說下每一個字段的含義:
1、@timestamp 是指目前時間戳。
2、@log_timestamp 是指慢日志指令執行的時間戳。
3、slow_id 是該慢日志的id。
4、cmd 是指執行的 redis 指令,比如sadd、scard等等。
5、key 是指 redis key 的名稱
6、args 是指 redis 指令的其他參數,通過 cmd、key、args我們可以完整還原執行的 redis 指令。
7、duration 是指 redis 指令執行的具體時長,機關是微秒。
8、ip_port 是指發生指令的 redis server 位址。
有了這些字段,我們就可以用 kibana 來愉快的進行可視化資料分析了。
Kibana 圖形化分析 slowlog
Kibana 提供了非常友善的資料分析操作,這裡不展開解釋了,感興趣的可以自行去學習,這裡直接上圖,看下最終的分析結果。
清單詳情頁
時間段自由指定
檢視慢日志按照時間的分布情況
上圖可以看到最近有一個很明顯的數量減少,原因是我們解決了相關的慢查詢。
按慢查詢數目來檢視cmd分布和key分布
按慢查詢時長來檢視cmd分布和key分布
表格呈現慢查詢的具體指令
看完上面的截圖,有沒有心動,想親自操刀試一下?Kibana 操作起來非常簡單,尤其對于程式員來講,使用起來得心應手。趕緊下載下傳 rsbeat 下來自己試一下吧!
總結
随着 elastic stack 的發展,其使用門檻越來越低,我認為目前所有的有志于做資料分析的工程師都應該了解和掌握它的用法。有了它的幫助,你可以以極快的速度搭建起自己的一套免費強大的資料分析軟體,它的優點包括但不限于下面提到的:
1、資料源任意且自定制。隻要你能将資料讀取出來并存儲到 elasticsearch 中即可分析。
2、支援海量資料分析。得益于 elastic 多年的迅猛發展,其産品已經非常成熟,上TB的資料都可以輕松應對存儲與分析。有了它,你就可以舍棄資料一多就卡頓的 excel 了。
3、強大的開源社群支援。elastic 産品的迅猛發展離不開開源社群的支援,你隻要在社群中提出自己的問題或者需求,總會有人即時給你答複和建議。如果你有一定的開發能力,那麼完全可以按照自己的想法來折騰。
别再看了,趕緊去自己動手實踐下吧!
聲明:本文由原文《用 elastic stack 來分析下你的 redis slowlog》作者“魏彬”授權轉載,對未經許可擅自使用者,保留追究其法律責任的權利。
【
阿裡雲Elastic Stack】100%相容開源ES,獨有9大能力,提供免費X-pack服務(單節點價值$6000)
相關活動
更多折扣活動,請
通路阿裡雲 Elasticsearch 官網 阿裡雲 Elasticsearch 商業通用版,1核2G ,SSD 20G首月免費 阿裡雲 Logstash 2核4G首月免費