[翻译]60,000毫秒内对Linux进行性能诊断

原文链接：http://techblog.netflix.com/2015/11/linux-performance-analysis-in-60s.html

原文作者：Brendan Gregg，Linux系统性能分析的专家。

60,000毫秒内对Linux进行性能诊断

当你登陆上一个有性能问题的Linux服务器：在第一分钟你会做什么？

在Netflix我们有大规模的EC2 Linux云，也有许多性能分析工具来监控和诊断服务器的性能。例如针对云监控的Atlas,针对on-demand机器分析的Vector，这些工具帮助我们解决了大部分问题，但我们偶尔也需要登录服务器，并运行一些标准的Linux性能工具。

在本文中，Netflix性能工程师团队将使用标准的Linux命令行工具，演示在性能优化诊断中最初60秒要干的事情。

最初的60,000毫秒

在60秒内通过执行下面10个命令，你可以对系统资源消耗、正在运行的进程有个大致了解。首先查找的目标是错误及饱和（saturation）指标，这两种指标很容易被理解；然后是资源利用率。这里的“饱和”是指系统负载超出了处理能力，直接表现是请求队列堆积，等待的时间变长。

uptime
dmesg | tail
vmstat 1
mpstat -P ALL 1
pidstat 1
iostat -xz 1
free -m
sar -n DEV 1
sar -n TCP,ETCP 1
top

有些命令需要安装sysstat包，这些命令所输出的指标将会帮你来完成USE Method一部分，USE Method是一套定位性能瓶颈的方法，包括查看所有资源（CPU，内存，磁盘、网卡等)的利用率、当前负载，及错误等指标。随着对所有资源的逐步检查和排除，最终定位到目标资源。

下文通过生产环境的实例，对这些命令进行讲解。更详细的信息，请参考man page。

1. uptime

$ uptime
23:51:26 up 21:31, 1 user, load average: 30.02, 26.43, 19.02

这是查看平均负载的最快捷方法，输出内容显示了想要执行的任务（进程）数量。在linux系统，这些值（平均负载）的含义是在特定时间间隔内运行队列中的平均进程数，包括正在运行的进程数，加上等待运行的进程数，也包括那些阻塞在不可中断I/O（通常是磁盘I/O）的进程数。但是uptime仅仅给出了大概的负载情况，只供快速参考，更详细的状态需要用其他工具进行更进一步分析。

这三个值表示了1分钟、5分钟、15分钟的平均负载，这让我们了解到负载是如何随时间变化的。例如，当要求你检查一个有问题的服务器时，发现1分钟的值要比15分钟的值小的多，那么这可能意味着，你登陆太迟了，错过了问题发生的时刻。

以上例子中，平均负载有上升趋势，最近1分钟的负载甚至到了30，而15分钟的负载是19。这么大的负载意味着：多个任务（进程）急需CPU资源，然后可以进一步使用vmstat或者mpstat进行确认（将在命令3和命令4中介绍）。

2. dmesg | tail

$ dmesg | tail
[1880957.563150] perl invoked oom-killer: gfp_mask=0x280da, order=0, oom_score_adj=0
[...]
[1880957.563400] Out of memory: Kill process 18694 (perl) score 246 or sacrifice child
[1880957.563408] Killed process 18694 (perl) total-vm:1972392kB, anon-rss:1953348kB, file-rss:0kB
[2320864.954447] TCP: Possible SYN flooding on port 7001. Dropping request. Check SNMP counters.

这个命令会查看最近的10条系统消息，特别要着重查看那些可能会导致性能问题的错误输出。以上例子显示了oom-killer（out of memory），以及TCP丢掉一个请求。

不要漏掉这一步，检查一下dmesg总是很值得的！

3. vmstat 1

$ 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
34 0 0 200889792 73708 591828 0 0 0   5 6 10 96 1 3 0 0
32 0 0 200889920 73708 591860 0 0 0 592 13284 4282 98 1 1 0 0
32 0 0 200890112 73708 591860 0 0 0 0 9501 2154 99 1 0 0 0
32 0 0 200889568 73712 591856 0 0 0 48 11900 2459 99 0 0 0 0
32 0 0 200890208 73712 591860 0 0 0 0 15898 4840 98 1 1 0 0
^C

vmstat是虚拟内存统计的简称（virtual memory statistics），这是个常用的工具（几十年前出现在BSD），逐行的输出服务器的关键统计指标。

运行vmstat命令时加上参数1，可以输出每秒的统计结果。值得注意的是，这个版本的第一行输出结果含义是自启动以来各项指标的平均值，而并不是前一秒的平均值。这里我们跳过这第一行输出（除非你想学习并记住每列的含义）。

