linux 故障定位

- 1. cpu
- - 1.1 说明
  - 1.2 分析工具
  - 1.3 使用方式
- 2. 内存
- - 2.1 说明
  - 2.2 分析工具
  - 2.3 使用方式
- 3. I/O
- - 3.1 说明
  - 3.2 分析工具
  - 3.3 使用方式
- 4. 网络
- - 4.1 说明
  - 4.2 分析工具
  - 4.3 使用方式
- 5. 系统负载
- - 5.1 说明
  - 5.2 分析工具
  - 5.3 使用方式
- 6. 火焰图
- - 6.1 说明
  - 6.2 安装依赖库
  - 6.3 安装
  - 6.4 CPU级别火焰图
  - - 6.4.1 on-CPU
    - 6.4.2 off-CPU
  - 6.5 内存级别火焰图
  - 6.6 性能回退-红蓝差分火焰图
- 7. 案例分析
- - 7.1 接入层nginx集群异常现象
  - 7.2 分析nginx相关指标
  - 7.3 分析系统cpu情况
  - 7.4 火焰图分析cpu
  - 7.5 案例总结
  - - 7.5.1 深入分析
    - 7.5.2 解决方式

有时候会遇到一些疑难杂症，并且监控插件并不能一眼立马发现问题的根源。这时候就需要登录服务器进一步深入分析问题的根源。那么分析问题需要有一定的技术经验积累，并且有些问题涉及到的领域非常广，才能定位到问题。所以，分析问题和踩坑是非常锻炼一个人的成长和提升自我能力。如果我们有一套好的分析工具，那将是事半功倍，能够帮助大家快速定位问题，节省大家很多时间做更深入的事情。

1. cpu

1.1 说明

针对应用程序，我们通常关注的是内核CPU调度器功能和性能。

线程的状态分析主要是分析线程的时间用在什么地方，而线程状态的分类一般分为：

a. on-CPU：执行中，执行中的时间通常又分为用户态时间user和系统态时间sys。
b. off-CPU：等待下一轮上CPU，或者等待I/O、锁、换页等等，其状态可以细分为可执行、匿名换页、睡眠、锁、空闲等状态。

如果大量时间花在CPU上，对CPU的剖析能够迅速解释原因；如果系统时间大量处于off-cpu状态，定位问题就会费时很多。但是仍然需要清楚一些概念：

处理器
核
硬件线程
CPU内存缓存
时钟频率
每指令周期数CPI和每周期指令数IPC
CPU指令
使用率
用户时间／内核时间
调度器
运行队列
抢占
多进程
多线程
字长

1.2 分析工具

工具	描述
uptime	平均负载
vmstat	包括系统范围的cpu平均负载
mpstat	查看所有cpu核信息
top	监控每个进程cpu用量
sar -u	查看cpu信息
pidstat	每个进程cpu用量分解
perf	cpu剖析和跟踪，性能计数分析

说明：

uptime,vmstat,mpstat,top,pidstat只能查询到cpu及负载的的使用情况。
perf可以跟着到进程内部具体函数耗时情况，并且可以指定内核函数进行统计，指哪打哪。

1.3 使用方式

查看系统cpu使用情况

top

查看所有cpu核信息，工具在sysstat包中

mpstat -P ALL 1 5	#每隔1秒打印5次所有信息

mpstat [ -P { cpu [,...] | ON | ALL } ] [ interval [ count ] ]
[root@node-135 ~]# mpstat -P ALL 1 5
Linux 3.10.0-1160.92.1.el7.x86_64 (node-135)    07/27/2023      _x86_64_        (2 CPU)

05:10:11 PM  CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest  %gnice   %idle
05:10:12 PM  all    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00
05:10:12 PM    0    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00
05:10:12 PM    1    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00

05:10:12 PM  CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest  %gnice   %idle
05:10:13 PM  all    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00
05:10:13 PM    0    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00
05:10:13 PM    1    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00  100.00
...

查看cpu使用情况以及平均负载

vmstat 1 5	#

vmstat [options] [delay [count]]
[root@node-135 ~]# 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
 1  0      0 1328796   2108 378172    0    0   325    48  158  249  1  2 94  3  0
 0  0      0 1328796   2108 378204    0    0     0     0   86  127  0  0 100  0  0
 1  0      0 1328796   2108 378204    0    0     0     0   68  103  0  0 100  0  0

进程cpu的统计信息

