只要业务逻辑代码写正确,处理好业务状态在多线程的并发问题,很少会有调优方面的需求。最多就是在性能监控平台发现某些接口的调用耗时偏高,然后再发现某一SQL或第三方接口执行超时之类的。如果你是负责中间件或IM通讯相关项目开发,或许就需要偏向CPU、磁盘、网络及内存方面的问题排查及调优技能
$ uptime 10:54:52 up 1124 days, 16:31, 6 users, load average: 3.67, 2.13, 1.79
vmstat 和 pidstat。vmvmstat 可查看系统总体的指标,pidstat则详细到每一个进程服务的指标
$ vmstat 2 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 3498472 315836 3819540 0 0 0 1 2 0 3 1 96 0 0 -------- cs(context switch)是每秒上下文切换的次数 in(interrupt)则是每秒中断的次数 r(Running or Runnable)是就绪队列的长度,也就是正在运行和等待 CPU 的进程数.当这个值超过了CPU数目,就会出现CPU瓶颈 b(Blocked)则是处于不可中断睡眠状态的进程数
# pidstat -w Linux 3.10.0-862.el7.x86_64 (8f57ec39327b) 07/11/2021 _x86_64_ (6 CPU) 06:43:23 PM UID PID cswch/s nvcswch/s Command 06:43:23 PM 0 1 0.00 0.00 java 06:43:23 PM 0 102 0.00 0.00 bash 06:43:23 PM 0 150 0.00 0.00 pidstat ------各项指标解析--------------------------- PID 进程id Cswch/s 每秒主动任务上下文切换数量 Nvcswch/s 每秒被动任务上下文切换数量。大量进程都在争抢 CPU 时,就容易发生非自愿上下文切换 Command 进程执行命令
top -o 字段名
如:top -o %CPU
。 -o
可以指定排序字段,顺序从大到小# top -o %MEM top - 18:20:27 up 26 days, 8:30, 2 users, load average: 0.04, 0.09, 0.13 Tasks: 168 total, 1 running, 167 sleeping, 0 stopped, 0 zombie %Cpu(s): 0.3 us, 0.5 sy, 0.0 ni, 99.1 id, 0.0 wa, 0.0 hi, 0.1 si, 0.0 st KiB Mem: 32762356 total, 14675196 used, 18087160 free, 884 buffers KiB Swap: 2103292 total, 0 used, 2103292 free. 6580028 cached Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2323 mysql 20 0 19.918g 4.538g 9404 S 0.333 14.52 352:51.44 mysqld 1260 root 20 0 7933492 1.173g 14004 S 0.333 3.753 58:20.74 java 1520 daemon 20 0 358140 3980 776 S 0.333 0.012 6:19.55 httpd 1503 root 20 0 69172 2240 1412 S 0.333 0.007 0:48.05 httpd ---------各项指标解析--------------------------------------------------- 第一行统计信息区 18:20:27 当前时间 up 25 days, 17:29 系统运行时间,格式为时:分 1 user 当前登录用户数 load average: 0.04, 0.09, 0.13 系统负载,三个数值分别为 1分钟、5分钟、15分钟前到现在的平均值 Tasks:进程相关信息 running 正在运行的进程数 sleeping 睡眠的进程数 stopped 停止的进程数 zombie 僵尸进程数 Cpu(s):CPU相关信息 %us:表示用户空间程序的cpu使用率(没有通过nice调度) %sy:表示系统空间的cpu使用率,主要是内核程序 %ni:表示用户空间且通过nice调度过的程序的cpu使用率 %id:空闲cpu %wa:cpu运行时在等待io的时间 %hi:cpu处理硬中断的数量 %si:cpu处理软中断的数量 Mem 内存信息 total 物理内存总量 used 使用的物理内存总量 free 空闲内存总量 buffers 用作内核缓存的内存量 Swap 内存信息 total 交换区总量 used 使用的交换区总量 free 空闲交换区总量 cached 缓冲的交换区总量
top -Hp pid
或pidstat -t -p pid
命令查看进程具体线程使用 CPU 情况,从而找到具体的导致 CPU 高的线程 # top top - 18:20:27 up 26 days, 8:30, 2 users, load average: 0.04, 0.09, 0.13 Tasks: 168 total, 1 running, 167 sleeping, 0 stopped, 0 zombie %Cpu(s): 0.3 us, 0.5 sy, 0.0 ni, 99.1 id, 0.0 wa, 0.0 hi, 0.1 si, 0.0 st KiB Mem: 32762356 total, 14675196 used, 18087160 free, 884 buffers KiB Swap: 2103292 total, 0 used, 2103292 free. 6580028 cached Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2323 mysql 20 0 19.918g 4.538g 9404 S 0.333 14.52 352:51.44 mysqld 1260 root 20 0 7933492 1.173g 14004 S 0.333 3.753 58:20.74 java ....
# free -m total used free shared buffers cached Mem: 32107 30414 1692 0 1962 8489 -/+ buffers/cache: 19962 12144 Swap: 0 0 0
Swap 其实就是把一块磁盘空间或者一个本地文件,当成内存来使用。swap 换出,把进程暂时不用的内存数据存储到磁盘中,并释放这些数据占用的内存。swap 换入,在进程再次访问这些内存的时候,把它们从磁盘读到内存中来
# iostat -x -k -d 1 1 Linux 4.4.73-5-default (ceshi44) 2021年07月08日 _x86_64_ (40 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.08 2.48 0.37 11.71 27.80 507.24 88.53 0.02 1.34 14.96 0.90 0.09 0.10 sdb 0.00 1.20 1.28 16.67 30.91 647.83 75.61 0.17 9.51 9.40 9.52 0.32 0.57 ------ rrqm/s: 每秒对该设备的读请求被合并次数,文件系统会对读取同块(block)的请求进行合并 wrqm/s: 每秒对该设备的写请求被合并次数 r/s: 每秒完成的读次数 w/s: 每秒完成的写次数 rkB/s: 每秒读数据量(kB为单位) wkB/s: 每秒写数据量(kB为单位) avgrq-sz: 平均每次IO操作的数据量(扇区数为单位) avgqu-sz: 平均等待处理的IO请求队列长度 await: 平均每次IO请求等待时间(包括等待时间和处理时间,毫秒为单位) svctm: 平均每次IO请求的处理时间(毫秒为单位) %util: 采用周期内用于IO操作的时间比率,即IO队列非空的时间比率
# pidstat -d Linux 3.10.0-862.el7.x86_64 (8f57ec39327b) 07/11/2021 _x86_64_ (6 CPU) 06:42:35 PM UID PID kB_rd/s kB_wr/s kB_ccwr/s Command 06:42:35 PM 0 1 1.05 0.00 0.00 java 06:42:35 PM 0 102 0.04 0.05 0.00 bash ------ kB_rd/s 每秒从磁盘读取的KB kB_wr/s 每秒写入磁盘KB kB_ccwr/s 任务取消的写入磁盘的KB。当任务截断脏的pagecache的时候会发生 Command 进程执行命令
$ strace -p 18940 strace: Process 18940 attached ... mmap(NULL, 314576896, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0f7aee9000 mmap(NULL, 314576896, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f0f682e8000 write(3, "2018-12-05 15:23:01,709 - __main"..., 314572844 ) = 314572844 munmap(0x7f0f682e8000, 314576896) = 0 write(3, "\n", 1) = 1 munmap(0x7f0f7aee9000, 314576896) = 0 close(3) = 0 stat("/tmp/logtest.txt.1", {st_mode=S_IFREG|0644, st_size=943718535, ...}) = 0
$ lsof -p 18940 COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME java 18940 root cwd DIR 0,50 4096 1549389 / … java 18940 root 2u CHR 136,0 0t0 3 /dev/pts/0 java 18940 root 3w REG 8,1 117944320 303 /tmp/logtest.txt ---- FD 表示文件描述符号,TYPE 表示文件类型,NODE NAME 表示文件路径
当一个网络帧到达网卡后,网卡会通过 DMA 方式,把这个网络包放到收包队列中;然后通过硬中断,告诉中断处理程序已经收到了网络包。接着,网卡中断处理程序会为网络帧分配内核数据结构(sk_buff),并将其拷贝到 sk_buff 缓冲区中;然后再通过软中断,通知内核收到了新的网络帧。内核协议栈从缓冲区中取出网络帧,并通过网络协议栈,从下到上逐层处理这个网络帧
# ifconfig em1 em1 Link encap:Ethernet HWaddr 80:18:44:EB:18:98 inet addr:192.168.0.44 Bcast:192.168.0.255 Mask:255.255.255.0 inet6 addr: fe80::8218:44ff:feeb:1898/64 Scope:Link UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:3098067963 errors:0 dropped:5379363 overruns:0 frame:0 TX packets:2804983784 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:1661766458875 (1584783.9 Mb) TX bytes:1356093926505 (1293271.9 Mb) Interrupt:83 ----- TX 和 RX 部分的 errors、dropped、overruns、carrier 以及 collisions 等指标不为 0 时, 通常表示出现了网络 I/O 问题。 errors 表示发生错误的数据包数,比如校验错误、帧同步错误等 dropped 表示丢弃的数据包数,即数据包已经收到了 Ring Buffer,但因为内存不足等原因丢包 overruns 表示超限数据包数,即网络 I/O 速度过快,导致 Ring Buffer 中的数据包来不及处理(队列满)而导致的丢包 carrier 表示发生 carrirer 错误的数据包数,比如双工模式不匹配、物理电缆出现问题等 collisions 表示碰撞数据包数
# sar -n DEV 1 Linux 4.4.73-5-default (ceshi44) 2022年03月31日 _x86_64_ (40 CPU) 15时39分40秒 IFACE rxpck/s txpck/s rxkB/s txkB/s rxcmp/s txcmp/s rxmcst/s %ifutil 15时39分41秒 em1 1241.00 1022.00 600.48 590.39 0.00 0.00 165.00 0.49 15时39分41秒 lo 636.00 636.00 7734.06 7734.06 0.00 0.00 0.00 0.00 15时39分41秒 em4 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 15时39分41秒 em3 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 15时39分41秒 em2 26.00 20.00 6.63 8.80 0.00 0.00 0.00 0.01 ---- rxpck/s 和 txpck/s 分别是接收和发送的 PPS,单位为包 / 秒 rxkB/s 和 txkB/s 分别是接收和发送的吞吐量,单位是 KB/ 秒 rxcmp/s 和 txcmp/s 分别是接收和发送的压缩数据包数,单位是包 / 秒
# ethtool em1 | grep Speed Speed: 1000Mb/s
# ping www.baidu.com PING www.a.shifen.com (14.215.177.38) 56(84) bytes of data. 64 bytes from 14.215.177.38: icmp_seq=1 ttl=56 time=53.9 ms 64 bytes from 14.215.177.38: icmp_seq=2 ttl=56 time=52.3 ms 64 bytes from 14.215.177.38: icmp_seq=3 ttl=56 time=53.8 ms 64 bytes from 14.215.177.38: icmp_seq=4 ttl=56 time=56.0 ms
[root@root ~]$>#ss -ant | awk '{++S[$1]} END {for(a in S) print a, S[a]}' LISTEN 96 CLOSE-WAIT 527 ESTAB 8520 State 1 SYN-SENT 2 TIME-WAIT 660 [root@root ~]$>#netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}' CLOSE_WAIT 530 ESTABLISHED 8511 FIN_WAIT2 3 TIME_WAIT 809
jmap -histo:live [pid]
和jmap -dump:format=b,file=filename [pid]
前者可以统计堆内存对象大小和数量,后者可以把堆内存 dump 下来-XX:+HeapDumpOnOutOfMemoryError
来保存OOM时的dump文件jstack –l pid | grep -i –E 'BLOCKED | deadlock'
, 加上参数 -l,jstack 命令可以快速打印出造成死锁的代码# jstack -l 28764 Full thread dump Java HotSpot(TM) 64-Bit Server VM (13.0.2+8 mixed mode, sharing): ..... "Thread-0" #14 prio=5 os_prio=0 cpu=0.00ms elapsed=598.37s tid=0x000001b3c25f7000 nid=0x4abc waiting for monitor entry [0x00000061661fe000] java.lang.Thread.State: BLOCKED (on object monitor) at com.Test$DieLock.run(Test.java:52) - waiting to lock <0x0000000712d7c230> (a java.lang.Object) - locked <0x0000000712d7c220> (a java.lang.Object) at java.lang.Thread.run(java.base@13.0.2/Thread.java:830) Locked ownable synchronizers: - None "Thread-1" #15 prio=5 os_prio=0 cpu=0.00ms elapsed=598.37s tid=0x000001b3c25f8000 nid=0x1984 waiting for monitor entry [0x00000061662ff000] java.lang.Thread.State: BLOCKED (on object monitor) at com.Test$DieLock.run(Test.java:63) - waiting to lock <0x0000000712d7c220> (a java.lang.Object) - locked <0x0000000712d7c230> (a java.lang.Object) at java.lang.Thread.run(java.base@13.0.2/Thread.java:830) ..... Found one Java-level deadlock: ============================= "Thread-0": waiting to lock monitor 0x000001b3c1e4c480 (object 0x0000000712d7c230, a java.lang.Object), which is held by "Thread-1" "Thread-1": waiting to lock monitor 0x000001b3c1e4c080 (object 0x0000000712d7c220, a java.lang.Object), which is held by "Thread-0" Java stack information for the threads listed above: =================================================== "Thread-0": at com.Test$DieLock.run(Test.java:52) - waiting to lock <0x0000000712d7c230> (a java.lang.Object) - locked <0x0000000712d7c220> (a java.lang.Object) at java.lang.Thread.run(java.base@13.0.2/Thread.java:830) "Thread-1": at com.Test$DieLock.run(Test.java:63) - waiting to lock <0x0000000712d7c220> (a java.lang.Object) - locked <0x0000000712d7c230> (a java.lang.Object) at java.lang.Thread.run(java.base@13.0.2/Thread.java:830) Found 1 deadlock.