2. 程式人生 > 其它 >27-案例篇：為什麼我的磁碟I/O延遲很高？

27-案例篇：為什麼我的磁碟I/O延遲很高？

阿新 • • 發佈：2021-12-20

案例

  1. 環境準備

    # 伺服器
# 機器配置：2cpu，4GB記憶體
# 預先安裝docker、sysstat包

# 客戶端
# 任意linux伺服器即可

  2. 在服務端執行下面的命令，模擬案例

    [root@local_sa_192-168-1-6 ~]# docker run --name=app -p 10000:80 -itd feisky/word-pop

[root@local_sa_192-168-1-6 ~]# docker ps
CONTAINER ID   IMAGE             COMMAND            CREATED         STATUS         PORTS                                     NAMES
ad3887e297e3   feisky/word-pop   "python /app.py"   8 seconds ago   Up 6 seconds   0.0.0.0:10000->80/tcp, :::10000->80/tcp   app

[root@local_sa_192-168-1-6 ~]# curl http://192.168.1.6:10000/
hello world

  3. 在客戶端訪問服務端介面

    # 發現訪問介面很慢
[root@local_deploy_192-168-1-5 ~]# curl http://192.168.1.6:10000/popularity/word

# 訪問一個介面居然要2分多鐘
[root@local_deploy_192-168-1-5 ~]# time curl http://192.168.1.6:10000/popularity/word
{
  "popularity": 0.0,
  "word": "word"
}

real	2m45.296s
user	0m0.009s
sys	0m0.002s

# 一直訪問，便於分析
[root@local_deploy_192-168-1-5 ~]# while true; do time curl http://192.168.1.6:10000/popularity/word; sleep 1; done

  4. 在服務端，執行df命令，檢視一下檔案系統的使用情況

    [root@local_sa_192-168-1-6 ~]# df -h
檔案系統                 容量  已用  可用 已用% 掛載點
devtmpfs                 2.0G     0  2.0G    0% /dev
tmpfs                    2.0G     0  2.0G    0% /dev/shm
tmpfs                    2.0G  8.6M  2.0G    1% /run
tmpfs                    2.0G     0  2.0G    0% /sys/fs/cgroup
/dev/mapper/centos-root   98G   20G   79G   20% /
/dev/sda1               1014M  256M  759M   26% /boot
tmpfs                    394M     0  394M    0% /run/user/1007
overlay                   98G   20G   79G   20% 
##
系統還有足夠多的磁碟空間，那為什麼響應會變慢呢？

  5. 在服務端，用top來觀察CPU和記憶體的使用情況

    [root@local_sa_192-168-1-6 ~]# top
top - 14:36:02 up 1 day,  1:22,  1 user,  load average: 1.98, 1.18, 0.66
Tasks: 117 total,   1 running,  57 sleeping,   0 stopped,   0 zombie
%Cpu0  :  1.7 us,  1.0 sy,  0.0 ni, 29.5 id, 67.8 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu1  :  2.7 us,  1.0 sy,  0.0 ni, 24.9 id, 71.4 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  4027996 total,  1778052 free,   284884 used,  1965060 buff/cache
KiB Swap:  8388604 total,  8388604 free,        0 used.  3508532 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 5890 root      20   0  105912  31372   7312 S   6.6  0.8   0:19.76 python
##
兩個 CPU 的 iowait 都非常高
##
剩餘記憶體還有3GB，看起來也是充足的
##
還有python這個程序目前是使用CPU最高的程序之一，首先要分析一下它

  6. 用iostat來觀察磁碟的I/O情況

    # -d 選項是指顯示出IO的效能指標
# -x 選項是指顯示出擴充套件統計資訊（即顯示所有IO指標）
[root@local_sa_192-168-1-6 ~]# iostat -d -x 1
Linux 5.15.7-1.el7.elrepo.x86_64 (local_sa_192-168-1-6) 	2021年12月20日 	_x86_64_	(2 CPU)
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0.00     0.00    0.00   20.00     0.00 15382.50  1538.25     0.96   48.15    0.00   48.15  47.70  95.40
scd0              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
dm-0              0.00     0.00    0.00    8.00     0.00 15813.00  3953.25     1.44  179.38    0.00  179.38  42.00  33.60
dm-1              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
##
磁碟sda的I/O使用率已經達到95%，接近飽和了
而且，寫請求的響應時間高達20秒，每秒的寫資料為15MB
這些I/O請求到底是哪些程序導致的呢？

  7. pidstat觀察程序IO情況

    [root@local_sa_192-168-1-6 ~]# pidstat -d 1