pidstat -u 1 -p pid

pidstat  [ -U [ username ] ] [ -u ]  [ -p { pid [,...]| SELF | ALL } ]  [ interval [ count ] ]

[root@node-135 ~]# pidstat -u 1 -p 1
Linux 3.10.0-1160.92.1.el7.x86_64 (node-135)    07/27/2023      _x86_64_        (2 CPU)

05:14:39 PM   UID       PID    %usr %system  %guest    %CPU   CPU  Command
05:14:40 PM     0         1    0.00    0.00    0.00    0.00     0  systemd
05:14:41 PM     0         1    0.00    0.00    0.00    0.00     0  systemd
05:14:42 PM     0         1    0.00    0.00    0.00    0.00     0  systemd
05:14:43 PM     0         1    0.00    0.00    0.00    0.00     0  systemd

跟踪进程内部函数级cpu使用情况，这个有点厉害了，能跟踪函数

perf top -p pid -e cpu-clock

Samples: 58  of event 'cpu-clock', 4000 Hz, Event count (approx.): 12686807 lost: 0/0 drop: 0/4
Overhead  Shared O  Symbol
  80.55%  [kernel]  [k] mpt_put_msg_frame
   8.57%  [kernel]  [k] _raw_spin_unlock_irqrestore
   2.98%  [kernel]  [k] finish_task_switch
   1.97%  [kernel]  [k] __radix_tree_preload
   1.97%  [kernel]  [k] put_page
   1.97%  [kernel]  [k] vmware_sched_clock
   0.88%  [kernel]  [k] __fget_light
   0.59%  dockerd   [.] sync.(*RWMutex).Lock
   0.52%  [kernel]  [k] futex_wait

2. 内存

2.1 说明

内存是为提高效率而生，实际分析问题的时候，内存出现问题可能不只是影响性能，而是影响服务或者引起其他问题。同样对于内存有些概念需要清楚：

主存
虚拟内存
常驻内存
地址空间
OOM
页缓存
缺页
换页
交换空间
交换
用户分配器libc、glibc、libmalloc和mtmalloc
LINUX内核级SLUB分配器

2.2 分析工具

工具	描述
free	缓存容量统计信息
vmstat	虚拟内存统计信息
top	监视每个进程的内存使用情况
pidstat	显示活动进程的内存使用统计
pmap	查看进程的内存映像信息
sar -r	查看内存
dtrace	动态跟踪
valgrind	分析程序性能及程序中内存泄露错误

2.3 使用方式

查看系统内存使用情况

free -m
[root@node-135 ~]# free -h
              total        used        free      shared  buff/cache   available
Mem:           1.8G        1.6G         90M         12M        137M         80M
Swap:          2.0G        1.0G        996M

虚拟内存统计信息

vmstat 1

查看系统内存情况

top

每隔1秒采集5次，获取内存的统计信息

pidstat  [ -r ]  [ -U [ username ] ]  [ -p { pid [,...]| SELF | ALL } ] [ -T { TASK | CHILD | ALL } ] [ interval [ count ] ]

[root@node-135 ~]# pidstat -p 8593 -r 1 5
Linux 3.10.0-1160.92.1.el7.x86_64 (node-135)    07/27/2023      _x86_64_        (2 CPU)

05:25:55 PM   UID       PID  minflt/s  majflt/s     VSZ    RSS   %MEM  Command
05:25:56 PM     0      8593      0.00      0.00  763936  14124   0.76  dockerd
05:25:57 PM     0      8593      0.00      0.00  763936  14124   0.76  dockerd
05:25:58 PM     0      8593      0.00      0.00  763936  14124   0.76  dockerd
05:25:59 PM     0      8593      0.00      0.00  763936  14124   0.76  dockerd
05:26:00 PM     0      8593      0.00      0.00  763936  14124   0.76  dockerd
Average:        0      8593      0.00      0.00  763936  14124   0.76  dockerd

查看进程的内存映像信息

pmap [options] pid [...]

