文章來(lái)源：linux性能優(yōu)化實(shí)戰(zhàn)

redis 是最常用的鍵值存儲(chǔ)系統(tǒng)之一，常用作數(shù)據(jù)庫(kù)、高速緩存和消息隊(duì)列代理等。Redis 基于內(nèi)存來(lái)存儲(chǔ)數(shù)據(jù)，不過(guò)，為了保證在服務(wù)器異常時(shí)數(shù)據(jù)不丟失，很多情況下，我們要為它配置持久化，而這就可能會(huì)引發(fā)磁盤(pán) I/O 的性能問(wèn)題。

今天，我就帶你一起來(lái)分析一個(gè)利用 Redis 作為緩存的案例。

這同樣是一個(gè)基于 Python Flask 的應(yīng)用程序，它提供了一個(gè) 查詢緩存的接口，但接口的響應(yīng)時(shí)間比較長(zhǎng)，并不能滿足線上系統(tǒng)的要求。

非常感謝攜程系統(tǒng)研發(fā)部資深后端工程師董國(guó)星，幫助提供了今天的案例。

案例準(zhǔn)備

本次案例還是基于 Ubuntu 18.04，同樣適用于其他的 Linux 系統(tǒng)。我使用的案例環(huán)境如下所示：

機(jī)器配置：2 CPU，8GB 內(nèi)存

預(yù)先安裝 Docker、sysstat 、git、make 等工具，如 apt install docker.io sysstat

今天的案例由 Python 應(yīng)用 +Redis 兩部分組成。其中，Python 應(yīng)用是一個(gè)基于 Flask 的應(yīng)用，它會(huì)利用 Redis ，來(lái)管理應(yīng)用程序的緩存，并對(duì)外提供三個(gè) HTTP 接口：

/：返回 hello redis；

/init/：插入指定數(shù)量的緩存數(shù)據(jù)，如果不指定數(shù)量，默認(rèn)的是 5000 條；

緩存的鍵格式為 uuid:

緩存的值為 good、bad 或 normal 三者之一

/get_cache/<type_name>：查詢指定值的緩存數(shù)據(jù)，并返回處理時(shí)間。其中，type_name 參數(shù)只支持 good, bad 和 normal（也就是找出具有相同 value 的 key 列表）。

由于應(yīng)用比較多，為了方便你運(yùn)行，我把它們打包成了兩個(gè) Docker 鏡像，并推送到了 Github 上。這樣你就只需要運(yùn)行幾條命令，就可以啟動(dòng)了。

今天的案例需要兩臺(tái)虛擬機(jī)，其中一臺(tái)用作案例分析的目標(biāo)機(jī)器，運(yùn)行 Flask 應(yīng)用，它的 IP 地址是 192.168.0.10；而另一臺(tái)作為客戶端，請(qǐng)求緩存查詢接口。我畫(huà)了一張圖來(lái)表示它們的關(guān)系。

接下來(lái)，打開(kāi)兩個(gè)終端，分別 SSH 登錄到這兩臺(tái)虛擬機(jī)中，并在第一臺(tái)虛擬機(jī)中安裝上述工具。

跟以前一樣，案例中所有命令都默認(rèn)以 root 用戶運(yùn)行，如果你是用普通用戶身份登陸系統(tǒng)，請(qǐng)運(yùn)行 sudo su root 命令切換到 root 用戶。

到這里，準(zhǔn)備工作就完成了。接下來(lái)，我們正式進(jìn)入操作環(huán)節(jié)。

案例分析

首先，我們?cè)诘谝粋€(gè)終端中，執(zhí)行下面的命令，運(yùn)行本次案例要分析的目標(biāo)應(yīng)用。正常情況下，你應(yīng)該可以看到下面的輸出：

$ docker run

ec41cb9e4dd5cb7079e1d9f72b7cee7de67278dbd3bd0956b4c0846bff211803

然后，再運(yùn)行 docker ps 命令，確認(rèn)兩個(gè)容器都處于運(yùn)行（Up）狀態(tài)：

$ docker ps
CONTAINER ID        IMAGE                 COMMAND                  CREATED             STATUS              PORTS                             NAMES
2c54eb252d05        feisky/redis-App      "python /app.py"         48 seconds ago      Up 47 seconds                                         app
ec41cb9e4dd5        feisky/redis-server   "docker-entrypoint.s…"   49 seconds ago      Up 48 seconds       6379/tcp, 0.0.0.0:10000->80/tcp   redis