检查以下列：

  • r：CPU正在运行和等待运行的进程数量。与平均负载（uptime输出）相比，因为这个值并不包含（阻塞在）I/O的进程数量，所以能更好的反应CPU负载。简单来说，r值比CPU核数高时，就意味着CPU过载了。
  • free：以千字节为单位的空闲内存。如果有很多位数字，意味着你还有充足的内存。命令行“free -m”（第7个命令），更好地解释了空闲内存的状态。
  • si，so：换入内存和换出内存，如果这两个值非0，意味着你的内存不够了。
  • us，sy，id，wa，st：分解的平均CPU时间。分别是user（应用程序）、system（内核）、idle（空闲）、wait（等待I/O操作）、steal（还被称作Stolen CPU，存在于虚拟环境，例如AWS）。

参照CPU的分解时间，指标（user时间+system时间）可以用来衡量CPU是否繁忙，而wait时间表示磁盘可能存在瓶颈，因为该值表示CPU实际上是空闲的，但是由于等待磁盘I/O，导致任务被阻塞，所以可以认为wait是另外一种形式CPU空闲，并且wait指出了CPU空闲的原因（阻塞I/O）。

system时间在I/O处理时是必须的，但是一个较高的平均system时间（例如超过20%）通常是很值得挖掘的，因为很可能内核在处理I/O时并不十分高效。

以上例子显示，CPU消耗主要集中在用户态，表示应用程序占用了CPU的使用，所有CPU的平均使用率超过90%。这不一定是个问题，检查下r列，看看是否过载了。

4. mpstat -P ALL 1

$ mpstat -P ALL 1
Linux 3.13.0-49-generic (titanclusters-xxxxx)  07/14/2015  _x86_64_ (32 CPU)

07:38:49 PM  CPU   %usr  %nice   %sys %iowait   %irq  %soft  %steal  %guest  %gnice  %idle
07:38:50 PM  all  98.47   0.00   0.75    0.00   0.00   0.00    0.00    0.00    0.00   0.78
07:38:50 PM    0  96.04   0.00   2.97    0.00   0.00   0.00    0.00    0.00    0.00   0.99
07:38:50 PM    1  97.00   0.00   1.00    0.00   0.00   0.00    0.00    0.00    0.00   2.00
07:38:50 PM    2  98.00   0.00   1.00    0.00   0.00   0.00    0.00    0.00    0.00   1.00
07:38:50 PM    3  96.97   0.00   0.00    0.00   0.00   0.00    0.00    0.00    0.00   3.03
[...]

这个命令输出每个CPU的使用状况，可以用来确定CPU使用不均衡（imbalance）的场景。若存在一个热点CPU，说明系统运行着一个单线程的应用程序。

5. pidstat 1

$ pidstat 1
Linux 3.13.0-49-generic (titanclusters-xxxxx)  07/14/2015    _x86_64_    (32 CPU)

07:41:02 PM   UID       PID    %usr %system  %guest    %CPU   CPU  Command
07:41:03 PM     0         9    0.00    0.94    0.00    0.94     1  rcuos/0
07:41:03 PM     0      4214    5.66    5.66    0.00   11.32    15  mesos-slave
07:41:03 PM     0      4354    0.94    0.94    0.00    1.89     8  java
07:41:03 PM     0      6521 1596.23    1.89    0.00 1598.11    27  java
07:41:03 PM     0      6564 1571.70    7.55    0.00 1579.25    28  java
07:41:03 PM 60004     60154    0.94    4.72    0.00    5.66     9  pidstat

07:41:03 PM   UID       PID    %usr %system  %guest    %CPU   CPU  Command
07:41:04 PM     0      4214    6.00    2.00    0.00    8.00    15  mesos-slave
07:41:04 PM     0      6521 1590.00    1.00    0.00 1591.00    27  java
07:41:04 PM     0      6564 1573.00   10.00    0.00 1583.00    28  java
07:41:04 PM   108      6718    1.00    0.00    0.00    1.00     0  snmp-pass
07:41:04 PM 60004     60154    1.00    4.00    0.00    5.00     9  pidstat
^C

类似top命令，pidstat也是对每个进程进行统计，但与top不同的是，pidstat的每次输出不会覆盖之前的输出，而是循环输出每次统计信息，这有助于观察进程随时间的变化趋势，同时也便于将输出数据记录到调查结果中。

以上例子中，有两个java进程消耗了大量的CPU。%CPU列是该进程在所有CPU核心上的使用总和，1591%表示这个java进程几乎占用了16个CPU核心。

6. iostat -xz 1

$ iostat -xz 1
Linux 3.13.0-49-generic (titanclusters-xxxxx)  07/14/2015  _x86_64_ (32 CPU)

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
          73.96    0.00    3.73    0.03    0.06   22.21