pmap -d pid
[root@node-135 ~]# pmap -d 8593
8593:   /usr/bin/dockerd -H fd:// --containerd=/run/containerd/containerd.sock
Address           Kbytes Mode  Offset           Device    Mapping
000000c000000000   65536 rw--- 0000000000000000 000:00000   [ anon ]
000055e7d7140000   56980 r-x-- 0000000000000000 0fd:00000 dockerd
000055e7daae4000   28588 r---- 00000000037a4000 0fd:00000 dockerd
000055e7dc6cf000     588 rw--- 000000000538f000 0fd:00000 dockerd
000055e7dc762000     192 rw--- 0000000000000000 000:00000   [ anon ]
000055e7de446000     132 rw--- 0000000000000000 000:00000   [ anon ]
00007f7f44000000     132 rw--- 0000000000000000 000:00000   [ anon ]
00007f7f44021000   65404 ----- 0000000000000000 000:00000   [ anon ]
00007f7f4c000000     132 rw--- 0000000000000000 000:00000   [ anon ]
...

检测程序内存问题

valgrind --tool=memcheck --leak-check=full --log-file=./log.txt  ./程序名

valgrind [valgrind-options] [your-program] [your-program-options]

3. I/O

3.1 说明

磁盘通常是计算机最慢的子系统，也是最容易出现性能瓶颈的地方，因为磁盘离 CPU 距离最远而且 CPU 访问磁盘要涉及到机械操作，比如转轴、寻轨等。访问硬盘和访问内存之间的速度差别是以数量级来计算的，就像1天和1分钟的差别一样。要监测 IO 性能，有必要了解一下基本原理和 Linux 是如何处理硬盘和内存之间的 IO 的。

在理解磁盘IO之前，同样我们需要理解一些概念，例如：

文件系统
VFS
文件系统缓存
页缓存page cache
缓冲区高速缓存buffer cache
目录缓存
inode
inode缓存
noop调用策略

3.2 分析工具

工具	描述
iostat	磁盘详细统计信息
iotop	按进程查询磁盘IO的使用情况
pidstat	按进程查询磁盘IO的使用情况
perf	动态跟踪工具

3.3 使用方式

查看系统io信息

iotop

Total DISK READ :      74.74 K/s | Total DISK WRITE :      26.16 K/s
Actual DISK READ:      74.74 K/s | Actual DISK WRITE:      48.58 K/s
   TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN     IO>    COMMAND
  9743 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.05 % [kworker/1:3]
  9310 be/4 1000        0.00 B/s    3.74 K/s  0.00 %  0.00 % java -jar lib/sonar-application-9.1.0.~/postgres:5432/sonar [VM Periodic Tas]
  9339 be/4 200         0.00 B/s    7.47 K/s  0.00 %  0.00 % java -server -Dinstall4j.jvmDir=/usr/l~exus.karaf.NexusMain [VM Periodic Tas]
  9416 be/4 1000        0.00 B/s    3.74 K/s  0.00 %  0.00 % java -XX:+UseG1GC -Djava.io.tmpdir=/op~tstrap.Elasticsearch ...

统计io详细信息

iostat -d -x -k 1 10

[root@node-135 home]# iostat -d -x -k 1 2
Linux 3.10.0-1160.92.1.el7.x86_64 (node-135)    07/27/2023      _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              22.31   161.26   63.39    5.84  3506.85   871.70   126.49     4.74   68.28   61.82  138.35   3.02  20.91
scd0              0.00     0.00    0.01    0.00     0.44     0.00   114.22     0.00   43.67   43.67    0.00  42.89   0.03
dm-0              0.00     0.00   49.69    5.87  3357.45   220.04   128.78     4.39   78.92   77.62   90.01   3.09  17.15
dm-1              0.00     0.00   35.36  161.25   142.25   644.98     8.01    68.35  347.61   14.80  420.61   0.65  12.80

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              14.00     0.00    3.00    0.00    72.00     0.00    48.00     0.00    2.33    2.33    0.00   1.33   0.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    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
dm-1              0.00     0.00   16.00    0.00    64.00     0.00     8.00     0.02    1.62    1.62    0.00   0.25   0.40

查看进程级io的信息

pidstat -d 1 -p  pid

[root@node-135 home]# pidstat -d 1 -p 8593
Linux 3.10.0-1160.92.1.el7.x86_64 (node-135)    07/27/2023      _x86_64_        (2 CPU)

05:42:32 PM   UID       PID   kB_rd/s   kB_wr/s kB_ccwr/s  Command
05:42:33 PM     0      8593      0.00      0.00      0.00  dockerd
05:42:34 PM     0      8593      0.00      0.00      0.00  dockerd
05:42:35 PM     0      8593      0.00      0.00      0.00  dockerd
05:42:36 PM     0      8593      0.00      0.00      0.00  dockerd
05:42:37 PM     0      8593      0.00      4.00      0.00  dockerd