比如，我們切換到第二個(gè)終端，使用 curl 工具，訪問(wèn)應(yīng)用首頁(yè)。如果你看到 hello redis 的輸出，說(shuō)明應(yīng)用正常啟動(dòng)：

接下來(lái)，繼續(xù)在終端二中，執(zhí)行下面的 curl 命令，來(lái)調(diào)用應(yīng)用的 /init 接口，初始化 Redis 緩存，并且插入 5000 條緩存信息。這個(gè)過(guò)程比較慢，比如我的機(jī)器就花了十幾分鐘時(shí)間。耐心等一會(huì)兒后，你會(huì)看到下面這行輸出：

# 案例插入5000條數(shù)據(jù)，在實(shí)踐時(shí)可以根據(jù)磁盤(pán)的類(lèi)型適當(dāng)調(diào)整，比如使用SSD時(shí)可以調(diào)大，而HDD可以適當(dāng)調(diào)小

$ curl http:
{"elapsed_seconds":30.26814079284668,"keys_initialized":5000}

繼續(xù)執(zhí)行下一個(gè)命令，訪問(wèn)應(yīng)用的緩存查詢接口。如果一切正常，你會(huì)看到如下輸出：

$ curl http:
{"count":1677,"data":["d97662fa-06ac-11e9-92c7-0242ac110002",...],"elapsed_seconds":10.545469760894775,"type":"good"}

我們看到，這個(gè)接口調(diào)用居然要花 10 秒！這么長(zhǎng)的響應(yīng)時(shí)間，顯然不能滿足實(shí)際的應(yīng)用需求。

到底出了什么問(wèn)題呢？我們還是要用前面學(xué)過(guò)的性能工具和原理，來(lái)找到這個(gè)瓶頸。

不過(guò)別急，同樣為了避免分析過(guò)程中客戶端的請(qǐng)求結(jié)束，在進(jìn)行性能分析前，

我們先要把 curl 命令放到一個(gè)循環(huán)里來(lái)執(zhí)行。你可以在終端二中，繼續(xù)執(zhí)行下面的命令：

$ while true; do curl http:

接下來(lái)，再重新回到終端一，查找接口響應(yīng)慢的“病因”。

最近幾個(gè)案例的現(xiàn)象都是響應(yīng)很慢，這種情況下，我們自然先會(huì)懷疑，是不是系統(tǒng)資源出現(xiàn)了瓶頸。

所以，先觀察 CPU、內(nèi)存和磁盤(pán) I/O 等的使用情況肯定不會(huì)錯(cuò)。

我們先在終端一中執(zhí)行 top 命令，分析系統(tǒng)的 CPU 使用情況：

$ top
top - 12:46:18 up 11 days,  8:49,  1 user,  load average: 1.36, 1.36, 1.04
Tasks: 137 total,   1 running,  79 sleeping,   0 stopped,   0 zombie
%Cpu0  :  6.0 us,  2.7 sy,  0.0 ni,  5.7 id, 84.7 wa,  0.0 hi,  1.0 si,  0.0 st
%Cpu1  :  1.0 us,  3.0 sy,  0.0 ni, 94.7 id,  0.0 wa,  0.0 hi,  1.3 si,  0.0 st
KiB Mem :  8169300 total,  7342244 free,   432912 used,   394144 buff/cache
KiB Swap:        0 total,        0 free,        0 used.  7478748 avail Mem
 PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
9181 root      20   0  193004  27304   8716 S   8.6  0.3   0:07.15 python
9085 systemd+  20   0   28352   9760   1860 D   5.0  0.1   0:04.34 redis-server
 368 root      20   0       0      0      0 D   1.0  0.0   0:33.88 jbd2/sda1-8
 149 root       0 -20       0      0      0 I   0.3  0.0   0:10.63 kworker/0:1H
1549 root      20   0  236716  24576   9864 S   0.3  0.3  91:37.30 python3