Device:   rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
xvda        0.00     0.23    0.21    0.18     4.52     2.08    34.37     0.00    9.98   13.80    5.42   2.44   0.09
xvdb        0.01     0.00    1.02    8.94   127.97   598.53   145.79     0.00    0.43    1.78    0.28   0.25   0.25
xvdc        0.01     0.00    1.02    8.86   127.79   595.94   146.50     0.00    0.45    1.82    0.30   0.27   0.26
dm-0        0.00     0.00    0.69    2.32    10.47    31.69    28.01     0.01    3.23    0.71    3.98   0.13   0.04
dm-1        0.00     0.00    0.00    0.94     0.01     3.78     8.00     0.33  345.84    0.04  346.81   0.01   0.00
dm-2        0.00     0.00    0.09    0.07     1.35     0.36    22.50     0.00    2.55    0.23    5.62   1.78   0.03
[...]
^C

这是一个理解块设备（磁盘）的很好的工具，该命令既输出了负载的大小，又输出了性能数据。

检查以下列：

  • r/s, w/s, rkB/s, wkB/s：分别是每秒钟系统对磁盘的读次数、写次数、读的字节数（单位千字节）、写的字节数（单位千字节）。利用这些指标，很容易发现性能问题是否是由施加过量负载导致的。
  • await：I/O的平均消耗时间，单位是毫秒。这个时间是应用程序所感知的时间，既包括请求在队列里的等待时间，又包括请求的被处理时间。若该值比预期大，这意味着磁盘满载或者磁盘出了故障。
  • avgqu-sz：发送到磁盘上的平均队列长度（原文处可能有错误，该含义在man page中是The average queue length of the requests that were issued to the device）。若值大于1就是满载的证据（尽管磁盘是并行地执行请求，特别是那些由很多磁盘组成的虚拟磁盘，磁盘再多也可能满载）。
  • %util：设备使用率。表示磁盘繁忙的百分比，显示了每秒钟磁盘工作的时间。尽管这个值对不同磁盘有不同的衡量标准，但大于60%通常会导致较差的性能（会在await中体现，导致I/O阻塞）。若接近100%则意味着满载了。

请牢记较差的disk I/O性能可能不是应用程序问题。另外很多技术都使用异步I/O（例如预读、写缓冲），通常应用程序不会直接被阻塞或者承受时延。

7. free -m

$ free -m
             total       used       free     shared    buffers     cached
Mem:        245998      24545     221453         83         59        541
-/+ buffers/cache:      23944     222053
Swap:            0          0          0

右侧两列为：

  • buffers：对阻塞I/O的缓冲
  • cached：文件系统的页缓存

这两个值若接近0时，会导致较高的磁盘I/O（用iostat命令确认）和较差的性能。不过上述例子看起来还好，还有很多M的空间。

“-/+ buffers/cache”是处理过的更为准确的used/free内存，Linux系统使用空闲内存做缓存，当应用程序需要内存的时候这些缓存会被快速回收，因此cached内存应该包含在空闲内存列中，这一行的输出就是这样处理后的结果。关于这个困惑，甚至有个网站，linuxatemyram，哇哦！

如果在Linux上使用ZFS文件系统（听说是Oracle设计的），正如我们在一些设备上使用的，这一点会变得更加迷惑。因为ZFS有自己的文件系统缓存，并不算入free -m的输出中，因此有时系统显示可用内存比较低，而事实上这些内存都在ZFS的缓存中。

8. sar -n DEV 1

$ sar -n DEV 1
Linux 3.13.0-49-generic (titanclusters-xxxxx)  07/14/2015     _x86_64_    (32 CPU)

12:16:48 AM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s   %ifutil
12:16:49 AM      eth0  18763.00   5032.00  20686.42    478.30      0.00      0.00      0.00      0.00
12:16:49 AM        lo     14.00     14.00      1.36      1.36      0.00      0.00      0.00      0.00
12:16:49 AM   docker0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00

12:16:49 AM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s   %ifutil
12:16:50 AM      eth0  19763.00   5101.00  21999.10    482.56      0.00      0.00      0.00      0.00
12:16:50 AM        lo     20.00     20.00      3.25      3.25      0.00      0.00      0.00      0.00
12:16:50 AM   docker0      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
^C

这个工具可以用来检查网络接口的吞吐指标：rxkB/s和txkB/s，这可用来检查是否达到了流量上限。以上例子中，eth0接收速度达到22 Mbyte/s，即176 Mbps（低于1Gbps上限）。

这个版本的%ifutil列表示设备的使用率（对于双工设备，取两个方向的最大值），也可用Brendan的nicstat tool来测量。跟nicstat一样，这个值很难正确地获得，以上例子就不正确（0.00）。

9. sar -n TCP,ETCP 1

$ sar -n TCP,ETCP 1
Linux 3.13.0-49-generic (titanclusters-xxxxx)  07/14/2015    _x86_64_    (32 CPU)

