瓶颈排查 —— 最耗CPU、丢包、网络错误|8月更文挑战

668 阅读7分钟

这是我参与8月更文挑战的第30天,活动详情查看:8月更文挑战

1 定位线上最耗CPU的线程

第一步:通过 top 命令找到最耗时 ( Shift + P ) 的进程

[root@localhost ~]# top
top - 11:11:05 up 20:02,  3 users,  load average: 0.09, 0.07, 0.05
Tasks: 225 total,   1 running, 224 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.0 us,  0.7 sy,  0.0 ni, 99.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  1421760 total,   135868 free,   758508 used,   527384 buff/cache
KiB Swap:  2097148 total,  2070640 free,    26508 used.   475852 avail Mem
Change delay from 3.0 to
   PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 98344 root      20   0 2422552  23508  12108 S   0.7  1.7   0:00.32 java
     1 root      20   0  194100   6244   3184 S   0.0  0.4   0:20.41 systemd
     2 root      20   0       0      0      0 S   0.0  0.0   0:00.12 kthreadd
     4 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:20.25 ksoftirqd/0

找到进程号是98344。

第二步:找到进程中最耗CUP的线程

使用ps -Lp <pid> cu命令,查看某个进程中的线程CPU消耗排序:

[root@localhost ~]# ps -Lp 98344 cu
USER        PID    LWP %CPU NLWP %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root      98344  98344  0.0   10  4.1 2422552 59060 pts/0   Sl+  11:09   0:00 java
root      98344  98345  0.0   10  4.1 2422552 59060 pts/0   Sl+  11:09   0:04 java
root      98344  98346  0.0   10  4.1 2422552 59060 pts/0   Sl+  11:09   0:01 VM Thread
root      98344  98347  0.0   10  4.1 2422552 59060 pts/0   Sl+  11:09   0:00 Reference Handl
root      98344  98348  0.0   10  4.1 2422552 59060 pts/0   Sl+  11:09   0:00 Finalizer
root      98344  98349  0.0   10  4.1 2422552 59060 pts/0   Sl+  11:09   0:00 Signal Dispatch
root      98344  98350  0.0   10  4.1 2422552 59060 pts/0   Sl+  11:09   0:05 C2 CompilerThre
root      98344  98351  0.0   10  4.1 2422552 59060 pts/0   Sl+  11:09   0:00 C1 CompilerThre
root      98344  98352  0.0   10  4.1 2422552 59060 pts/0   Sl+  11:09   0:00 Service Thread
root      98344  98353  0.1   10  4.1 2422552 59060 pts/0   Sl+  11:09   0:19 VM Periodic Tas

TIME列可看出哪个线程耗费CUP多,LWP列可以看到线程的ID号,但需要转换成16进制才可以查询线程堆栈信息。

第三步:获取线程id的十六进制码

使用printf '%x\n' <LWP>命令做进制转换:

[root@localhost ~]# printf '%x\n' 98345
18029

第四步:查看线程堆栈信息

使用jstack获取堆栈信息jstack <pid> | grep -A 10 <16进制LWP>

[root@localhost ~]# jstack 98344 | grep -A 10 0x18029
"main" #1 prio=5 os_prio=0 tid=0x00007fb88404b800 nid=0x18029 waiting on condition [0x00007fb88caab000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
        at java.lang.Thread.sleep(Native Method)
        at java.lang.Thread.sleep(Thread.java:340)
        at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
        at demo.MathGame.main(MathGame.java:17)
​
"VM Thread" os_prio=0 tid=0x00007fb8840f2800 nid=0x1802a runnable
"VM Periodic Task Thread" os_prio=0 tid=0x00007fb884154000 nid=0x18031 waiting on condition

通过命令我们可以看到这个线程的对应的耗时代码是在 demo.MathGame.main(MathGame.java:17)

2 定位丢包错包情况

watch more /proc/net/dev用于定位丢包,错包情况,以便看网络瓶颈,重点关注drop(包被丢弃)和网络包传送的总量,不要超过网络上限:

[root@localhost ~]# watch -n 2 more /proc/net/dev
Every 2.0s: more /proc/net/dev                                                                                                                                                   Fri May  1 17:16:55 2020
Inter-|   Receive                                                |  Transmit
 face |bytes    packets errs drop fifo frame compressed multicast|bytes    packets errs drop fifo colls carrier compressed
    lo:   10025     130    0    0    0     0          0         0    10025     130    0    0    0     0       0          0
 ens33: 759098071  569661    0    0    0     0          0         0 19335572  225551    0    0    0     0       0          0
  • 最左边的表示接口的名字,Receive表示收包,Transmit表示发送包
  • bytes:表示收发的字节数
  • packets:表示收发正确的包量
  • errs:表示收发错误的包量
  • drop:表示收发丢弃的包量

3 查看路由经过的地址

traceroute ip可以查看路由经过的地址,常用来统计网络在各个路由区段的耗时,如:

[root@localhost ~]# traceroute 14.215.177.38
traceroute to 14.215.177.38 (14.215.177.38), 30 hops max, 60 byte packets
 1  CD-HZTK5H2.mshome.net (192.168.137.1)  0.126 ms * *
 2  * * *
 3  10.250.112.3 (10.250.112.3)  12.587 ms  12.408 ms  12.317 ms
 4  172.16.227.230 (172.16.227.230)  2.152 ms  2.040 ms  1.956 ms
 5  172.16.227.202 (172.16.227.202)  11.884 ms  11.746 ms  12.692 ms
 6  172.16.227.65 (172.16.227.65)  2.665 ms  3.143 ms  2.923 ms
 7  171.223.206.217 (171.223.206.217)  2.834 ms  2.752 ms  2.654 ms
 8  182.150.18.205 (182.150.18.205)  5.145 ms  5.815 ms  5.542 ms
 9  110.188.6.33 (110.188.6.33)  3.514 ms 171.208.199.185 (171.208.199.185)  3.431 ms 171.208.199.181 (171.208.199.181)  10.768 ms