觀察 top 的輸出可以發(fā)現(xiàn)，CPU0 的 iowait 比較高，已經(jīng)達(dá)到了 84%；而各個(gè)進(jìn)程的 CPU 使用率都不太高，最高的 python 和 redis-server ，也分別只有 8% 和 5%。再看內(nèi)存，總內(nèi)存 8GB，剩余內(nèi)存還有 7GB 多，顯然內(nèi)存也沒(méi)啥問(wèn)題。

綜合 top 的信息，最有嫌疑的就是 iowait。所以，接下來(lái)還是要繼續(xù)分析，是不是 I/O 問(wèn)題。

還在第一個(gè)終端中，先按下 Ctrl+C，停止 top 命令；然后，執(zhí)行下面的 IOStat 命令，查看有沒(méi)有 I/O 性能問(wèn)題：

$ iostat -d -x 1
Device            r/s     w/s     rkB/s     wkB/s   rrqm/s   wrqm/s  %rrqm  %wrqm r_await w_await aqu-sz rareq-sz wareq-sz  svctm  %util
...
sda              0.00  492.00      0.00   2672.00     0.00   176.00   0.00  26.35    0.00    1.76   0.00     0.00     5.43   0.00   0.00

觀察 iostat 的輸出，

我們發(fā)現(xiàn)，磁盤(pán) sda 每秒的寫(xiě)數(shù)據(jù)（wkB/s）為 2.5MB，I/O 使用率（%util）是 0。

看來(lái)，雖然有些 I/O 操作，但并沒(méi)導(dǎo)致磁盤(pán)的 I/O 瓶頸。

排查一圈兒下來(lái)，CPU 和內(nèi)存使用沒(méi)問(wèn)題，I/O 也沒(méi)有瓶頸，接下來(lái)好像就沒(méi)啥分析方向了？

碰到這種情況，還是那句話，反思一下，是不是又漏掉什么有用線索了。

你可以先自己思考一下，從分析對(duì)象（案例應(yīng)用）、系統(tǒng)原理和性能工具這三個(gè)方向下功夫，回憶它們的特性，查找現(xiàn)象的異常，再繼續(xù)往下走。

回想一下，今天的案例問(wèn)題是從 Redis 緩存中查詢數(shù)據(jù)慢。

對(duì)查詢來(lái)說(shuō)，對(duì)應(yīng)的 I/O 應(yīng)該是磁盤(pán)的讀操作，但剛才我們用 iostat 看到的卻是寫(xiě)操作。

雖說(shuō) I/O 本身并沒(méi)有性能瓶頸，但這里的磁盤(pán)寫(xiě)也是比較奇怪的。

為什么會(huì)有磁盤(pán)寫(xiě)呢？那我們就得知道，到底是哪個(gè)進(jìn)程在寫(xiě)磁盤(pán)。

要知道 I/O 請(qǐng)求來(lái)自哪些進(jìn)程，還是要靠我們的老朋友 pidstat。在終端一中運(yùn)行下面的 pidstat 命令，觀察進(jìn)程的 I/O 情況：

$ pidstat -d 1
12:49:35      UID       PID   kB_rd/s   kB_wr/s kB_ccwr/s iodelay  Command
12:49:36        0       368      0.00     16.00      0.00      86  jbd2/sda1-8
12:49:36      100      9085      0.00    636.00      0.00       1  redis-server
從 pidstat 的輸出，我們看到，I/O 最多的進(jìn)程是 PID 為 9085 的 redis-server，并且它也剛好是在寫(xiě)磁盤(pán)。這說(shuō)明，確實(shí)是 redis-server 在進(jìn)行磁盤(pán)寫(xiě)。

當(dāng)然，光找到讀寫(xiě)磁盤(pán)的進(jìn)程還不夠，我們還要再用 strace+lsof 組合，看看 redis-server 到底在寫(xiě)什么。

接下來(lái)，還是在終端一中，執(zhí)行 strace 命令，并且指定 redis-server 的進(jìn)程號(hào) 9085：

# -f表示跟蹤子進(jìn)程和子線程，-T表示顯示系統(tǒng)調(diào)用的時(shí)長(zhǎng)，-tt表示顯示跟蹤時(shí)間

$ strace -f -T -tt -p 9085