12:17:19 AM  active/s passive/s    iseg/s    oseg/s
12:17:20 AM      1.00      0.00  10233.00  18846.00

12:17:19 AM  atmptf/s  estres/s retrans/s isegerr/s   orsts/s
12:17:20 AM      0.00      0.00      0.00      0.00      0.00

12:17:20 AM  active/s passive/s    iseg/s    oseg/s
12:17:21 AM      1.00      0.00   8359.00   6039.00

12:17:20 AM  atmptf/s  estres/s retrans/s isegerr/s   orsts/s
12:17:21 AM      0.00      0.00      0.00      0.00      0.00
^C

输出显示了一些TCP的关键指标，包括：

  • active/s: 每秒钟本地发起的TCP连接（例如通过connect()）
  • passive/s: 每秒钟远程进入的TCP连接（例如通过accept())
  • retrans/s: 每秒钟TCP的重传次数

主动连接（active）和被动连接（passive）可以用来粗略衡量服务器的负载：新接受连接的数量（passive），对外连接的数量（active），也可以认为active对外，passtive对内，但是这并不是绝对正确（请考虑一下localhost到localhost连接的情况）。

发生重传意味着网络或着服务器可能出现了问题，比如网络可能不太可靠（公网），或者服务器过载导致了丢包。以上例子显示每秒钟仅有一个新的TCP连接，所以服务器网络负载不高。

10. top

$ top
top - 00:15:40 up 21:56,  1 user,  load average: 31.09, 29.87, 29.92
Tasks: 871 total,   1 running, 868 sleeping,   0 stopped,   2 zombie
%Cpu(s): 96.8 us,  0.4 sy,  0.0 ni,  2.7 id,  0.1 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem:  25190241+total, 24921688 used, 22698073+free,    60448 buffers
KiB Swap:        0 total,        0 used,        0 free.   554208 cached Mem

   PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 20248 root      20   0  0.227t 0.012t  18748 S  3090  5.2  29812:58 java
  4213 root      20   0 2722544  64640  44232 S  23.5  0.0 233:35.37 mesos-slave
 66128 titancl+  20   0   24344   2332   1172 R   1.0  0.0   0:00.07 top
  5235 root      20   0 38.227g 547004  49996 S   0.7  0.2   2:02.74 java
  4299 root      20   0 20.015g 2.682g  16836 S   0.3  1.1  33:14.42 java
     1 root      20   0   33620   2920   1496 S   0.0  0.0   0:03.82 init
     2 root      20   0       0      0      0 S   0.0  0.0   0:00.02 kthreadd
     3 root      20   0       0      0      0 S   0.0  0.0   0:05.35 ksoftirqd/0
     5 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 kworker/0:0H
     6 root      20   0       0      0      0 S   0.0  0.0   0:06.94 kworker/u256:0
     8 root      20   0       0      0      0 S   0.0  0.0   2:38.05 rcu_sched

top命令包含了很多我们已经检查过的指标，可以方便地用来查看某项指标是否跟之前的结果相差很大的情况，也可以动态观察负载的变化。

top命令的一个不足是，很难观察指标随时间变化的趋势（因为清屏的原因），而使用vmstat和pidstat可能更为清晰，因为它们的输出结果并不会覆盖之前的输出结果。此外在使用top命令时，由于不能及时暂停，加上后面的输出结果会覆盖前面的输出，因此可能容易丢失那些间断的不连续的证据。

60,000毫秒后…

还有很多命令和方法来帮助你进行更深层次的挖掘。参照Brendan在2015年Velocity大会上的Linux性能工具教程，该教程介绍了40多个命令，包括了观测、基准测试、调优、静态性能调优、分析（profiling）和追踪等方方面面的内容。

参考：

  1. http://www.linuxatemyram.com/
  2. http://www.linuxhowtos.org/System/Linux%20Memory%20Management.htm
  3. http://www.linuxnix.com/find-ram-size-in-linuxunix/
  4. http://www.csdn.net/article/2012-12-10/2812662-shei-dong-cpu
  5. http://blog.scoutapp.com/articles/2009/07/31/understanding-load-averages

附录：

  1. saturation中文含义是饱和度、（达到）饱和状态。本文有时翻译为过载（因为达到了饱和状态嘛），有时根据语境也翻译为负载。若是有困惑，可以参照原文。
  2. Brendan Gregg的技术博客：http://www.brendangregg.com/index.html

作者说明：

限于本人英文阅读水平，加之对某些技术点的理解并不一定充分正确（虽然也查了很多资料），可能某些地方翻译的不太准确，敬请指教，联系方式为pengfeicui@yeah.net。

posted @ 2016-01-13 20:54  FigoCui  阅读(896)  评论(0)  编辑  收藏  举报