10  202.97.29.17 (202.97.29.17)  29.574 ms 202.97.30.146 (202.97.30.146)  32.619 ms *
11  113.96.5.126 (113.96.5.126)  36.062 ms 113.96.5.70 (113.96.5.70)  35.940 ms 113.96.4.42 (113.96.4.42)  45.859 ms
12  90.96.135.219.broad.fs.gd.dynamic.163data.com.cn (219.135.96.90)  35.680 ms  35.468 ms  35.304 ms
13  14.215.32.102 (14.215.32.102)  35.135 ms 14.215.32.110 (14.215.32.110)  35.613 ms 14.29.117.242 (14.29.117.242)  54.712 ms
14  * 14.215.32.134 (14.215.32.134)  49.518 ms 14.215.32.122 (14.215.32.122)  47.652 ms
15  * * *
...

4 查看网络错误

netstat -i可以查看网络错误:

[root@localhost ~]# netstat -i
Kernel Interface table
Iface             MTU    RX-OK RX-ERR RX-DRP RX-OVR    TX-OK TX-ERR TX-DRP TX-OVR Flg
ens33            1500   570291      0      0 0        225897      0      0      0 BMRU
lo              65536      130      0      0 0           130      0      0      0 LRU
  • Iface: 网络接口名称
  • MTU: 最大传输单元,它限制了数据帧的最大长度,不同的网络类型都有一个上限值,如:以太网的MTU是1500
  • RX-OK:接收时,正确的数据包数
  • RX-ERR:接收时,产生错误的数据包数
  • RX-DRP:接收时,丢弃的数据包数
  • RX-OVR:接收时,由于过速(在数据传输中,由于接收设备不能接收按照发送速率传送来的数据而使数据丢失)而丢失的数据包数
  • TX-OK:发送时,正确的数据包数
  • TX-ERR:发送时,产生错误的数据包数
  • TX-DRP:发送时,丢弃的数据包数
  • TX-OVR:发送时,由于过速而丢失的数据包数
  • Flg:标志,B 已经设置了一个广播地址。L 该接口是一个回送设备。M 接收所有数据包(混乱模式)。N 避免跟踪。O 在该接口上,禁用ARP。P 这是一个点到点链接。R 接口正在运行。U 接口处于“活动”状态

5 包的重传率

cat /proc/net/snmp 查看和分析240秒内网络包量、流量、错包和丢包。通过 RetransSegsOutSegs 来计算:

TCP重传率 =(RetransSegs ÷ OutSegs)× 100%

[root@localhost ~]# cat /proc/net/snmp
Ip: Forwarding DefaultTTL InReceives InHdrErrors InAddrErrors ForwDatagrams InUnknownProtos InDiscards InDelivers OutRequests OutDiscards OutNoRoutes ReasmTimeout ReasmReqds ReasmOKs ReasmFails FragOKs FragFails FragCreates
Ip: 1 64 241708 0 0 0 0 0 238724 225517 15 0 0 0 0 0 0 0 0
Icmp: InMsgs InErrors InCsumErrors InDestUnreachs InTimeExcds InParmProbs InSrcQuenchs InRedirects InEchos InEchoReps InTimestamps InTimestampReps InAddrMasks InAddrMaskReps OutMsgs OutErrors OutDestUnreachs OutTimeExcds OutParmProbs OutSrcQuenchs OutRedirects OutEchos OutEchoReps OutTimestamps OutTimestampReps OutAddrMasks OutAddrMaskReps
Icmp: 149 0 0 50 99 0 0 0 0 0 0 0 0 0 147 0 147 0 0 0 0 0 0 0 0 0 0
IcmpMsg: InType3 InType11 OutType3
IcmpMsg: 50 99 147
Tcp: RtoAlgorithm RtoMin RtoMax MaxConn ActiveOpens PassiveOpens AttemptFails EstabResets CurrEstab InSegs OutSegs RetransSegs InErrs OutRsts InCsumErrors
Tcp: 1 200 120000 -1 376 6 0 0 4 236711 223186 292 0 4 0
Udp: InDatagrams NoPorts InErrors OutDatagrams RcvbufErrors SndbufErrors InCsumErrors
Udp: 1405 438 0 1896 0 0 0
UdpLite: InDatagrams NoPorts InErrors OutDatagrams RcvbufErrors SndbufErrors InCsumErrors
UdpLite: 0 0 0 0 0 0 0

TCP重传率为:(292÷223186) × 100% = 0.13%

  • 平均每秒新增TCP连接数:通过/proc/net/snmp文件得到最近240秒内PassiveOpens的增量,除以240得到每秒的平均增量
  • 机器的TCP连接数 :通过/proc/net/snmp文件的CurrEstab得到TCP连接数
  • 平均每秒的UDP接收数据报:通过/proc/net/snmp文件得到最近240秒内InDatagrams的增量,除以240得到平均每秒的UDP接收数据报
  • 平均每秒的UDP发送数据报:通过/proc/net/snmp文件得到最近240秒内OutDatagrams的增量,除以240得到平均每秒的UDP发送数据报