[pid  9085] 14:20:16.826131 epoll_pwait(5, [{EPOLLIN, {u32=8, u64=8}}], 10128, 65, NULL, 8) = 1 <0.000055>
[pid  9085] 14:20:16.826301 read(8, "*2rn$3rnGETrn$41rnuuid:5b2e76cc-"..., 16384) = 61 <0.000071>
[pid  9085] 14:20:16.826477 read(3, 0x7fff366a5747, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000063>
[pid  9085] 14:20:16.826645 write(8, "$3rnbadrn", 9) = 9 <0.000173>
[pid  9085] 14:20:16.826907 epoll_pwait(5, [{EPOLLIN, {u32=8, u64=8}}], 10128, 65, NULL, 8) = 1 <0.000032>
[pid  9085] 14:20:16.827030 read(8, "*2rn$3rnGETrn$41rnuuid:55862ada-"..., 16384) = 61 <0.000044>
[pid  9085] 14:20:16.827149 read(3, 0x7fff366a5747, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000043>
[pid  9085] 14:20:16.827285 write(8, "$3rnbadrn", 9) = 9 <0.000141>
[pid  9085] 14:20:16.827514 epoll_pwait(5, [{EPOLLIN, {u32=8, u64=8}}], 10128, 64, NULL, 8) = 1 <0.000049>
[pid  9085] 14:20:16.827641 read(8, "*2rn$3rnGETrn$41rnuuid:53522908-"..., 16384) = 61 <0.000043>
[pid  9085] 14:20:16.827784 read(3, 0x7fff366a5747, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000034>
[pid  9085] 14:20:16.827945 write(8, "$4rngoodrn", 10) = 10 <0.000288>
[pid  9085] 14:20:16.828339 epoll_pwait(5, [{EPOLLIN, {u32=8, u64=8}}], 10128, 63, NULL, 8) = 1 <0.000057>
[pid  9085] 14:20:16.828486 read(8, "*3rn$4rnSADDrn$4rngoodrn$36rn535"..., 16384) = 67 <0.000040>
[pid  9085] 14:20:16.828623 read(3, 0x7fff366a5747, 1) = -1 EAGAIN (Resource temporarily unavailable) <0.000052>
[pid  9085] 14:20:16.828760 write(7, "*3rn$4rnSADDrn$4rngoodrn$36rn535"..., 67) = 67 <0.000060>
[pid  9085] 14:20:16.828970 fdatasync(7) = 0 <0.005415>
[pid  9085] 14:20:16.834493 write(8, ":1rn", 4) = 4 <0.000250>

觀察一會(huì)兒，有沒(méi)有發(fā)現(xiàn)什么有趣的現(xiàn)象呢？

事實(shí)上，從系統(tǒng)調(diào)用來(lái)看， epoll_pwait、read、write、fdatasync 這些系統(tǒng)調(diào)用都比較頻繁。

那么，剛才觀察到的寫(xiě)磁盤(pán)，應(yīng)該就是 write 或者 fdatasync 導(dǎo)致的了。

接著再來(lái)運(yùn)行 lsof 命令，找出這些系統(tǒng)調(diào)用的操作對(duì)象：

$ lsof -p 9085
redis-ser 9085 systemd-network    3r     FIFO   0,12      0t0 15447970 pipe
redis-ser 9085 systemd-network    4w     FIFO   0,12      0t0 15447970 pipe
redis-ser 9085 systemd-network    5u  a_inode   0,13        0    10179 [eventpoll]
redis-ser 9085 systemd-network    6u     sock    0,9      0t0 15447972 protocol: TCP
redis-ser 9085 systemd-network    7w      REG    8,1  8830146  2838532 /data/appendonly.aof
redis-ser 9085 systemd-network    8u     sock    0,9      0t0 15448709 protocol: TCP

現(xiàn)在你會(huì)發(fā)現(xiàn)，描述符編號(hào)為 3 的是一個(gè) pipe 管道，5 號(hào)是 eventpoll，7 號(hào)是一個(gè)普通文件，而 8 號(hào)是一個(gè) TCP socket。

結(jié)合磁盤(pán)寫(xiě)的現(xiàn)象，我們知道，只有 7 號(hào)普通文件才會(huì)產(chǎn)生磁盤(pán)寫(xiě)，而它操作的文件路徑是 /data/appendonly.aof，相應(yīng)的系統(tǒng)調(diào)用包括 write 和 fdatasync。

如果你對(duì) Redis 的持久化配置比較熟，看到這個(gè)文件路徑以及 fdatasync 的系統(tǒng)調(diào)用，你應(yīng)該能想到，這對(duì)應(yīng)著正是 Redis 持久化配置中的 appendonly 和 appendfsync 選項(xiàng)。很可能是因?yàn)樗鼈兊呐渲貌缓侠恚瑢?dǎo)致磁盤(pán)寫(xiě)比較多。

接下來(lái)就驗(yàn)證一下這個(gè)猜測(cè)，我們可以通過(guò) Redis 的命令行工具，查詢這兩個(gè)選項(xiàng)的配置。

繼續(xù)在終端一中，運(yùn)行下面的命令，查詢 appendonly 和 appendfsync 的配置：

$ docker exec -it redis redis-cli config get 'append*'
1) "appendfsync"
2) "always"
3) "appendonly"
4) "yes"

