用elastic stack來分析下你的redis slowlog

用elastic stack來分析下你的redis slowlog

來自專欄 猿論

redis是目前最流行的 NoSQL 內存資料庫，然而如果在使用過程中出現濫用、亂用的情況，很容易發生性能問題，此時我們就要去關注慢查詢日誌，本文嘗試給大家介紹一種通過 elastic stack 來快速分析 redis 慢查詢日誌的方法，希望能給大家提供幫助。

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 21) 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、kibana和beats三款產品。elasticsearch用來存儲解析後的redis slowlog，kibana用於圖形化分析，beats用於收集redis slowlog。

這裡著重講一下beats，它是一系列輕量級的數據收集產品統稱，目前官方提供了filebeat、packetbeat、heartbeat、metricbeat等，可以用來收集日誌文件、網路包、心跳包、各類指標數據等。像我們這次要收集的redis slowlog，官方還沒有提供相關工具，需要我們自己實現，但藉助beats的一系列腳手架工具，我們可以方便快速的創建自己的rsbeat---redis slowlog beat。

rsbeat原理簡介

接下來我們先講解一下rsbeat的實現原理，一圖勝千言，我們先來看下它的工作流。

我們由下往上分析：

1. 最下面是我們要分析的redis server列表
2. 再往上便是rsbeat，它會與這些redis server建立連接並定期去拉取 slowlog。
1. 在啟動時，rsbeat會發送下面的命令到每一台redis server，來完成slowlog的配置，這裡設置記錄最近執行時長超過20ms的500條命令。config set slowlog-log-slower-than 20000
   config set slowlog-max-len 500
   slowlog reset
2. 然後rsbeat會定時去拉取每台redis server的慢查詢命令slowlog get 500
   slowlog reset

注意之類slowlog reset是因為此次已經將所有的慢日誌都取出了，下次獲取時取最新生成的，防止重複計算。

1. rsbeat將解析的慢日誌發布到elasticsearch中進行存儲
2. 通過kibana進行slowlog的圖形化分析

rsbeat的整個工作流到這裡已經介紹完畢了，是不是很簡單呢？下面我們來簡單看一下rsbeat的核心代碼實現。

rsbeat核心代碼講解

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提供了非常方便的數據分析操作，這裡不展開解釋了，感興趣的可以自行去學習，這裡直接上圖，看下最終的分析結果。

上圖可以看到最近有一個很明顯的數量減少，原因是我們解決了相關的慢查詢。

看完上面的截圖，有沒有心動，想親自操刀試一下？Kibana操作起來非常簡單，尤其對於程序員來講，使用起來得心應手。趕緊下載rsbeat下來自己試一下吧！

總結

隨著 elastic stack 的發展，其使用門檻越來越低，我認為目前所有的有志於做數據分析的工程師都應該了解和掌握它的用法。有了它的幫助，你可以以極快的速度搭建起自己的一套免費強大的數據分析軟體，它的優點包括但不限於下面提到的：

1. 數據源任意且自定製。只要你能將數據讀取出來並存儲到elasticsearch中即可分析。
2. 支持海量數據分析。得益於elastic多年的迅猛發展，其產品已經非常成熟，上TB的數據都可以輕鬆應對存儲與分析。有了它，你就可以捨棄數據一多就卡頓的excel了。
3. 強大的開源社區支持。elastic產品的迅猛發展離不開開源社區的支持，你只要在社區中提出自己的問題或者需求，總會有人即時給你答覆和建議。如果你有一定的開發能力，那麼完全可以按照自己的想法來折騰。

別再看了，趕緊去自己動手實踐下吧！

作者： rockybean

鏈接：https://www.imooc.com/article/27282

來源：慕課網

---

推薦閱讀：

打造個人品牌 so easy ！_慕課手記

Vue.js、vue安裝步驟、單文件組件、模板指令

配置MySQL開啟遠程連接的方法

如何解決MaxScale2.2版本無法load MySQL用戶的問題

搜索：ElasticSearch OR MySQL?

推薦閱讀：