查看系统IO的请求，比如可以在发现系统IO异常时，可以使用该命令进行调查，就能指定到底是什么原因导致的IO异常

perf record -e block:block_rq_issue -ag

perf report
Samples: 87  of event 'block:block_rq_issue', Event count (approx.): 87
  Children      Self  Trace output
+   10.34%    10.34%  0,0 R 8 (4a 01 00 00 10 00 00 00 08 00) 0 + 0 [kworker/1:3]
+    1.15%     1.15%  8,0 R 0 () 2849088 + 64 [elasticsearch[s]
+    1.15%     1.15%  8,0 R 0 () 2849440 + 32 [elasticsearch[s]
+    1.15%     1.15%  8,0 R 0 () 2845376 + 16 [elasticsearch[s]
+    1.15%     1.15%  8,0 R 0 () 2845400 + 40 [elasticsearch[s]
+    1.15%     1.15%  8,0 R 0 () 2845440 + 32 [elasticsearch[s]
+    1.15%     1.15%  8,0 R 0 () 2845472 + 32 [elasticsearch[s]
+    1.15%     1.15%  8,0 R 0 () 2845504 + 32 [elasticsearch[s]
+    1.15%     1.15%  8,0 R 0 () 2845536 + 32 [elasticsearch[s]
+    1.15%     1.15%  8,0 R 0 () 2845568 + 64 [elasticsearch[s]

4. 网络

4.1 说明

网络的监测是所有 Linux 子系统里面最复杂的，有太多的因素在里面，比如：延迟、阻塞、冲突、丢包等，更糟的是与 Linux 主机相连的路由器、交换机、无线信号都会影响到整体网络，并且很难判断是因为 Linux 网络子系统的问题还是别的设备的问题，增加了监测和判断的复杂度。现在我们使用的所有网卡都称为自适应网卡，意思是说能根据网络上的不同网络设备导致的不同网络速度和工作模式进行自动调整。

4.2 分析工具

工具	描述
ping	主要透过ICMP封包来进行整个网络的状况报告
traceroute	用来检测发出数据包的主机到目标主机之间所经过的网关数量的工具
netstat	用于显示与IP、TCP、UDP和ICMP协议相关的统计数据，一般用于检验本机各端口的网络连接情况
ss	可以用来获取socket统计信息，而且比netstat更快速高效
host	可以用来查出某个主机名的IP，跟nslookup作用一样
tcpdump	是以包为单位进行输出的，阅读起来不是很方便
tcpflow	是面向tcp流的，每个tcp传输会保存成一个文件，很方便查看
sar -n DEV	网卡流量情况
sar -n SOCK	查询网络及tcp、udp状态信息

ICMP（Internet Control Message Protocol）Internet控制报文协议。它是TCP/IP协议簇的一个子协议，用于在IP主机、路由器之间传递控制消息。控制消息是指网络通不通、主机是否可达、路由是否可用等网络本身的消息。这些控制消息虽然并不传输用户数据，但是对于用户数据的传递起着重要的作用。

4.3 使用方式

显示网络统计信息，在net-tools包中，端口统计信息和ss基本一样

[root@node-135 home]# netstat -s
Ip:
    16106 total packets received
    64 forwarded
    0 incoming packets discarded
    16039 incoming packets delivered
    12629 requests sent out
    4 outgoing packets dropped
    16 dropped because of missing route
Icmp:
    12 ICMP messages received
    0 input ICMP message failed.
...
[root@node-135 home]# netstat -nltp
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      993/sshd
tcp        0      0 127.0.0.1:25            0.0.0.0:*               LISTEN      1503/master
tcp        0      0 127.0.0.1:40030         0.0.0.0:*               LISTEN      8581/containerd
tcp6       0      0 :::22                   :::*                    LISTEN      993/sshd
tcp6       0      0 :::5432                 :::*                    LISTEN      8912/docker-proxy
tcp6       0      0 ::1:25                  :::*                    LISTEN      1503/master
tcp6       0      0 :::9090                 :::*                    LISTEN      8900/docker-proxy
tcp6       0      0 :::8081                 :::*                    LISTEN      8886/docker-proxy

显示当前UDP连接状况

netstat -nu

显示UDP端口号的使用情况

netstat -apu

//统计机器中网络连接各个状态个数

netstat -a | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'

[root@node-135 home]# netstat -at
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address           Foreign Address         State
tcp        0      0 0.0.0.0:ssh             0.0.0.0:*               LISTEN
tcp        0      0 localhost:smtp          0.0.0.0:*               LISTEN
tcp        0      0 localhost:40030         0.0.0.0:*               LISTEN
tcp        0     48 node-135:ssh            192.168.17.1:51805      ESTABLISHED
tcp        0      0 node-135:ssh            192.168.17.1:51810      ESTABLISHED
tcp6       0      0 [::]:ssh                [::]:*                  LISTEN
tcp6       0      0 [::]:postgres           [::]:*                  LISTEN
tcp6       0      0 localhost:smtp          [::]:*                  LISTEN
tcp6       0      0 [::]:websm              [::]:*                  LISTEN
tcp6       0      0 [::]:tproxy             [::]:*                  LISTEN
[root@node-135 home]# netstat -a | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
LISTEN 8
ESTABLISHED 2

显示TCP连接

ss -t -a

显示sockets摘要信息

[root@node-135 home]# ss -s
Total: 1834 (kernel 1887)
TCP:   32 (estab 2, closed 22, orphaned 0, synrecv 0, timewait 0/0), ports 0

Transport Total     IP        IPv6
*         1887      -         -
RAW       1         0         1
UDP       3         2         1
TCP       10        5         5
INET      14        7         7
FRAG      0         0         0

显示所有udp sockets

ss -u -a

tcp,etcp状态

[root@node-135 home]# sar -n TCP,ETCP 1
Linux 3.10.0-1160.92.1.el7.x86_64 (node-135)    07/28/2023      _x86_64_        (2 CPU)

09:13:39 AM  active/s passive/s    iseg/s    oseg/s
09:13:40 AM      0.00      0.00      0.00      0.00

09:13:39 AM  atmptf/s  estres/s retrans/s isegerr/s   orsts/s
09:13:40 AM      0.00      0.00      0.00      0.00      0.00

09:13:40 AM  active/s passive/s    iseg/s    oseg/s
09:13:41 AM      0.00      0.00      1.00      1.00

查看网络IO

[root@node-135 home]# sar -n DEV 1 2
Linux 3.10.0-1160.92.1.el7.x86_64 (node-135)    07/28/2023      _x86_64_        (2 CPU)

09:14:54 AM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
09:14:55 AM vethab7170f     14.00     18.00      1.33      2.01      0.00      0.00      0.00
09:14:55 AM     ens37      0.00      0.00      0.00      0.00      0.00      0.00      0.00
09:14:55 AM        lo      0.00      0.00      0.00      0.00      0.00      0.00      0.00
09:14:55 AM br-9230369a4904      0.00      0.00      0.00      0.00      0.00      0.00      0.00
09:14:55 AM     ens33      0.00      0.00      0.00      0.00      0.00      0.00      0.00
09:14:55 AM veth03e8740     18.00     14.00      2.01      1.33      0.00      0.00      0.00
09:14:55 AM veth6725483      0.00      0.00      0.00      0.00      0.00      0.00      0.00
09:14:55 AM   docker0      0.00      0.00      0.00      0.00      0.00      0.00      0.00

09:14:55 AM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
09:14:56 AM vethab7170f      0.00      0.00      0.00      0.00      0.00      0.00      0.00
09:14:56 AM     ens37      3.00      2.00      0.26      0.28      0.00      0.00      0.00
09:14:56 AM        lo      0.00      0.00      0.00      0.00      0.00      0.00      0.00
09:14:56 AM br-9230369a4904      0.00      0.00      0.00      0.00      0.00      0.00      0.00
09:14:56 AM     ens33      0.00      0.00      0.00      0.00      0.00      0.00      0.00
09:14:56 AM veth03e8740      0.00      0.00      0.00      0.00      0.00      0.00      0.00
09:14:56 AM veth6725483      0.00      0.00      0.00      0.00      0.00      0.00      0.00
09:14:56 AM   docker0      0.00      0.00      0.00      0.00      0.00      0.00      0.00

抓包以包为单位进行输出

tcpdump -i eth1 host 192.168.1.1 and port 80 

[root@node-135 home]# tcpdump -i ens37 host 192.168.17.1 and port 22
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on ens37, link-type EN10MB (Ethernet), capture size 262144 bytes
09:18:00.178935 IP node-135.ssh > 192.168.17.1.51805: Flags [P.], seq 1526219631:1526219679, ack 3271988518, win 1432, length 48
09:18:00.220769 IP 192.168.17.1.51805 > node-135.ssh: Flags [.], ack 48, win 4101, length 0
09:18:00.242269 IP node-135.ssh > 192.168.17.1.51805: Flags [P.], seq 48:240, ack 1, win 1432, length 192
09:18:00.242408 IP node-135.ssh > 192.168.17.1.51805: Flags [P.], seq 240:320, ack 1, win 1432, length 80
09:18:00.242493 IP 192.168.17.1.51805 > node-135.ssh: Flags [.], ack 320, win 4100, length 0
09:18:00.242613 IP node-135.ssh > 192.168.17.1.51805: Flags [P.], seq 320:416, ack 1, win 1432, length 96
09:18:00.242789 IP node-135.ssh > 192.168.17.1.51805: Flags [P.], seq 416:480, ack 1, win 1432, length 64
09:18:00.242872 IP 192.168.17.1.51805 > node-135.ssh: Flags [.], ack 480, win 4106, length 0

抓包以流为单位显示数据内容

rpm -ivh https://download-ib01.fedoraproject.org/pub/epel/epel-release-latest-7.noarch.rpm;yum install -y tcpflow;

tcpflow -cp host 192.168.1.1

5. 系统负载

5.1 说明

Load 就是对计算机干活多少的度量（WikiPedia：the system Load is a measure of the amount of work that a compute system is doing）简单的说是进程队列的长度。Load Average 就是一段时间（1分钟、5分钟、15分钟）内平均Load。

5.2 分析工具

工具	描述
top	查看系统负载情况
uptime	查看系统负载情况
strace	统计跟踪内核态信息
vmstat	查看系统负载情况
dmesg	查看内核日志信息

5.3 使用方式

查看负载情况

uptime
top
vmstat
[root@node-135 home]# uptime
 09:38:45 up 16:36,  3 users,  load average: 0.01, 0.07, 0.11
[root@node-135 home]# vmstat
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 1  0 1276160 106256      0 324328    6   17    96    25  167  326  0  0 99  1  0

统计系统调用耗时情况

strace -c -p pid

[root@node-135 home]# strace -c -p  8886
strace: Process 8886 attached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 92.69    0.000203         101         2         1 futex		#重启服务
  7.31    0.000016          16         1           rt_sigreturn
------ ----------- ----------- --------- --------- ----------------
100.00    0.000219                     3         1 total

跟踪指定的系统操作例如epoll_wait

strace -T -e epoll_wait -p pid

[root@node-135 home]# strace -T -e epoll_wait -p 1
strace: Process 1 attached
epoll_wait(4, 3
[{EPOLLIN, {u32=3241125888, u64=94406622291968}}], 38, -1) = 1 <42.303390>

查看内核日志信息

[root@node-135 home]# dmesg
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 3.10.0-1160.92.1.el7.x86_64 (mockbuild@kbuilder.bsys.centos.org) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-44) (GCC) ) #1 SMP Tue Jun 20 11:48:01 UTC 2023
[    0.000000] Command line: BOOT_IMAGE=/vmlinuz-3.10.0-1160.92.1.el7.x86_64 root=/dev/mapper/centos-root ro crashkernel=auto rd.lvm.lv=centos/root rd.lvm.lv=centos/swap rhgb quiet LANG=en_US.UTF-8
[    0.000000] Disabled fast string operations
[    0.000000] e820: BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009ebff] usable
[    0.000000] BIOS-e820: [mem 0x000000000009ec00-0x000000000009ffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000000dc000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000007fedffff] usable
[    0.000000] BIOS-e820: [mem 0x000000007fee0000-0x000000007fefefff] ACPI data
...

6. 火焰图

6.1 说明

火焰图（Flame Graph是 Bredan Gregg 创建的一种性能分析图表，因为它的样子近似火焰而得名。

火焰图主要是用来展示 CPU的调用栈。

y 轴表示调用栈，每一层都是一个函数。调用栈越深，火焰就越高，顶部就是正在执行的函数，下方都是它的父函数。
x 轴表示抽样数，如果一个函数在 x 轴占据的宽度越宽，就表示它被抽到的次数多，即执行的时间长。
注意，x 轴不代表时间，而是所有的调用栈合并后，按字母顺序排列的。

火焰图就是看顶层的哪个函数占据的宽度最大。只要有”平顶”（plateaus），就表示该函数可能存在性能问题。颜色没有特殊含义，因为火焰图表示的是 CPU 的繁忙程度，所以一般选择暖色调。

常见的火焰图类型有On-CPU、Off-CPU、Memory、Hot/Cold、Differential等等。

6.2 安装依赖库

安装systemtap，默认系统已安装

yum install systemtap systemtap-runtime

内核调试库必须跟内核版本对应，例如：

[root@node-135 kernel]# uname -r
3.10.0-1160.92.1.el7.x86_64
#需要安装如下
kernel-debuginfo-common
kernel-debuginfo				
kernel-devel					#yum可直接安装
#去对应的网站下载即可（下面的几个应该都可以下载）：
http://mirror.facebook.net/centos-debuginfo/
http://linuxsoft.cern.ch/centos-debuginfo/
https://ftp.sjtu.edu.cn/scientific/7/archive/debuginfo/
ftp://mirror.switch.ch/pool/4/mirror/scientificlinux/7.0/

安装内核调试库

debuginfo-install  search kernel
debuginfo-install  search glibc

6.3 安装

git clone https://github.com/lidaohang/quick_location.git			#科学上网
cd quick_location

6.4 CPU级别火焰图

cpu占用过高，或者使用率提不上来，你能快速定位到代码的哪块有问题吗？
一般的做法可能就是通过日志等方式去确定问题。现在我们有了火焰图，能够非常清晰的发现哪个函数占用cpu过高，或者过低导致的问题。

6.4.1 on-CPU

cpu占用过高，执行中的时间通常又分为用户态时间user和系统态时间sys。
使用方式：

cd demo
gcc test.c -g -o test
./test

ps -ef|grep test
45721

//on-CPU user
sh ngx_on_cpu_u.sh 45721

//进入结果目录
cd ngx_on_cpu_u

//on-CPU kernel
sh ngx_on_cpu_k.sh 45721

//进入结果目录
cd ngx_on_cpu_k

//开一个临时端口8088
python -m SimpleHTTPServer 8088

//打开浏览器输入地址
127.0.0.1:8088/pid.svg

DEMO：

#include <stdio.h>
#include <stdlib.h>

void foo3()
{
}

void foo2()
{
  int i;
  for(i=0 ; i < 10; i++)
       foo3();
}

void foo1()
{
  int i;
  for(i = 0; i< 1000; i++)
     foo3();
}

int main(void)
{
  int i;
  for( i =0; i< 1000000000; i++) {
      foo1();
      foo2();
  }
}

DEMO火焰图：
在这里插入图片描述

6.4.2 off-CPU

cpu过低，利用率不高。等待下一轮CPU，或者等待I/O、锁、换页等等，其状态可以细分为可执行、匿名换页、睡眠、锁、空闲等状态。

使用方式：

// off-CPU user
sh ngx_off_cpu_u.sh pid

//进入结果目录
cd ngx_off_cpu_u

//off-CPU kernel
sh ngx_off_cpu_k.sh pid

//进入结果目录
cd ngx_off_cpu_k

//开一个临时端口8088
python -m SimpleHTTPServer 8088

//打开浏览器输入地址
127.0.0.1:8088/pid.svg

官网DEMO：
在这里插入图片描述

6.5 内存级别火焰图

如果线上程序出现了内存泄漏，并且只在特定的场景才会出现。这个时候我们怎么办呢？有什么好的方式和工具能快速的发现代码的问题呢？同样内存级别火焰图帮你快速分析问题的根源。

使用方式：

sh ngx_on_memory.sh pid

//进入结果目录
cd ngx_on_memory

//开一个临时端口8088
python -m SimpleHTTPServer 8088

//打开浏览器输入地址
127.0.0.1:8088/pid.svg

官网DEMO：
在这里插入图片描述

6.6 性能回退-红蓝差分火焰图

你能快速定位CPU性能回退的问题么？如果你的工作环境非常复杂且变化快速，那么使用现有的工具是来定位这类问题是很具有挑战性的。当你花掉数周时间把根因找到时，代码已经又变更了好几轮，新的性能问题又冒了出来。主要可以用到每次构建中，每次上线做对比看，如果损失严重可以立马解决修复。

通过抓取了两张普通的火焰图，然后进行对比，并对差异部分进行标色：红色表示上升，蓝色表示下降。差分火焰图是以当前（“修改后”）的profile文件作为基准，形状和大小都保持不变。因此你通过色彩的差异就能够很直观的找到差异部分，且可以看出为什么会有这样的差异。

cd quick_location

//抓取代码修改前的profile 1文件
perf record -F 99 -p pid -g -- sleep 30
perf script > out.stacks1

//抓取代码修改后的profile 2文件
perf record -F 99 -p pid -g -- sleep 30
perf script > out.stacks2

//生成差分火焰图:
./FlameGraph/stackcollapse-perf.pl ../out.stacks1 > out.folded1
./FlameGraph/stackcollapse-perf.pl ../out.stacks2 > out.folded2
./FlameGraph/difffolded.pl out.folded1 out.folded2 | ./FlameGraph/flamegraph.pl > diff2.svg

DEMO：

//test.c
#include <stdio.h>
#include <stdlib.h>

void foo3()
{
}

void foo2()
{
  int i;
  for(i=0 ; i < 10; i++)
       foo3();
}

void foo1()
{
  int i;
  for(i = 0; i< 1000; i++)
     foo3();
}

int main(void)
{
  int i;
  for( i =0; i< 1000000000; i++) {
      foo1();
      foo2();
  }
}

//test1.c
#include <stdio.h>
#include <stdlib.h>

void foo3()
{
}

void foo2()
{
  int i;
  for(i=0 ; i < 10; i++)
       foo3();
}

void foo1()
{
  int i;
  for(i = 0; i< 1000; i++)
     foo3();
}

void add()
{
  int i;
  for(i = 0; i< 10000; i++)
     foo3();
}

int main(void)
{
  int i;
  for( i =0; i< 1000000000; i++) {
      foo1();
      foo2();
      add();
  }
}

DEMO红蓝差分火焰图：
在这里插入图片描述

7. 案例分析

7.1 接入层nginx集群异常现象

通过监控插件发现在2017.09.25 19点nginx集群请求流量出现大量的499，5xx状态码。并且发现机器cpu使用率升高，目前一直持续中。

7.2 分析nginx相关指标

a) 分析nginx请求流量
在这里插入图片描述
结论：
通过上图发现流量并没有突增，反而下降了，跟请求流量突增没关系。
b) 分析nginx响应时间

结论：
通过上图发现nginx的响应时间有增加可能跟nginx自身有关系或者跟后端upstream响应时间有关系。
c) 分析nginx upstream响应时间
在这里插入图片描述
结论：

通过上图发现nginx upstream 响应时间有增加，目前猜测可能后端upstream响应时间拖住nginx，导致nginx出现请求流量异常。

7.3 分析系统cpu情况

a) 通过top观察系统指标
在这里插入图片描述
结论：

发现nginx worker cpu比较高
b) 分析nginx进程内部cpu情况

perf top -p pid

结论：

发现主要开销在free,malloc,json解析上面

7.4 火焰图分析cpu

a) 生成用户态cpu火焰图