從這個(gè)結(jié)果你可以發(fā)現(xiàn)，appendfsync 配置的是 always，而 appendonly 配置的是 yes。

這兩個(gè)選項(xiàng)的詳細(xì)含義，你可以從 Redis Persistence 的文檔中查到，這里我做一下簡(jiǎn)單介紹。

Redis 提供了兩種數(shù)據(jù)持久化的方式，分別是快照和追加文件。

快照方式，會(huì)按照指定的時(shí)間間隔，生成數(shù)據(jù)的快照，并且保存到磁盤(pán)文件中。

為了避免阻塞主進(jìn)程，Redis 還會(huì) fork 出一個(gè)子進(jìn)程，來(lái)負(fù)責(zé)快照的保存。這種方式的性能好，無(wú)論是備份還是恢復(fù)，都比追加文件好很多。

不過(guò)，它的缺點(diǎn)也很明顯。在數(shù)據(jù)量大時(shí)，fork 子進(jìn)程需要用到比較大的內(nèi)存，保存數(shù)據(jù)也很耗時(shí)。所以，你需要設(shè)置一個(gè)比較長(zhǎng)的時(shí)間間隔來(lái)應(yīng)對(duì)，比如至少 5 分鐘。這樣，如果發(fā)生故障，你丟失的就是幾分鐘的數(shù)據(jù)。

追加文件，則是用在文件末尾追加記錄的方式，對(duì) Redis 寫(xiě)入的數(shù)據(jù)，依次進(jìn)行持久化，所以它的持久化也更安全。

此外，它還提供了一個(gè)用 appendfsync 選項(xiàng)設(shè)置 fsync 的策略，確保寫(xiě)入的數(shù)據(jù)都落到磁盤(pán)中，具體選項(xiàng)包括 always、everysec、no 等。

always 表示，每個(gè)操作都會(huì)執(zhí)行一次 fsync，是最為安全的方式；
everysec 表示，每秒鐘調(diào)用一次 fsync ，這樣可以保證即使是最壞情況下，也只丟失 1 秒的數(shù)據(jù)；
而 no 表示交給操作系統(tǒng)來(lái)處理。

回憶一下我們剛剛看到的配置，appendfsync 配置的是 always，意味著每次寫(xiě)數(shù)據(jù)時(shí)，都會(huì)調(diào)用一次 fsync，從而造成比較大的磁盤(pán) I/O 壓力。

當(dāng)然，你還可以用 strace ，觀察這個(gè)系統(tǒng)調(diào)用的執(zhí)行情況。比如通過(guò) -e 選項(xiàng)指定 fdatasync 后，你就會(huì)得到下面的結(jié)果：

$ strace -f -p 9085 -T -tt -e fdatasync
strace: Process 9085 attached with 4 threads
[pid  9085] 14:22:52.013547 fdatasync(7) = 0 <0.007112>
[pid  9085] 14:22:52.022467 fdatasync(7) = 0 <0.008572>
[pid  9085] 14:22:52.032223 fdatasync(7) = 0 <0.006769>
...

從這里你可以看到，每隔 10ms 左右，就會(huì)有一次 fdatasync 調(diào)用，并且每次調(diào)用本身也要消耗 7~8ms。

不管哪種方式，都可以驗(yàn)證我們的猜想，配置確實(shí)不合理。這樣，我們就找出了 Redis 正在進(jìn)行寫(xiě)入的文件，也知道了產(chǎn)生大量 I/O 的原因。