Linux 5.15.7-1.el7.elrepo.x86_64 (local_sa_192-168-1-6) 	2021年12月20日 	_x86_64_	(2 CPU)

14時44分49秒   UID       PID   kB_rd/s   kB_wr/s kB_ccwr/s  Command
14時44分50秒     0      5890      0.00  18043.56      0.00  python

14時44分50秒   UID       PID   kB_rd/s   kB_wr/s kB_ccwr/s  Command
14時44分51秒     0      5890      0.00  17952.00      0.00  python
##
從pidstat的輸出，看到了PID號為5890的結果
這說明，正是案例應用引發I/O的效能瓶頸

  8. 先用strace確認它是不是在寫檔案

    [root@local_sa_192-168-1-6 ~]# strace -p 5890 -f
[pid  5890] stat("/usr/local/lib/python3.7/lib-dynload/select.cpython-37m-x86_64-linux-gnu.so", {st_mode=S_IFREG|0755, st_size=87240, ...}) = 0
[pid  5890] stat("/usr/local/lib/python3.7/lib-dynload/select.cpython-37m-x86_64-linux-gnu.so", {st_mode=S_IFREG|0755, st_size=87240, ...}) = 0
[pid  5890] stat("/usr/local/lib/python3.7/lib-dynload/select.cpython-37m-x86_64-linux-gnu.so", {st_mode=S_IFREG|0755, st_size=87240, ...}) = 0
[pid  5890] stat("/usr/local/lib/python3.7/urllib/__init__.py", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
[pid  5890] stat("/usr/local/lib/python3.7/urllib/__init__.py", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
[pid  5890] stat("/usr/local/lib/python3.7/urllib/__init__.py", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
[pid  5890] stat("/usr/local/lib/python3.7/urllib/parse.py", {st_mode=S_IFREG|0644, st_size=36925, ...}) = 0
[pid  5890] stat("/usr/local/lib/python3.7/urllib/parse.py", {st_mode=S_IFREG|0644, st_size=36925, ...}) = 0
[pid  5890] stat("/usr/local/lib/python3.7/urllib/parse.py", {st_mode=S_IFREG|0644, st_size=36925, ...}) = 0
[pid  5890] stat("/usr/local/lib/python3.7/email/_parseaddr.py", {st_mode=S_IFREG|0644, 
##
從strace中，可以看到大量的stat系統呼叫，並且大都為python的檔案，但是這裡並沒有任何write系統呼叫

## 由於strace的輸出比較多，可以用grep，來過濾一下write
[root@local_sa_192-168-1-6 ~]# strace -p 5890 2>&1 | grep write
##
仍然沒有任何輸出

  9. 只好綜合strace、pidstat和iostat這三個結果來分析了
    iostat已經證明磁碟I/O有效能瓶頸，而pidstat也證明了，這個瓶頸是由5890號程序導致的
    但strace跟蹤這個程序，卻沒有找到任何write系統呼叫檔案寫，
    明明應該有相應的write系統呼叫，但用現有工具卻找不到痕跡，這時就該想想換工具的問題了

    filetop是bcc軟體包的一部分，主要跟蹤核心中檔案的讀寫情況，並輸出執行緒ID、讀寫大小、讀寫型別以及檔名稱

    # -C 選項表示輸出新內容時不清空螢幕
[root@local_sa_192-168-1-6 ~]# filetop -C
TID     COMM             READS  WRITES R_Kb    W_Kb    T FILE
5968    python           0      1      0       4199    R 711.txt
5968    python           0      1      0       3369    R 707.txt
5968    python           0      1      0       3222    R 710.txt
5968    python           0      1      0       2636    R 708.txt
5968    python           0      1      0       2392    R 709.txt
5969    filetop          1      0      4       0       R type
5969    filetop          1      0      4       0       R retprobe
5969    filetop          2      0      2       0       R loadavg
656     auditd           0      5      0       0       R audit.log
......
TID     COMM             READS  WRITES R_Kb    W_Kb    T FILE
5968    python           0      1      0       3369    R 714.txt
5968    python           0      1      0       2685    R 712.txt
5968    python           0      1      0       2587    R 718.txt
5968    python           0      1      0       2490    R 716.txt
5968    python           0      1      0       2099    R 717.txt
5968    python           0      1      0       1904    R 715.txt
5968    python           0      1      0       1757    R 713.txt
5969    filetop          2      0      2       0       R loadavg

##
filetop輸出了8列內容，分別是執行緒ID、執行緒命令列、讀寫次數、讀寫的大小、檔案型別以及讀寫的檔名稱
##
多觀察一會兒會發現，每隔一段時間，執行緒號為5968的python應用就會先寫入大量的txt檔案，再大量地讀

##
執行緒號為5968的執行緒，屬於哪個程序呢？可以用ps命令檢視
[root@local_sa_192-168-1-6 ~]# ps -efT|grep 5968
root      5890  5968  5860  8 14:54 pts/0    00:00:07 /usr/local/bin/python /app.py
root      5985  5985  5348  0 14:55 pts/0    00:00:00 grep --color=auto 5971
##
這個執行緒正是案例應用5890的執行緒
filetop只給出了檔名稱，卻沒有檔案路徑

  10. opensnoop屬於bcc軟體包，可以動態跟蹤核心中的open系統呼叫，這樣就可以找出這些 txt 檔案的路徑

    [root@local_sa_192-168-1-6 ~]# opensnoop
libbpf: failed to find valid kernel BTF
libbpf: vmlinux BTF is not found
PID    COMM               FD ERR PATH
5890   python              6   0 /tmp/0a9f7e26-6162-11ec-b257-0242ac110002/454.txt
5890   python              6   0 /tmp/0a9f7e26-6162-11ec-b257-0242ac110002/455.txt
5890   python              6   0 /tmp/0a9f7e26-6162-11ec-b257-0242ac110002/456.txt
5890   python              6   0 /tmp/0a9f7e26-6162-11ec-b257-0242ac110002/457.txt
5890   python              6   0 /tmp/0a9f7e26-6162-11ec-b257-0242ac110002/458.txt
5890   python              6   0 /tmp/0a9f7e26-6162-11ec-b257-0242ac110002/459.txt
5890   python              6   0 /tmp/0a9f7e26-6162-11ec-b257-0242ac110002/460.txt
5890   python              6   0 /tmp/0a9f7e26-6162-11ec-b257-0242ac110002/461.txt
5890   python              6   0 /tmp/0a9f7e26-6162-11ec-b257-0242ac110002/462.txt
5890   python              6   0 /tmp/0a9f7e26-6162-11ec-b257-0242ac110002/463.txt
5890   python              6   0 /tmp/0a9f7e26-6162-11ec-b257-0242ac110002/464.txt
5890   python              6   0 /tmp/0a9f7e26-6162-11ec-b257-0242ac110002/465.txt
5890   python              6   0 /tmp/0a9f7e26-6162-11ec-b257-0242ac110002/466.txt
##
通過opensnoop的輸出可以看到，這些txt路徑位於/tmp目錄下
它開啟的檔案數量，按照數字編號，從0.txt依次增大到999.txt，這可遠多於前面用filetop看到的數量
##
綜合filetop和opensnoop就可以進一步分析了
可以大膽猜測，案例應用在寫入1000個txt檔案後，又把這些內容讀到記憶體中進行處理。
來檢查一下，這個目錄中是不是真的有1000個檔案
[root@local_sa_192-168-1-6 ~]# ls /tmp/0a9f7e26-6162-11ec-b257-0242ac110002|wc -l
ls: 無法訪問/tmp/0a9f7e26-6162-11ec-b257-0242ac110002: 沒有那個檔案或目錄
0
##
操作後卻發現，目錄居然不存在了。怎麼回事呢？回到opensnoop再觀察一會兒
[root@local_sa_192-168-1-6 ~]# opensnoop
libbpf: failed to find valid kernel BTF
libbpf: vmlinux BTF is not found
PID    COMM               FD ERR PATH
5890   python              6   0 /tmp/6ab71080-6162-11ec-b257-0242ac110002/309.txt
5890   python              6   0 /tmp/6ab71080-6162-11ec-b257-0242ac110002/310.txt
5890   python              6   0 /tmp/6ab71080-6162-11ec-b257-0242ac110002/311.txt
5890   python              6   0 /tmp/6ab71080-6162-11ec-b257-0242ac110002/312.txt
5890   python              6   0 /tmp/6ab71080-6162-11ec-b257-0242ac110002/313.txt
##
原來，這時的路徑已經變成了另一個目錄。這說明，這些目錄都是應用程式動態生成的，用完就刪了
##
結合前面的所有分析，基本可以判斷，案例應用會動態生成一批檔案，用來臨時儲存資料，用完就會刪除它們
但不幸的是，正是這些檔案讀寫，引發了I/O的效能瓶頸，導致整個處理過程非常慢

  11. 檢視應用程式的原始碼 app.py

    # 拷貝程式碼到本地目錄
[root@local_sa_192-168-1-6 ~]# docker cp app:/app.py .
[root@local_sa_192-168-1-6 ~]# ls
app.py

# 檢視原始碼
[root@local_sa_192-168-1-6 ~]# cat app.py
#!/usr/bin/env python
# -*- coding: UTF-8 -*-

import os
import uuid
import random
import shutil
from concurrent.futures import ThreadPoolExecutor
from flask import Flask, jsonify

app = Flask(__name__)


def validate(word, sentence):
    return word in sentence


def generate_article():
    s_nouns = [
        "A dude", "My mom", "The king", "Some guy", "A cat with rabies",
        "A sloth", "Your homie", "This cool guy my gardener met yesterday",
        "Superman"
    ]
    p_nouns = [
        "These dudes", "Both of my moms", "All the kings of the world",
        "Some guys", "All of a cattery's cats",
        "The multitude of sloths living under your bed", "Your homies",
        "Like, these, like, all these people", "Supermen"
    ]
    s_verbs = [
        "eats", "kicks", "gives", "treats", "meets with", "creates", "hacks",
        "configures", "spies on", "retards", "meows on", "flees from",
        "tries to automate", "explodes"
    ]
    infinitives = [
        "to make a pie.", "for no apparent reason.",
        "because the sky is green.", "for a disease.",
        "to be able to make toast explode.", "to know more about archeology."
    ]
    sentence = '{} {} {} {}'.format(
        random.choice(s_nouns), random.choice(s_verbs),
        random.choice(s_nouns).lower() or random.choice(p_nouns).lower(),
        random.choice(infinitives))
    return '\n'.join([sentence for i in range(50000)])


@app.route('/')
def hello_world():
    return 'hello world'


@app.route("/popularity/<word>")
def word_popularity(word):
    dir_path = '/tmp/{}'.format(uuid.uuid1())
    count = 0
    sample_size = 1000

    def save_to_file(file_name, content):
        with open(file_name, 'w') as f:
            f.write(content)

    try:
        # initial directory firstly
        os.mkdir(dir_path)

        # save article to files
        for i in range(sample_size):
            file_name = '{}/{}.txt'.format(dir_path, i)
            article = generate_article()
            save_to_file(file_name, article)

        # count word popularity
        for root, dirs, files in os.walk(dir_path):
            for file_name in files:
                with open('{}/{}'.format(dir_path, file_name)) as f:
                    if validate(word, f.read()):
                        count += 1
    finally:
        # clean files
        shutil.rmtree(dir_path, ignore_errors=True)

    return jsonify({'popularity': count / sample_size * 100, 'word': word})


@app.route("/popular/<word>")
def word_popular(word):
    count = 0
    sample_size = 1000
    articles = []

    try:
        for i in range(sample_size):
            articles.append(generate_article())

        for article in articles:
            if validate(word, article):
                count += 1
    finally:
        pass

    return jsonify({'popularity': count / sample_size * 100, 'word': word})


if __name__ == '__main__':
    app.run(debug=True, host='0.0.0.0', port=80)
    
##
原始碼中可以看到，這個案例應用，在每個請求的處理過程中，都會生成一批臨時檔案
然後讀入記憶體處理，最後再把整個目錄刪除掉
##
這是一種常見的利用磁碟空間處理大量資料的技巧，不過，本次案例中的I/O請求太重，導致磁碟I/O利用率過高
##
要解決這一點，其實就是演算法優化問題了
比如在記憶體充足時，就可以把所有資料都放到記憶體中處理，這樣就能避免I/O的效能問題

  12. 在終端二中分別訪問http://192.168.1.6:10000/popularity/word和http://192.168.1.6:10000/popular/word ，對比前後的效果

    [root@local_deploy_192-168-1-5 ~]# time curl  http://192.168.1.6:10000/popular/word
{
  "popularity": 0.0,
  "word": "word"
}

real	0m30.063s
user	0m0.002s
sys	0m0.002s

[root@local_deploy_192-168-1-5 ~]# time curl http://192.168.1.6:10000/popularity/word
{
  "popularity": 0.0,
  "word": "word"
}

real	2m45.296s
user	0m0.009s
sys	0m0.002s
##
新的介面只要30秒就可以返回，明顯比一開始的3分鐘好很多
##
當然，這只是優化的第一步，並且方法也不算完善，還可以做進一步的優化
不過，在實際系統中，大都是類似的做法，先用最簡單的方法，儘早解決線上問題，然後再繼續思考更好的優化方法

小結

今天分析了一個響應過慢的單詞熱度案例

首先，用top、iostat分析了系統的CPU和磁碟使用情況，發現了磁碟I/O瓶頸，也知道了這個瓶頸是案例應用導致的
接著用strace來觀察程序的系統呼叫，沒找到任何write系統呼叫
於是用新的工具，藉助動態追蹤工具包bcc中的filetop和opensnoop，找出了案例應用的問題，發現這個根源是大量讀寫臨時檔案

找出問題後，優化方法就相對比較簡單了
如果記憶體充足時，最簡單的方法，就是把資料都放在速度更快的記憶體中，這樣就沒有磁碟I/O的瓶頸了
當然，再進一步，還可以利用Trie樹等各種演算法，進一步優化單詞處理的效率


轉載請註明出處喲~ https://www.cnblogs.com/lichengguo

相關推薦

27-案例篇：為什麼我的磁碟I/O延遲很高？

案例 環境準備 # 伺服器 # 機器配置：2cpu，4GB記憶體 # 預先安裝docker、sysstat包 # 客戶端

25 | 基礎篇：Linux 磁碟I/O是怎麼工作的（下）

上一節我們學習了 Linux 磁碟 I/O 的工作原理，並瞭解了由檔案系統層、通用塊層和裝置層構成的 Linux 儲存系統 I/O 棧。其中，通用塊層是 Linux 磁碟 I/O 的核心。向上，它為檔案系統和應用程式，提供訪問了塊裝置的

24-基礎篇：Linux磁碟I/O是怎麼工作的(上)

磁碟 按照儲存介質分類：機械磁碟和固態磁碟 機械磁碟，也稱為硬碟驅動器，通常縮寫為HDD

25-基礎篇：Linux磁碟I/O是怎麼工作的(下)

磁碟效能指標 磁碟效能的衡量標準，有五個：使用率、飽和度、IOPS、吞吐量、響應時間

31-套路篇：磁碟I/O效能優化的幾個思路

I/O基準測試 I/O效能優化的目標是什麼？ 換句話說觀察的這些I/O效能指標（比如IOPS、吞吐量、延遲等），要達到多少才合適呢？

40 | 案例篇：網路請求延遲變大了，我該怎麼辦？

上一節，學習了碰到分散式拒絕服務（DDoS）的緩解方法。簡單回顧一下，DDoS 利用大量的偽造請求，導致目標服務要耗費大量資源，來處理這些無效請求，進而無法正常響應正常使用者的請求。

磁碟I/O的三種方式對比：標準I/O、直接 I/O、mmap

文章目錄 @[TOC] 1.引入 1.1 標準I/O 1.2直接I/O 1.3 mmap1.引入讓我們先看一下Linux系統下IO結構模型

10-案例篇：系統的軟中斷CPU使用率升高，我該怎麼辦？

中斷 中斷是一種非同步的事件處理機制，用來提高系統的併發處理能力 中斷事件發生，會觸發執行中斷處理程式，而中斷處理程式被分為上半部和下半部這兩個部分

06-案例篇：系統的CPU使用率很高，但為啥卻找不到高CPU的應用

上一節我講了 CPU 使用率是什麼，並通過一個案例教你使用 top、vmstat、pidstat 等工具，排查高 CPU 使用率的程序，然後再使用 perf top 工具，定位應用內部函式的問題。不過就有人留言了，說似乎感覺高 CPU 使用率的

25-基礎篇：Linux磁碟IO是怎麼工作的（下）

上一節我們學習了 Linux 磁碟 I/O 的工作原理，並瞭解了由檔案系統層、通用塊層和裝置層構成的 Linux 儲存系統 I/O 棧。

記一次斷電偶然導致Linux磁碟I/O故障無法讀寫

機房偶然的一次斷電中，恢復伺服器後出現了 無法讀寫磁碟。 其他掛載的磁碟均無異常

Iometer 測試 磁碟 I/O

Iometer 是一個工作在單系統和集群系統上用來衡量和描述I/O子系統的工具。它的發音為“eye-OM-i-ter,” 以便和單詞“thermometer.”的發音押韻。Iometer 為計算機I/O子系統所作的工作就如同測力計為引擎所

VMware虛擬機器置備磁碟I/O測試分析

個人的專案實施中，經常有同事或者客戶問“VMware虛擬機器有三種置備方式，厚置備延遲置零、厚置備格式、精簡置備哪種好”，根據不同的具體環境，從不同的側重點出發，答案是選擇最合適的，而不是最好的。

作業系統之I/O管理：2、I/O軟體層次結構

2、I/O軟體層次結構 思維導圖I/O軟體層次結構簡單流程分析I/O核心子系統 思維導圖

作業系統之I/O管理：1、I/O控制器、I/O控制方式(程式直接控制方式、中斷驅動方式、DMA方式、通道控制方式)

1、I/O裝置的概念、分類 基礎知識思維導圖什麼是I/O裝置？分類 I/O控制器思維導圖I/O控制器功能I/O控制器的組成記憶體映像I/O vs 暫存器獨立編址

Citrix虛擬機器磁碟I/O和網路I/O測試工具

Citrix虛擬機器磁碟I/O和網路I/O測試工具 公司的3D設計軟體執行在xenapp 5.0上，效能不是很理想。先找個工具測試一下磁碟和網路效能，在citrix網站上找到了。XenServer Virtual Machine Performance Utili

netty前傳：從傳統I/O到Reactor的三種模型

netty前傳：從傳統I/O到Reactor的三種模型 對最近學習netty的一些知識的一個彙總，對前人知識總結的一些個人理解。

Linux系統如何查詢磁碟I/O讀寫過高的程序？

首先，模擬磁碟I/O讀寫高的情況 # 拷貝大檔案進行測試 [root@proxy1 ~]# \\cp -rp /mnt/cdrom/ /tmp/

38 | 案例篇：怎麼使用 tcpdump 和 Wireshark 分析網路流量？

通常，需要暴露到公網的服務，都會繫結一個域名，既方便了人們記憶，也避免了後臺服務 IP 地址的變更影響到使用者。

41 | 案例篇：如何優化 NAT 效能？（上）

上一節，探究了網路延遲增大問題的分析方法，並通過一個案例，掌握瞭如何用 hping3、tcpdump、Wireshark、strace 等工具，來排查和定位問題的根源。簡單回顧一下，網路延遲是最核心的網路效能指標。由於網路傳輸、網