Linux性能优化实战学习笔记：第二十七讲
1、案例环境描述
一、环境准备
2CPU,4GB内存python
预先安装docker sysstat工具linux
二、舒适提示
案例中 Python 应用的核心逻辑比较简单，你可能一眼就能看出问题，但实际生产环境中的源码就复杂多了。因此，
我依旧建议，操做以前别看源码，避免先入为主，要把它当成一个黑盒来分析。这样 你能够更好把握住，怎么从系统的资源使用问题出发，分析出瓶颈
所在的应用，以及瓶颈在应用中大概的位置ios
三、测试环境准备
一、运行目标应用git
docker run --name=app -p 10000:80 -itd feisky/word-pop
二、确认应用正常启动github
[root@luoahong ~]# ps aux | grep app.py root 10130 0.0 0.5 95700 23392 pts/0 Ss+ 10:29 0:00 python /app.py root 10167 30.8 0.7 104924 30372 pts/0 Sl+ 10:29 4:32 /usr/local/bin/python /app.py root 10256 0.0 0.0 112716 2288 pts/1 S+ 10:44 0:00 grep --color=auto app.py
2、故障现象
一、发现故障
一、接下来，在第二个终端中，访问案例应用的单词热度接口算法
[root@luoahong ~]# curl http://192.168.118.115:10000
hello world[root@luoahong ~]# curl http://192.168.118.115:10000/popularity/word
{
"popularity": 0.0,
"word": "word"
}
稍等一下子，你会发现，这个接口竟然这么长时间都没响应，到底是怎么回事呢？咱们先回到终端一来分析一下。docker
二、咱们试试在第一个终端里，随便执行一个命令，竟然也要等很久才能输出json
[root@luoahong ~]# df Filesystem 1K-blocks Used Available Use% Mounted on devtmpfs 1995624 0 1995624 0% /dev tmpfs 2007620 0 2007620 0% /dev/shm tmpfs 2007620 9336 1998284 1% /run tmpfs 2007620 0 2007620 0% /sys/fs/cgroup /dev/sda2 50306052 29273120 21032932 59% / tmpfs 401524 0 401524 0% /run/user/0 overlay 50306052 29273120 21032932 59% /var/lib/docker/overlay2/0bc7de96c86ea3d2fe1059ccf2dea175b05a5434cc0a73858b5292b610699530/merged shm 65536 0 65536 0% /var/lib/docker/containers/f0b72f14052f48a2a6eaf034d11e2fea77b76250bd87863e50d2f8aeb22c9918/mounts/shm
二、故障现象
一、top
进程部分有一个 python 进程的 CPU 使用率稍微有点达到了 40.4%。虽然 40.1%并不能成为性能瓶颈，不过有点嫌疑——可能跟 iowait 的升高有关ubuntu
那这个 PID 号为 10167 的 python 进程，究竟是不是咱们的案例应用呢？bash
二、而后执行下面的 ps 命令，查找案例应用 app.py 的 PID 号：
[root@luoahong ~]# ps aux | grep app.py root 10130 0.0 0.5 95700 23392 pts/0 Ss+ 10:29 0:00 python /app.py root 10167 30.8 0.7 104924 30372 pts/0 Sl+ 10:29 4:32 /usr/local/bin/python /app.py root 10256 0.0 0.0 112716 2288 pts/1 S+ 10:44 0:00 grep --color=auto app.py
从 ps 的输出，你能够看到，这个 CPU 使用率较高的进程，不过先别着急分析 CPU 问题，毕竟 iowait 已经高达92%
3、分析过程
一、观察系统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 loop0 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 0.00 0.00 sda 0.00 71.00 0.00 32912.00 0.00 0.00 0.00 0.00 0.00 18118.31 241.89 0.00 463.55 13.86 98.40
二、实际测试
root@luoahong ~]# iostat -d -x 1 Linux 5.1.0-1.el7.elrepo.x86_64 (luoahong) 05/30/2019 _x86_64_ (2 CPU) Device r/s rkB/s rrqm/s %rrqm r_await rareq-sz w/s wkB/s wrqm/s %wrqm w_await wareq-sz d/s dkB/s drqm/s %drqm d_await dareq-sz aqu-sz %util sda 2.14 834.77 0.01 0.44 23.88 390.85 75.84 85205.18 0.60 0.79 191.95 1123.42 0.00 0.00 0.00 0.00 0.00 0.00 14.57 10.79 Device r/s rkB/s rrqm/s %rrqm r_await rareq-sz w/s wkB/s wrqm/s %wrqm w_await wareq-sz d/s dkB/s drqm/s %drqm d_await dareq-sz aqu-sz %util sda 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 0.00 0.00 0.00 0.00 0.00 0.00 0.00 Device r/s rkB/s rrqm/s %rrqm r_await rareq-sz w/s wkB/s wrqm/s %wrqm w_await wareq-sz d/s dkB/s drqm/s %drqm d_await dareq-sz aqu-sz %util sda 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 0.00 0.00 0.00 0.00 0.00 0.00 0.00 Device r/s rkB/s rrqm/s %rrqm r_await rareq-sz w/s wkB/s wrqm/s %wrqm w_await wareq-sz d/s dkB/s drqm/s %drqm d_await dareq-sz aqu-sz %util sda 0.00 0.00 0.00 0.00 0.00 0.00 125.00 103592.00 1.00 0.79 39.18 828.74 0.00 0.00 0.00 0.00 0.00 0.00 4.83 14.90
-d 选项是指显示出I/O的性能指标；
-x 选项是指显示出扩展统计信息（即显示全部I/O指标）
一、你能够发现，磁盘 sda 的 I/O 使用率已经达到 98%接近饱和了
二、并且，写请求的响应时间高达 18 秒，每秒的写数据为32MB，虽然写磁盘碰到了瓶颈
三、这些I/O请求究竟是那些进程致使的呢？
二、知道了进程PID，具体要怎么查看写的状况呢？
[root@luoahong ~]# pidstat -d 1 Linux 5.1.0-1.el7.elrepo.x86_64 (luoahong) 05/30/2019 _x86_64_ (2 CPU) 11:19:22 AM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 11:19:23 AM 0 10167 0.00 124549.02 0.00 0 python 11:19:23 AM 0 10191 0.00 0.00 0.00 108 kworker/u256:1+flush-8:0 11:19:23 AM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 11:19:24 AM 0 10167 0.00 126168.00 0.00 0 python 11:19:24 AM 0 10191 0.00 0.00 0.00 100 kworker/u256:1+flush-8:0
走到这一步，你估计以为，接下来就很简单了，上一个案例不刚刚学过吗？无非就是，先用 strace 确认它是否是在写文件，再用 lsof 找出文件描述符对应的文件便可。
一、strace查看制定PID调用状况
[root@luoahong ~]# strace -p 10167
strace: Process 10167 attached
select(0, NULL, NULL, NULL, {0, 403619}) = 0 (Timeout)
......
stat("/usr/local/lib/python3.7/stringprep.py", {st_mode=S_IFREG|0644, st_size=12917, ...}) = 0
stat("/usr/local/lib/python3.7/stringprep.py", {st_mode=S_IFREG|0644, st_size=12917, ...}) = 0
stat("/usr/local/lib/python3.7/_bootlocale.py", {st_mode=S_IFREG|0644, st_size=1801, ...}) = 0
stat("/usr/local/lib/python3.7/_bootlocale.py", {st_mode=S_IFREG|0644, st_size=1801, ...}) =
因为 strace 的输出比较多，咱们能够用 grep ，来过滤一下 write，好比：
[root@luoahong ~]# strace -p 10167 2>&1 |grep write
遗憾的是没有任何输出
二、filetop
它是 bcc 软件包的一部分，基于 Linux 内核的eBPF（extended Berkeley Packet Filters）机制，主要跟踪内核中文件的读写状况，并输出线
程 ID（TID）、读写大小、读写类型以及文件名称。
bcc的安装方法：https://github.com/iovisor/bcc
sudo apt-key adv --keyserver keyserver.ubuntu.com --recv-keys 4052245BD4284CDD echo "deb https://repo.iovisor.org/apt/$(lsb_release -cs) $(lsb_release -cs) main" | sudo tee /etc/apt/sources.list.d/iovisor.list sudo apt-get update sudo apt-get install bcc-tools libbcc-examples linux-headers-$(uname -r)
安装后，bcc 提供的全部工具，就所有安装到了/usr/share/bcc/tools 这个目录中接下来咱们就用这个工具，观察一下文件的读写状况。
[root@luoahong tools]# ./filetop -C Tracing... Output every 1 secs. Hit Ctrl-C to end 11:54:58 loadavg: 2.37 1.27 0.54 2/185 9851 TID COMM READS WRITES R_Kb W_Kb T FILE 9850 python 2 0 3662 0 R 995.txt 9850 python 2 0 3564 0 R 998.txt 9850 python 2 0 3466 0 R 986.txt 9850 python 2 0 3466 0 R 994.txt 9850 python 2 0 3222 0 R 988.txt 9850 python 2 0 3173 0 R 993.txt 9850 python 2 0 2929 0 R 992.txt 9850 python 2 0 2832 0 R 990.txt 9850 python 2 0 2734 0 R 989.txt 9850 python 2 0 2490 0 R 997.txt 9850 python 2 0 2441 0 R 999.txt 9850 python 2 0 2294 0 R 987.txt 9850 python 2 0 2246 0 R 996.txt 9850 python 2 0 2099 0 R 984.txt 9850 python 2 0 1806 0 R 985.txt 9850 python 2 0 1660 0 R 991.txt 9847 filetop 1 0 4 0 R retprobe 9847 filetop 1 0 4 0 R type 9847 filetop 2 0 2 0 R loadavg 9851 sleep 1 0 0 0 R libc-2.17.so
线程号为 514 的线程，属于哪一个进程呢？
[root@luoahong tools]# ps -efT|grep 9891 root 9798 9891 9755 46 11:59 pts/0 00:00:07 /usr/local/bin/python /app.py root 9894 9894 9805 0 12:00 pts/1 00:00:00 grep --color=auto 9891
filetop 只给出了文件名称，却没有文件路径，还得继续找啊
三、opensnoop
它同属于 bcc 软件包，能够动态跟踪内核中的 open 系统调用。这样，咱们能够找出这些txt文件的路径
[root@luoahong tools]# ./opensnoop PID COMM FD ERR PATH 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/898.txt 9921 opensnoop -1 2 /usr/lib64/python2.7/encodings/ascii.so 9921 opensnoop -1 2 /usr/lib64/python2.7/encodings/asciimodule.so 9921 opensnoop 12 0 /usr/lib64/python2.7/encodings/ascii.py 9921 opensnoop 13 0 /usr/lib64/python2.7/encodings/ascii.pyc 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/899.txt 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/900.txt 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/901.txt 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/902.txt 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/903.txt 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/904.txt 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/905.txt 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/906.txt 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/907.txt 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/908.txt 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/909.txt 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/910.txt 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/911.txt 9798 python 6 0 /tmp/9ef81916-828f-11e9-960a-0242ac110002/912.txt
综合 filetop 和 opensnoop ，咱们就能够进一步分析了。咱们能够大胆猜想，案例应用在写入1000 个 txt 文件后又把这些内容读到内存中进行处理
咱们来检查一下，这个目录中是否是真的有 1000 个文件：
[root@luoahong tools]# ls /tmp/9ef81916-828f-11e9-960a-0242ac110002 |wc -l ls: cannot access /tmp/9ef81916-828f-11e9-960a-0242ac110002: No such file or directory 0
操做后却发现，目录竟然不存在了，怎么回事呢？咱们回到 opensnoop 再观察一下子
[root@luoahong tools]# ./opensnoop PID COMM FD ERR PATH 9798 python 6 0 /tmp/d94f7bec-829c-11e9-960a-0242ac110002/351.txt 10589 opensnoop -1 2 /usr/lib64/python2.7/encodings/ascii.so 10589 opensnoop -1 2 /usr/lib64/python2.7/encodings/asciimodule.so 10589 opensnoop 12 0 /usr/lib64/python2.7/encodings/ascii.py 10589 opensnoop 13 0 /usr/lib64/python2.7/encodings/ascii.pyc 9798 python 6 0 /tmp/d94f7bec-829c-11e9-960a-0242ac110002/352.txt 9798 python 6 0 /tmp/d94f7bec-829c-11e9-960a-0242ac110002/353.txt 9798 python 6 0 /tmp/d94f7bec-829c-11e9-960a-0242ac110002/354.txt 9798 python 6 0 /tmp/d94f7bec-829c-11e9-960a-0242ac110002/355.txt 9798 python 6 0 /tmp/d94f7bec-829c-11e9-960a-0242ac110002/356.txt 9798 python 6 0 /tmp/d94f7bec-829c-11e9-960a-0242ac110002/357.txt
原来，这时的路径已经变成了另外一个目录，这说明，这些目录都是应用程序动态生成的，用完就删了。
结合前面的全部分析，咱们基本能够判断，案例应用会动态生成一批文件，用来临时存储数据，用完就会删除它们。但不幸的是，正是这些文件读写，引起了 I/O 的性能瓶颈，
致使整个处理过程很是慢
四、确认猜测（查看源代码）
@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})
4、解决方案
一、问题总结
源码中能够看到，这个案例应用
一、在每一个请求的处理过程当中毛都会生成一批临时文件。
二、而后读入内存处理，
三、最后把整个目录删除掉
这是一种常见的利用磁盘空间处理大量数据技巧，不过，本次案例中I/O请求过重。致使磁盘I/O利用率太高
二、算法优化
要解决这一点其实就是算法优化问题，好比在内存充足时，就能够把全部的数据存放到内存中处理，这样就避免I/O的性能问题
你能够检验一下，在中断二中分别访问：http://192.168.0.10:10000/popularity/word和http://192.168.0.10:10000/popular/word对比先后的效果
http://192.168.0.10:10000/popularity/word
time curl http://192.168.0.10:10000/popularity/word
{
"popularity": 0.0,
"word": "word"
}
real 2m43.172s
user 0m0.004s
sys 0m0.007s
http://192.168.0.10:10000/popular/word
time curl http://192.168.0.10:10000/popular/word
{
"popularity": 0.0,
"word": "word"
}
real 0m8.810s
user 0m0.010s
sys 0m0.000s
新的接口只要 8 秒就能够返回，明显比一开始的 3 分钟好不少
固然，这只是优化的第一步，而且方法不算完善，还能够作进一步的优化，
不过，在实际系统中，咱们大都是相似的作法，先用简单的方法，尽早解决线上问题，而后在继续思考更好的优化方法
5、故障小结
今天，咱们分析了一个响应过慢的单词热度案例。
首先，咱们用 top、iostat，分析了系统的 CPU 和磁盘使用状况，咱们发现了磁盘I/O 瓶颈，也知道了这个瓶颈是案例应用致使的。
接着，咱们试着照搬上一节案例的方法，用 strace 来观察进程的系统调用，不过此次很不走运，没找到任何 write 系统调用。
因而，咱们又用了新的工具，借助动态追踪工具包 bcc 中的 filetop 和 opensnoop ，找出了案例应用的问题，发现这个根源是大量读写临时文件。
找出问题后，优化方法就相对比较简单了。若是内存充足时，最简单的方法，就是把数据都放在速度更快的内存中，这样就没有磁盘 I/O 的瓶颈了。
固然，再进一步，你能够还能够利用 Trie 树等各类算法，进一步优化单词处理的效率。
相关文章
- 1. Linux性能优化实战学习笔记：第三十七讲
- 2. Linux性能优化实战学习笔记：第五十七讲
- 3. Linux性能优化实战学习笔记：第四十七讲
- 4. Linux性能优化实战学习笔记：第十七讲
- 5. Linux性能优化实战学习笔记：第二十六讲
- 6. Linux性能优化实战学习笔记：第二十五讲
- 7. Linux性能优化实战学习笔记：第二十八讲
- 8. Linux性能优化实战学习笔记：第十二讲
- 9. Linux性能优化实战学习笔记：第三十二讲
- 10. Linux性能优化实战学习笔记：第二十四讲
- 更多相关文章...
- • SEO - 搜索引擎优化 - 网站建设指南
- • 您已经学习了 XML Schema，下一步学习什么呢？ - XML Schema 教程
- • Tomcat学习笔记（史上最全tomcat学习笔记）
- • Kotlin学习（二）基本类型
相关标签/搜索
每日一句
-
每一个你不满意的现在，都有一个你没有努力的曾经。
欢迎关注本站公众号,获取更多信息