不過(guò)，回到最初的疑問(wèn)，為什么查詢時(shí)會(huì)有磁盤(pán)寫(xiě)呢？按理來(lái)說(shuō)不應(yīng)該只有數(shù)據(jù)的讀取嗎？這就需

要我們?cè)賮?lái)審查一下 strace -f -T -tt -p 9085 的結(jié)果。

read(8, "*2rn$3rnGETrn$41rnuuid:53522908-"..., 16384)

write(8, "$4rngoodrn", 10)

read(8, "*3rn$4rnSADDrn$4rngoodrn$36rn535"..., 16384)

write(7, "*3rn$4rnSADDrn$4rngoodrn$36rn535"..., 67)

write(8, ":1rn", 4)

細(xì)心的你應(yīng)該記得，根據(jù) lsof 的分析，文件描述符編號(hào)為 7 的是一個(gè)普通文件 /data/appendonly.aof，而編號(hào)為 8 的是 TCP socket。而觀察上面的內(nèi)容，8 號(hào)對(duì)應(yīng)的 TCP 讀寫(xiě)，是一個(gè)標(biāo)準(zhǔn)的“請(qǐng)求 - 響應(yīng)”格式，即：

從 socket 讀取 GET uuid:53522908-… 后，響應(yīng) good；

再?gòu)?socket 讀取 SADD good 535… 后，響應(yīng) 1。

對(duì) Redis 來(lái)說(shuō)，SADD 是一個(gè)寫(xiě)操作，所以 Redis 還會(huì)把它保存到用于持久化的 appendonly.aof 文件中。

觀察更多的 strace 結(jié)果，你會(huì)發(fā)現(xiàn)，每當(dāng) GET 返回 good 時(shí)，隨后都會(huì)有一個(gè) SADD 操作，這也就導(dǎo)致了，明明是查詢接口，Redis 卻有大量的磁盤(pán)寫(xiě)。

到這里，我們就找出了 Redis 寫(xiě)磁盤(pán)的原因。不過(guò)，在下最終結(jié)論前，我們還是要確認(rèn)一下，8 號(hào) TCP socket 對(duì)應(yīng)的 Redis 客戶端，到底是不是我們的案例應(yīng)用。

我們可以給 lsof 命令加上 -i 選項(xiàng)，找出 TCP socket 對(duì)應(yīng)的 TCP 連接信息。不過(guò)，由于 Redis 和 Python 應(yīng)用都在容器中運(yùn)行，我們需要進(jìn)入容器的網(wǎng)絡(luò)命名空間內(nèi)部，才能看到完整的 TCP 連接。

注意：下面的命令用到的 nsenter 工具，可以進(jìn)入容器命名空間。如果你的系統(tǒng)沒(méi)有安裝，請(qǐng)運(yùn)行下面命令安裝 nsenter：

docker run --rm -v /usr/local/bin:/target jpetazzo/nsenter

還是在終端一中，運(yùn)行下面的命令：

# 由于這兩個(gè)容器共享同一個(gè)網(wǎng)絡(luò)命名空間，所以我們只需要進(jìn)入app的網(wǎng)絡(luò)命名空間即可

$ PID=$(docker inspect --format {{.State.Pid}} app)
# -i表示顯示網(wǎng)絡(luò)套接字信息
$ nsenter --target $PID --net -- lsof -i
COMMAND    PID            USER   FD   TYPE   DEVICE SIZE/OFF NODE NAME
redis-ser 9085 systemd-network    6u  IPv4 15447972      0t0  TCP localhost:6379 (LISTEN)
redis-ser 9085 systemd-network    8u  IPv4 15448709      0t0  TCP localhost:6379->localhost:32996 (ESTABLISHED)
python    9181            root    3u  IPv4 15448677      0t0  TCP *:http (LISTEN)
python    9181            root    5u  IPv4 15449632      0t0  TCP localhost:32996->localhost:6379 (ESTABLISHED)

這次我們可以看到，redis-server 的 8 號(hào)文件描述符，對(duì)應(yīng) TCP 連接 localhost:6379->localhost:32996。

其中， localhost:6379 是 redis-server 自己的監(jiān)聽(tīng)端口，自然 localhost:32996 就是 redis 的客戶端。