//test.c
#include <stdio.h>
#include <stdlib.h>
//on-CPU user
sh ngx_on_cpu_u.sh pid

//进入结果目录
cd ngx_on_cpu_u

//开一个临时端口8088
python -m SimpleHTTPServer 8088

//打开浏览器输入地址
127.0.0.1:8088/pid.svg

在这里插入图片描述
结论：

发现代码里面有频繁的解析json操作，并且发现这个json库性能不高，占用cpu挺高。

7.5 案例总结

a) 分析请求流量异常，得出nginx upstream后端机器响应时间拉长

b) 分析nginx进程cpu高，得出nginx内部模块代码有耗时的json解析以及内存分配回收操作

7.5.1 深入分析

根据以上两点问题分析的结论，我们进一步深入分析。

后端upstream响应拉长，最多可能影响nginx的处理能力。但是不可能会影响nginx内部模块占用过多的cpu操作。并且当时占用cpu高的模块，是在请求的时候才会走的逻辑。不太可能是upstram后端拖住nginx，从而触发这个cpu的耗时操作。

7.5.2 解决方式

遇到这种问题，我们优先解决已知的，并且非常明确的问题。那就是cpu高的问题。解决方式先降级关闭占用cpu过高的模块，然后进行观察。经过降级关闭该模块cpu降下来了，并且nginx请求流量也正常了。之所以会影响upstream时间拉长，因为upstream后端的服务调用的接口可能是个环路再次走回到nginx。