案例準備
本次案例還是基于 Ubuntu 18.04，同樣適用于其他的 Linux 系統(tǒng)谈宛。我使用的案例環(huán)境如下所示：
機器配置：2 CPU次哈，8GB 內(nèi)存預先安裝 docker、sysstat 吆录、git窑滞、make 等工具，如 apt install docker.io sysstat make git
其中恢筝，docker 和 sysstat 已經(jīng)用過很多次哀卫，這里不再贅述；git 用來拉取本次案例所需腳本撬槽，這些腳本存儲在 Github 代碼倉庫中此改；最后的 make 則是一個常用構建工具，這里用來運行今天的案例侄柔。
案例總共由三個容器組成共啃，包括一個 MySQL 數(shù)據(jù)庫應用、一個商品搜索應用以及一個數(shù)據(jù)處理的應用暂题。其中移剪，商品搜索應用以 HTTP 的形式提供了一個接口：
- /：返回 Index Page；
- /db/insert/products/：插入指定數(shù)量的商品信息薪者；
- /products/：查詢指定商品的信息纵苛，并返回處理時間。
由于應用比較多，為了方便你運行它們攻人，我把它們同樣打包成了幾個 Docker 鏡像取试，并推送到了 Github 上。這樣怀吻，你只需要運行幾條命令瞬浓，就可以啟動了。
首先烙博，我們在第一個終端中執(zhí)行下面命令，拉取本次案例所需腳本：
$ git clone https://github.com/feiskyer/linux-perf-examples
$ cd linux-perf-examples/mysql-slow
接著烟逊，執(zhí)行下面的命令渣窜，運行本次的目標應用。正常情況下宪躯，你應該可以看到下面的輸出：
# 注意下面的隨機字符串是容器ID乔宿，每次運行均會不同，并且你不需要關注它访雪，因為我們只會用到名字
$ make run
docker run --name=mysql -itd -p 10000:80 -m 800m feisky/mysql:5.6
WARNING: Your kernel does not support swap limit capabilities or the cgroup is not mounted. Memory limited without swap.
4156780da5be0b9026bcf27a3fa56abc15b8408e358fa327f472bcc5add4453f
docker run --name=dataservice -itd --privileged feisky/mysql-dataservice
f724d0816d7e47c0b2b1ff701e9a39239cb9b5ce70f597764c793b68131122bb
docker run --name=app --network=container:mysql -itd feisky/mysql-slow
81d3392ba25bb8436f6151662a13ff6182b6bc6f2a559fc2e9d873cd07224ab6
然后详瑞，再運行 docker ps 命令，確認三個容器都處在運行（Up）狀態(tài)：
$ docker ps
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
9a4e3c580963 feisky/mysql-slow "python /app.py" 42 seconds ago Up 36 seconds app
2a47aab18082 feisky/mysql-dataservice "python /dataservice…" 46 seconds ago Up 41 seconds dataservice
4c3ff7b24748 feisky/mysql:5.6 "docker-entrypoint.s…" 47 seconds ago Up 46 seconds 3306/tcp, 0.0.0.0:10000->80/tcp mysql
MySQL 數(shù)據(jù)庫的啟動過程臣缀，需要做一些初始化工作坝橡，這通常需要花費幾分鐘時間。你可以運行 docker logs 命令精置，查看它的啟動過程计寇。
當你看到下面這個輸出時，說明 MySQL 初始化完成脂倦，可以接收外部請求了：
$ docker logs -f mysql
...
... [Note] mysqld: ready for connections.
Version: '5.6.42-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 MySQL Community Server (GPL)
而商品搜索應用則是在 10000 端口監(jiān)聽番宁。你可以按 Ctrl+C ，停止 docker logs 命令赖阻；然后蝶押，執(zhí)行下面的命令，確認它也已經(jīng)正常運行火欧。如果一切正常棋电，你會看到 Index Page 的輸出：
$ curl http://127.0.0.1:10000/
Index Page
接下來，運行 make init 命令苇侵，初始化數(shù)據(jù)庫离陶，并插入 10000 條商品信息。這個過程比較慢衅檀，比如在我的機器中招刨，就花了十幾分鐘時間。耐心等待一段時間后哀军，你會看到如下的輸出：
$ make init
docker exec -i mysql mysql -uroot -P3306 < tables.sql
curl http://127.0.0.1:10000/db/insert/products/10000
insert 10000 lines
接著沉眶，我們切換到第二個終端打却，訪問一下商品搜索的接口，看看能不能找到想要的商品谎倔。執(zhí)行如下的 curl 命令：
$ curl http://192.168.0.10:10000/products/geektime
Got data: () in 15.364538192749023 sec
稍等一會兒柳击，你會發(fā)現(xiàn)，這個接口返回的是空數(shù)據(jù)片习，而且處理時間超過 15 秒捌肴。這么慢的響應速度讓人無法忍受，到底出了什么問題呢藕咏？
既然今天用了 MySQL状知，你估計會猜到是慢查詢的問題。
不過別急孽查，在具體分析前饥悴，為了避免在分析過程中客戶端的請求結束，我們把 curl 命令放到一個循環(huán)里執(zhí)行盲再。同時西设，為了避免給系統(tǒng)過大壓力，我們設置在每次查詢后答朋，都先等待 5 秒贷揽，然后再開始新的請求。
所以梦碗，你可以在終端二中擒滑，繼續(xù)執(zhí)行下面的命令：
$ while true; do curl http://192.168.0.10:10000/products/geektime; sleep 5; done
接下來，重新回到終端一中叉弦，分析接口響應速度慢的原因丐一。不過，重回終端一后淹冰，你會發(fā)現(xiàn)系統(tǒng)響應也明顯變慢了库车，隨便執(zhí)行一個命令，都得停頓一會兒才能看到輸出樱拴。
這跟上一節(jié)的現(xiàn)象很類似柠衍，看來，我們還是得觀察一下系統(tǒng)的資源使用情況晶乔，比如 CPU珍坊、內(nèi)存和磁盤 I/O 等的情況。
首先正罢，我們在終端一執(zhí)行 top 命令阵漏，分析系統(tǒng)的 CPU 使用情況：
$ top
top - 12:02:15 up 6 days, 8:05, 1 user, load average: 0.66, 0.72, 0.59
Tasks: 137 total, 1 running, 81 sleeping, 0 stopped, 0 zombie
%Cpu0 : 0.7 us, 1.3 sy, 0.0 ni, 35.9 id, 62.1 wa, 0.0 hi, 0.0 si, 0.0 st
%Cpu1 : 0.3 us, 0.7 sy, 0.0 ni, 84.7 id, 14.3 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 8169300 total, 7238472 free, 546132 used, 384696 buff/cache
KiB Swap: 0 total, 0 free, 0 used. 7316952 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
27458 999 20 0 833852 57968 13176 S 1.7 0.7 0:12.40 mysqld
27617 root 20 0 24348 9216 4692 S 1.0 0.1 0:04.40 python
1549 root 20 0 236716 24568 9864 S 0.3 0.3 51:46.57 python3
22421 root 20 0 0 0 0 I 0.3 0.0 0:01.16 kworker/u
觀察 top 的輸出，我們發(fā)現(xiàn)，兩個 CPU 的 iowait 都比較高履怯，特別是 CPU0回还，iowait 已經(jīng)超過 60%。而具體到各個進程叹洲， CPU 使用率并不高柠硕，最高的也只有 1.7%。
既然 CPU 的嫌疑不大运提，那問題應該還是出在了 I/O 上蝗柔。我們?nèi)匀辉诘谝粋€終端，按下 Ctrl+C民泵，停止 top 命令癣丧；然后，執(zhí)行下面的 iostat 命令洪灯，看看有沒有 I/O 性能問題：
$ 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 273.00 0.00 32568.00 0.00 0.00 0.00 0.00 0.00 7.90 0.00 1.16 119.30 0.00 3.56 97.20
iostat 的輸出你應該非常熟悉坎缭。觀察這個界面竟痰，我們發(fā)現(xiàn)签钩，磁盤 sda 每秒的讀數(shù)據(jù)為 32 MB， 而 I/O 使用率高達 97% 坏快，接近飽和铅檩，這說明，磁盤 sda 的讀取確實碰到了性能瓶頸莽鸿。
那要怎么知道昧旨，這些 I/O 請求到底是哪些進程導致的呢？當然可以找我們的老朋友祥得， pidstat兔沃。接下來，在終端一中级及，按下 Ctrl+C 停止 iostat 命令乒疏，然后運行下面的 pidstat 命令，觀察進程的 I/O 情況：
# -d選項表示展示進程的I/O情況
$ pidstat -d 1
12:04:11 UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command
12:04:12 999 27458 32640.00 0.00 0.00 0 mysqld
12:04:12 0 27617 4.00 4.00 0.00 3 python
12:04:12 0 27864 0.00 4.00 0.00 0 systemd-journal
從 pidstat 的輸出可以看到饮焦，PID 為 27458 的 mysqld 進程正在進行大量的讀怕吴，而且讀取速度是 32 MB/s，跟剛才 iostat 的發(fā)現(xiàn)一致县踢。兩個結果一對比转绷，我們自然就找到了磁盤 I/O 瓶頸的根源，即 mysqld 進程硼啤。
不過议经，這事兒還沒完。我們自然要懷疑一下，為什么 mysqld 會去讀取大量的磁盤數(shù)據(jù)呢爸业？按照前面猜測其骄，我們提到過，這有可能是個慢查詢問題扯旷。
可是拯爽，回想一下，慢查詢的現(xiàn)象大多是 CPU 使用率高（比如 100% ）钧忽，但這里看到的卻是 I/O 問題毯炮。看來耸黑，這并不是一個單純的慢查詢問題膛锭，我們有必要分析一下 MySQL 讀取的數(shù)據(jù)。
要分析進程的數(shù)據(jù)讀取颂斜，當然還要靠上一節(jié)用到過的 strace+ lsof 組合敌蜂。
接下來，還是在終端一中缺菌，執(zhí)行 strace 命令葫辐，并且指定 mysqld 的進程號 27458。我們知道伴郁，MySQL 是一個多線程的數(shù)據(jù)庫應用耿战，為了不漏掉這些線程的數(shù)據(jù)讀取情況，你要記得在執(zhí)行 stace 命令時焊傅，加上 -f 參數(shù)：
$ strace -f -p 27458
[pid 28014] read(38, "934EiwT363aak7VtqF1mHGa4LL4Dhbks"..., 131072) = 131072
[pid 28014] read(38, "hSs7KBDepBqA6m4ce6i6iUfFTeG9Ot9z"..., 20480) = 20480
[pid 28014] read(38, "NRhRjCSsLLBjTfdqiBRLvN9K6FRfqqLm"..., 131072) = 131072
[pid 28014] read(38, "AKgsik4BilLb7y6OkwQUjjqGeCTQTaRl"..., 24576) = 24576
[pid 28014] read(38, "hFMHx7FzUSqfFI22fQxWCpSnDmRjamaW"..., 131072) = 131072
[pid 28014] read(38, "ajUzLmKqivcDJSkiw7QWf2ETLgvQIpfC"..., 20480) = 20480
觀察一會剂陡，你會發(fā)現(xiàn)，線程 28014 正在讀取大量數(shù)據(jù)狐胎，且讀取文件的描述符編號為 38鸭栖。這兒的 38 又對應著哪個文件呢？我們可以執(zhí)行下面的 lsof 命令握巢，并且指定線程號 28014 晕鹊，具體查看這個可疑線程和可疑文件：
$ lsof -p 28014
奇怪的是，lsof 并沒有給出任何輸出镜粤。實際上捏题，如果你查看 lsof 命令的返回值，就會發(fā)現(xiàn)肉渴，這個命令的執(zhí)行失敗了公荧。
我們知道，在 SHELL 中同规，特殊標量 $? 表示上一條命令退出時的返回值循狰。查看這個特殊標量窟社，你會發(fā)現(xiàn)它的返回值是 1⌒髟浚可是別忘了灿里，在 Linux 中，返回值為 0 程腹，才表示命令執(zhí)行成功匣吊。返回值為 1，顯然表明執(zhí)行失敗寸潦。
$ echo $?
1
為什么 lsof 命令執(zhí)行失敗了呢色鸳？這里希望你暫停往下，自己先思考一下原因见转。記住我的那句話命雀，遇到現(xiàn)象解釋不了，先去查查工具文檔斩箫。
事實上吏砂，通過查詢 lsof 的文檔，你會發(fā)現(xiàn)乘客，-p 參數(shù)需要指定進程號狐血，而我們剛才傳入的是線程號，所以 lsof 失敗了寨典。你看氛雪，任何一個細節(jié)都可能成為性能分析的“攔路虎”房匆。
回過頭我們看耸成，mysqld 的進程號是 27458，而 28014 只是它的一個線程浴鸿。而且井氢，如果你觀察 一下 mysqld 進程的線程，你會發(fā)現(xiàn)岳链，mysqld 其實還有很多正在運行的其他線程：
# -t表示顯示線程花竞，-a表示顯示命令行參數(shù)
$ pstree -t -a -p 27458
mysqld,27458 --log_bin=on --sync_binlog=1
...
├─{mysqld},27922
├─{mysqld},27923
└─{mysqld},28014
找到了原因，lsof 的問題就容易解決了掸哑。把線程號換成進程號约急，繼續(xù)執(zhí)行 lsof 命令：
$ lsof -p 27458
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
...
?mysqld 27458 999 38u REG 8,1 512440000 2601895 /var/lib/mysql/test/products.MYD
這次我們得到了 lsof 的輸出。從輸出中可以看到苗分， mysqld 進程確實打開了大量文件厌蔽，而根據(jù)文件描述符（FD）的編號，我們知道摔癣，描述符為 38 的是一個路徑為 /var/lib/mysql/test/products.MYD 的文件奴饮。這里注意纬向， 38 后面的 u 表示， mysqld 以讀寫的方式訪問文件戴卜。
看到這個文件逾条，熟悉 MySQL 的你可能笑了：
- MYD 文件，是 MyISAM 引擎用來存儲表數(shù)據(jù)的文件投剥；
- 文件名就是數(shù)據(jù)表的名字师脂；
- 而這個文件的父目錄，也就是數(shù)據(jù)庫的名字江锨。
換句話說危彩，這個文件告訴我們，mysqld 在讀取數(shù)據(jù)庫 test 中的 products 表泳桦。
實際上汤徽，你可以執(zhí)行下面的命令，查看 mysqld 在管理數(shù)據(jù)庫 test 時的存儲文件灸撰。不過要注意谒府，由于 MySQL 運行在容器中，你需要通過 docker exec 到容器中查看：
$ docker exec -it mysql ls /var/lib/mysql/test/
db.opt products.MYD products.MYI products.frm
從這里你可以發(fā)現(xiàn)浮毯，/var/lib/mysql/test/ 目錄中有四個文件完疫，每個文件的作用分別是：
- MYD 文件用來存儲表的數(shù)據(jù)；
- MYI 文件用來存儲表的索引债蓝；
- frm 文件用來存儲表的元信息（比如表結構）壳鹤；
- opt 文件則用來存儲數(shù)據(jù)庫的元信息（比如字符集、字符校驗規(guī)則等）饰迹。
當然芳誓，看到這些，你可能還有一個疑問啊鸭，那就是锹淌，這些文件到底是不是 mysqld 正在使用的數(shù)據(jù)庫文件呢？有沒有可能是不再使用的舊數(shù)據(jù)呢赠制？其實赂摆，這個很容易確認，查一下 mysqld 配置的數(shù)據(jù)路徑即可钟些。
你可以在終端一中烟号，繼續(xù)執(zhí)行下面的命令：
$ docker exec -i -t mysql mysql -e 'show global variables like "%datadir%";'
+---------------+-----------------+
| Variable_name | Value |
+---------------+-----------------+
| datadir | /var/lib/mysql/ |
+---------------+-----------------+
這里可以看到，/var/lib/mysql/ 確實是 mysqld 正在使用的數(shù)據(jù)存儲目錄政恍。剛才分析得出的數(shù)據(jù)庫 test 和數(shù)據(jù)表 products 汪拥，都是正在使用。
既然已經(jīng)找出了數(shù)據(jù)庫和表抚垃，接下來要做的喷楣，就是弄清楚數(shù)據(jù)庫中正在執(zhí)行什么樣的 SQL 了趟大。我們繼續(xù)在終端一中，運行下面的 docker exec 命令铣焊，進入 MySQL 的命令行界面：
$ docker exec -i -t mysql mysql
...
?
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
?
mysql>
下一步你應該可以想到逊朽，那就是在 MySQL 命令行界面中，執(zhí)行 show processlist 命令曲伊，來查看當前正在執(zhí)行的 SQL 語句叽讳。
不過，為了保證 SQL 語句不截斷坟募，這里我們可以執(zhí)行 show full processlist 命令岛蚤。如果一切正常，你應該可以看到如下輸出：
mysql> show full processlist;
+----+------+-----------------+------+---------+------+--------------+-----------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+------+-----------------+------+---------+------+--------------+-----------------------------------------------------+
| 27 | root | localhost | test | Query | 0 | init | show full processlist |
| 28 | root | 127.0.0.1:42262 | test | Query | 1 | Sending data | select * from products where productName='geektime' |
+----+------+-----------------+------+---------+------+--------------+-----------------------------------------------------+
2 rows in set (0.00 sec)
多執(zhí)行幾次 show full processlist 命令懈糯，你可看到 select * from products where productName=‘geektime’ 這條 SQL 語句的執(zhí)行時間比較長涤妒。
我們知道，MySQL 的慢查詢問題赚哗，很可能是沒有利用好索引導致的她紫，那這條查詢語句是不是這樣呢？我們又該怎么確認屿储，查詢語句是否利用了索引呢贿讹？
其實，MySQL 內(nèi)置的 explain 命令够掠，就可以幫你解決這個問題民褂。繼續(xù)在 MySQL 終端中，運行下面的 explain 命令：
# 切換到test庫
mysql> use test;
# 執(zhí)行explain命令
mysql> explain select * from products where productName='geektime';
+----+-------------+----------+------+---------------+------+---------+------+-------+-------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+-------------+----------+------+---------------+------+---------+------+-------+-------------+
| 1 | SIMPLE | products | ALL | NULL | NULL | NULL | NULL | 10000 | Using where |
+----+-------------+----------+------+---------------+------+---------+------+-------+-------------+
1 row in set (0.00 sec)
根據(jù)這些信息疯潭，我們可以確定赊堪，這條查詢語句壓根兒沒有使用索引，所以查詢時袁勺，會掃描全表雹食，并且掃描行數(shù)高達 10000 行畜普。響應速度那么慢也就難怪了期丰。
走到這一步，你應該很容易想到優(yōu)化方法吃挑，沒有索引那我們就自己建立钝荡，給 productName 建立索引就可以了。
接下來舶衬，我們就可以給 productName 建立索引了埠通，也就是執(zhí)行下面的 CREATE INDEX 命令：
mysql> CREATE INDEX products_index ON products (productName);
ERROR 1170 (42000): BLOB/TEXT column 'productName' used in key specification without a key length
不過，醒目的 ERROR 告訴我們逛犹，這條命令運行失敗了端辱。根據(jù)錯誤信息梁剔，productName 是一個 BLOB/TEXT 類型，需要設置一個長度舞蔽。所以荣病，想要創(chuàng)建索引，就必須為 productName 指定一個前綴長度渗柿。
mysql> CREATE INDEX products_index ON products (productName(64));
Query OK, 10000 rows affected (14.45 sec)
Records: 10000 Duplicates: 0 Warnings: 0
現(xiàn)在可以看到个盆，索引已經(jīng)建好了。能做的都做完了朵栖，最后就該檢查一下颊亮，性能問題是否已經(jīng)解決了。
顯然陨溅，查詢時間已經(jīng)從 15 秒縮短到了 3 毫秒终惑。看來门扇，沒有索引果然就是這次性能問題的罪魁禍首狠鸳，解決了索引，就解決了查詢慢的問題悯嗓。
案例思考
到這里件舵，商品搜索應用查詢慢的問題已經(jīng)完美解決了。但是脯厨，對于這個案例铅祸，我還有一點想說明一下。
不知道你還記不記得合武，案例開始時临梗，我們啟動的幾個容器應用。除了 MySQL 和商品搜索應用外稼跳，還有一個 DataService 應用盟庞。為什么這個案例開始時，要運行一個看起來毫不相關的應用呢汤善？
實際上什猖，DataService 是一個嚴重影響 MySQL 性能的干擾應用。拋開上述索引優(yōu)化方法不說红淡，這個案例還有一種優(yōu)化方法不狮，也就是停止 DataService 應用。
接下來在旱，我們就刪除數(shù)據(jù)庫索引摇零，回到原來的狀態(tài)；然后停止 DataService 應用桶蝎，看看優(yōu)化效果如何驻仅。
首先谅畅，我們在終端二中停止 curl 命令，然后回到終端一中噪服，執(zhí)行下面的命令刪除索引：
# 刪除索引
$ docker exec -i -t mysql mysql
?
mysql> use test;
mysql> DROP INDEX products_index ON products;
接著铃彰，在終端二中重新運行 curl 命令。當然芯咧，這次你會發(fā)現(xiàn)牙捉，處理時間又變慢了：
$ while true; do curl http://192.168.0.10:10000/products/geektime; sleep 5; done
Got data: ()in 16.884345054626465 sec
接下來，再次回到終端一中敬飒，執(zhí)行下面的命令邪铲，停止 DataService 應用：
# 停止 DataService 應用
$ docker rm -f dataservice
最后，我們回到終端二中无拗，觀察 curl 的結果：
Got data: ()in 16.884345054626465 sec
Got data: ()in 15.238174200057983 sec
Got data: ()in 0.12604427337646484 sec
Got data: ()in 0.1101069450378418 sec
Got data: ()in 0.11235237121582031 sec
果然带到，停止 DataService 后，處理時間從 15 秒縮短到了 0.1 秒英染，雖然比不上增加索引后的 3 毫秒揽惹，但相對于 15 秒來說，優(yōu)化效果還是非常明顯的四康。
那么搪搏，這種情況下，還有沒有 I/O 瓶頸了呢闪金？
我們切換到終端一中疯溺，運行下面的 vmstat 命令（注意不是 iostat，稍后解釋原因）哎垦，觀察 I/O 的變化情況：
$ vmstat 1
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 1 0 6809304 1368 856744 0 0 32640 0 52 478 1 0 50 49 0
0 1 0 6776620 1368 889456 0 0 32640 0 33 490 0 0 50 49 0
0 0 0 6747540 1368 918576 0 0 29056 0 42 568 0 0 56 44 0
0 0 0 6747540 1368 918576 0 0 0 0 40 141 1 0 100 0 0
0 0 0 6747160 1368 918576 0 0 0 0 40 148 0 1 99 0 0
你可以看到囱嫩，磁盤讀（bi）和 iowait（wa）剛開始還是挺大的，但沒過多久漏设，就都變成了 0 墨闲。換句話說，I/O 瓶頸消失了郑口。
這是為什么呢鸳碧？原因先留個懸念，作為今天的思考題潘酗。
回過頭來解釋一下剛剛的操作杆兵，在查看 I/O 情況時，我并沒用 iostat 命令仔夺，而是用了 vmstat。其實攒砖，相對于 iostat 來說缸兔，vmstat 可以同時提供 CPU日裙、內(nèi)存和 I/O 的使用情況。
在性能分析過程中惰蜜，能夠綜合多個指標昂拂，并結合系統(tǒng)的工作原理進行分析，對解釋性能現(xiàn)象通常會有意想不到的幫助抛猖。
小結
今天我們分析了一個商品搜索的應用程序格侯。我們先是通過 top、iostat 分析了系統(tǒng)的 CPU 和磁盤使用情況财著，發(fā)現(xiàn)了磁盤的 I/O 瓶頸联四。
接著，我們借助 pidstat 撑教，發(fā)現(xiàn)瓶頸是 mysqld 導致的朝墩。緊接著，我們又通過 strace伟姐、lsof收苏，找出了 mysqld 正在讀的文件。同時愤兵，根據(jù)文件的名字和路徑鹿霸，我們找出了 mysqld 正在操作的數(shù)據(jù)庫和數(shù)據(jù)表。綜合這些信息秆乳，我們判斷杜跷，這是一個沒有利用索引導致的慢查詢問題。
于是矫夷，我們登錄到 MySQL 命令行終端葛闷，用數(shù)據(jù)庫分析工具進行驗證，發(fā)現(xiàn) MySQL 查詢語句訪問的字段双藕，果然沒有索引淑趾。所以，增加索引忧陪，就可以解決案例的性能問題了扣泊。
思考
停止 DataService 后，商品搜索應用的處理時間嘶摊，從 15 秒縮短到了 0.1 秒延蟹。這是為什么呢？
我給個小小的提示叶堆。你可以先查看 dataservice.py 的源碼阱飘，你會發(fā)現(xiàn)，DataService 實際上是在讀寫一個僅包括 “data” 字符串的小文件。不過在讀取文件前沥匈，它會先把 /proc/sys/vm/drop_caches 改成 1蔗喂。
echo 1>/proc/sys/vm/drop_caches表示釋放pagecache，也就是文件緩存高帖，而mysql讀書的數(shù)據(jù)就是文件緩存缰儿，dataservice不停的釋放文件緩存，就導致MySQL都無法利用磁盤緩存散址，也就慢了～
當你看到 DataService 在修改 /proc/sys/vm/drop_caches 時乖阵，就應該想到前面學過的 Cache 的作用。
案例應用訪問的數(shù)據(jù)表预麸，基于 MyISAM 引擎瞪浸，而 MyISAM 的一個特點，就是只在內(nèi)存中緩存索引师崎，并不緩存數(shù)據(jù)默终。所以，在查詢語句無法使用索引時犁罩，就需要數(shù)據(jù)表從數(shù)據(jù)庫文件讀入內(nèi)存齐蔽，然后再進行處理。
所以床估，如果你用 vmstat 工具含滴，觀察緩存和 I/O 的變化趨勢，就會發(fā)現(xiàn)下面這樣的結果：
$ vmstat 1
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
# 備注： DataService正在運行
0 1 0 7293416 132 366704 0 0 32516 12 36 546 1 3 49 48 0
0 1 0 7260772 132 399256 0 0 32640 0 37 463 1 1 49 48 0
0 1 0 7228088 132 432088 0 0 32640 0 30 477 0 1 49 49 0
0 0 0 7306560 132 353084 0 0 20572 4 90 574 1 4 69 27 0
0 2 0 7282300 132 368536 0 0 15468 0 32 304 0 0 79 20 0
# 備注：DataService從這里開始停止
0 0 0 7241852 1360 424164 0 0 864 320 133 1266 1 1 94 5 0
0 1 0 7228956 1368 437400 0 0 13328 0 45 366 0 0 83 17 0
0 1 0 7196320 1368 470148 0 0 32640 0 33 413 1 1 50 49 0
...
0 0 0 6747540 1368 918576 0 0 29056 0 42 568 0 0 56 44 0
0 0 0 6747540 1368 918576 0 0 0 0 40 141 1 0 100 0 0
在 DataService 停止前丐巫，cache 會連續(xù)增長三次后再降回去谈况，這正是因為 DataService 每隔 3 秒清理一次頁緩存。而 DataService 停止后递胧，cache 就會不停地增長碑韵，直到增長為 918576 后，就不再變了缎脾。
這時祝闻，磁盤的讀（bi）降低到 0，同時遗菠，iowait（wa）也降低到 0联喘，這說明，此時的所有數(shù)據(jù)都已經(jīng)在系統(tǒng)的緩存中了辙纬。我們知道豁遭，緩存是內(nèi)存的一部分，它的訪問速度比磁盤快得多贺拣，這也就能解釋蓖谢，為什么 MySQL 的查詢速度變快了很多捂蕴。
從這個案例，你會發(fā)現(xiàn)蜈抓，MySQL 的 MyISAM 引擎启绰，本身并不緩存數(shù)據(jù)昂儒，而要依賴系統(tǒng)緩存來加速磁盤 I/O 的訪問沟使。一旦系統(tǒng)中還有其他應用同時運行，MyISAM 引擎就很難充分利用系統(tǒng)緩存渊跋。因為系統(tǒng)緩存可能被其他應用程序占用腊嗡，甚至直接被清理掉。
所以拾酝，一般來說燕少，我并不建議，把應用程序的性能優(yōu)化完全建立在系統(tǒng)緩存上蒿囤。還是那句話客们，最好能在應用程序的內(nèi)部分配內(nèi)存，構建完全自主控制的緩存材诽，比如 MySQL 的 InnoDB 引擎底挫，就同時緩存了索引和數(shù)據(jù)；或者脸侥，可以使用第三方的緩存應用建邓，比如 Memcached、Redis 等睁枕。
老師官边，請教一個問題啊，既然只是iowait占比高外遇，cpu占比不高注簿，為什么執(zhí)行其它命令會感覺卡呢？在等待io的時候跳仿，CPU不應該去執(zhí)行其它進程嗎诡渴？
作者回復: 執(zhí)行命令也需要IO操作（比如讀目錄找到binary，加載命令和依賴的庫等等）