再觀察最后一行，localhost:32996 對(duì)應(yīng)的，正是我們的 Python 應(yīng)用程序（進(jìn)程號(hào)為 9181）。

歷經(jīng)各種波折，我們總算找出了 Redis 響應(yīng)延遲的潛在原因。總結(jié)一下，我們找到兩個(gè)問(wèn)題。

第一個(gè)問(wèn)題，Redis 配置的 appendfsync 是 always，這就導(dǎo)致 Redis 每次的寫(xiě)操作，都會(huì)觸發(fā) fdatasync 系統(tǒng)調(diào)用。今天的案例，沒(méi)必要用這么高頻的同步寫(xiě)，使用默認(rèn)的 1s 時(shí)間間隔，就足夠了。

第二個(gè)問(wèn)題，Python 應(yīng)用在查詢接口中會(huì)調(diào)用 Redis 的 SADD 命令，這很可能是不合理使用緩存導(dǎo)致的。

對(duì)于第一個(gè)配置問(wèn)題，我們可以執(zhí)行下面的命令，把 appendfsync 改成 everysec：

$ docker exec -it redis redis-cli config set appendfsync everysec
OK

改完后，切換到終端二中查看，你會(huì)發(fā)現(xiàn)，現(xiàn)在的請(qǐng)求時(shí)間，已經(jīng)縮短到了 0.9s：

{..., "elapsed_seconds":0.9368953704833984,"type":"good"}

而第二個(gè)問(wèn)題，就要查看應(yīng)用的源碼了。點(diǎn)擊 Github ，你就可以查看案例應(yīng)用的源代碼：

def get_cache(type_name):

'''handler for /get_cache'''

for key in redis_client.scan_iter("uuid:*"):

value = redis_client.get(key)

if value == type_name:

redis_client.sadd(type_name, key[5:])

data = list(redis_client.smembers(type_name))

redis_client.delete(type_name)

return jsonify({"type": type_name, 'count': len(data), 'data': data})

果然，Python 應(yīng)用把 Redis 當(dāng)成臨時(shí)空間，用來(lái)存儲(chǔ)查詢過(guò)程中找到的數(shù)據(jù)。不過(guò)我們知道，這些數(shù)據(jù)放內(nèi)存中就可以了，完全沒(méi)必要再通過(guò)網(wǎng)絡(luò)調(diào)用存儲(chǔ)到 Redis 中。

$ while true; do curl http:

{...,"elapsed_seconds":0.16034674644470215,"type":"good"}

你可以發(fā)現(xiàn)，解決第二個(gè)問(wèn)題后，新接口的性能又有了進(jìn)一步的提升，從剛才的 0.9s ，再次縮短成了不到 0.2s。

當(dāng)然，案例最后，不要忘記清理案例應(yīng)用。你可以切換到終端一中，執(zhí)行下面的命令進(jìn)行清理：

小結(jié)

今天我?guī)阋黄鸱治隽艘粋€(gè) Redis 緩存的案例。

我們先用 top、iostat ，分析了系統(tǒng)的 CPU 、內(nèi)存和磁盤(pán)使用情況，不過(guò)卻發(fā)現(xiàn)，系統(tǒng)資源并沒(méi)有出現(xiàn)瓶頸。這個(gè)時(shí)候想要進(jìn)一步分析的話，該從哪個(gè)方向著手呢？

通過(guò)今天的案例你會(huì)發(fā)現(xiàn)，為了進(jìn)一步分析，就需要你對(duì)系統(tǒng)和應(yīng)用程序的工作原理有一定的了解。

比如，今天的案例中，雖然磁盤(pán) I/O 并沒(méi)有出現(xiàn)瓶頸，但從 Redis 的原理來(lái)說(shuō)，查詢緩存時(shí)不應(yīng)該出現(xiàn)大量的磁盤(pán) I/O 寫(xiě)操作。

順著這個(gè)思路，我們繼續(xù)借助 pidstat、strace、lsof、nsenter 等一系列的工具，找出了兩個(gè)潛在問(wèn)題，一個(gè)是 Redis 的不合理配置，另一個(gè)是 Python 應(yīng)用對(duì) Redis 的濫用。找到瓶頸后，相應(yīng)的優(yōu)化工作自然就比較輕松了。