首页
学习
活动
专区
工具
TVP
发布
社区首页 >专栏 >JAVA 应用线上故障排查手册

JAVA 应用线上故障排查手册

作者头像
IT运维技术圈
发布2022-10-24 15:00:14
5290
发布2022-10-24 15:00:14
举报
文章被收录于专栏:IT运维技术圈IT运维技术圈

线上故障主要会包括 CPU、磁盘、内存(含JVM)以及网络问题,而大多数故障可能会包含不止一个层面的问题,所以进行排查时候尽量四个方面依次排查一遍。 基本上出问题就是 df、free、top、jstack、jmap具体问题具体分析

1. CPU

首先会排查 CPU 方面的问题。CPU 异常往往还是比较好定位的。原因包括业务逻辑问题(死循环)、频繁 gc 以及上下文切换过多。而最常见的往往是业务逻辑(或者框架)导致的,可以使用 jstack 来分析对应的堆栈情况。

1)使用 jstack 分析 CPU 问题

先用 ps 命令找到对应进程的 pid(如果你有好几个目标进程,可以先用 top 看一下哪个占用比较高。

[root@VM_0_7_centos mblog]# top
top - 14:23:00 up 147 days,  2:54,  3 users,  load average: 0.00, 0.10, 0.16
Tasks: 119 total,   1 running, 118 sleeping,   0 stopped,   0 zombie
%Cpu(s):  1.7 us,  2.7 sy,  0.0 ni, 95.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  1882216 total,    74340 free,  1430976 used,   376900 buff/cache
KiB Swap:        0 total,        0 free,        0 used.   271692 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND                                                                                                      
12026 root      20   0  137648   7900   1116 S  0.7  0.4   1:17.51 YDService                                                                                                    
29517 root      20   0  638800  56188   3324 S  0.7  3.0  41:43.95 dockerd                                                                                                      
14232 root      20   0  742548  13408   1476 S  0.3  0.7 600:08.06 barad_agent                                                                                                  
21163 root      20   0 2488632  45992    252 S  0.3  2.4  90:06.64 java                                                                                                         
23464 root      20   0  157228   2520    812 S  0.3  0.1   0:34.20 sshd                                                                                                         
    1 root      20   0   43588   2808   1404 S  0.0  0.1  12:07.03 systemd                                                                                                      
    2 root      20   0       0      0      0 S  0.0  0.0   0:00.87 kthreadd                                                                                                     
    3 root      20   0       0      0      0 S  0.0  0.0   4:55.87 ksoftirqd/0                                                                                                  
    5 root       0 -20       0      0      0 S  0.0  0.0   0:00.00 kworker/0:0H                                                                                                 
    7 root      rt   0       0      0      0 S  0.0  0.0   0:00.00 migration/0                                                                                                  
    8 root      20   0       0      0      0 S  0.0  0.0   0:00.00 rcu_bh                                                                                                       
    9 root      20   0       0      0      0 S  0.0  0.0  17:49.20 rcu_sched                                                                                                    
   10 root       0 -20       0      0      0 S  0.0  0.0   0:00.00 lru-add-drain                                                                                             
   11 root      rt   0       0      0      0 S  0.0  0.0   0:48.47 watchdog/0      
   13 root      20   0       0      0      0 S  0.0  0.0   0:00.00 kdevtmpfs  

top -H -p pid来找到 CPU 使用率比较高的一些线程

[root@VM_0_7_centos mblog]# top -H -p 26550
top - 14:24:31 up 147 days,  2:56,  3 users,  load average: 0.19, 0.13, 0.16
Threads:  48 total,   0 running,  48 sleeping,   0 stopped,   0 zombie
%Cpu(s):  2.3 us,  2.3 sy,  0.0 ni, 95.3 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  1882216 total,    70300 free,  1433760 used,   378156 buff/cache
KiB Swap:        0 total,        0 free,        0 used.   268880 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND                                                                                                      
26550 root      20   0 2581136 280592  12912 S  0.0 14.9   0:00.00 java                                                                                                         
26551 root      20   0 2581136 280592  12912 S  0.0 14.9   0:08.46 java                                                                                                         
26552 root      20   0 2581136 280592  12912 S  0.0 14.9   0:01.37 java                                                                                                         
26553 root      20   0 2581136 280592  12912 S  0.0 14.9   0:00.00 java                                                                                                         
26554 root      20   0 2581136 280592  12912 S  0.0 14.9   0:00.01 java                                                                                                         
26555 root      20   0 2581136 280592  12912 S  0.0 14.9   0:00.00 java                                                                                                         
26556 root      20   0 2581136 280592  12912 S  0.0 14.9   0:11.02 java                                                                                                         
26557 root      20   0 2581136 280592  12912 S  0.0 14.9   0:02.27 java                                                                                                         
26558 root      20   0 2581136 280592  12912 S  0.0 14.9   0:00.00 java                                                                                                         
26559 root      20   0 2581136 280592  12912 S  0.0 14.9   0:00.25 java                                                                                                         
26701 root      20   0 2581136 280592  12912 S  0.0 14.9   0:00.00 java                                                                                                         
26710 root      20   0 2581136 280592  12912 S  0.0 14.9   0:00.01 java                                                                                                         
26713 root      20   0 2581136 280592  12912 S  0.0 14.9   0:00.00 java    

然后在 jstack 中找到相应的堆栈信息jstack pid |grep 'nid' -C5

[root@VM_0_7_centos mblog]# jstack 26550 |grep '0x67bf' -C5 
    - locked <0x00000000ecda6770> (a java.lang.ref.Reference$Lock)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"VM Thread" os_prio=0 tid=0x00007fb7f8095000 nid=0x67b8 runnable 

"VM Periodic Task Thread" os_prio=0 tid=0x00007fb7f80de000 nid=0x67bf waiting on condition 

JNI global references: 1842

已经找到了 nid 为 0x67b6 的堆栈信息,接着只要仔细分析就行。 当然更常见的是对整个 jstack 文件进行分析,通常会比较关注 WAITING 和 TIMED_WAITING 的部分,BLOCKED 就不用说了。 可以使用命令cat jstack.log | grep "java.lang.Thread.State" | sort -nr | uniq -c来对 jstack 的状态有一个整体的把握,如果 WAITING 之类的特别多,那么多半是有问题啦。

2)频繁GC

是会使用 jstack 来分析问题,但有时候可以先确定下 gc 是不是太频繁,使用jstat -gc pid 1000命令来对 gc 分代变化情况进行观察,1000 表示采样间隔(ms),S0C/S1C、S0U/S1U、EC/EU、OC/OU、MC/MU 分别代表两个 Survivor 区、Eden 区、老年代、元数据区的容量和使用量。YGC/YGT、FGC/FGCT、GCT 则代表 YoungGc、FullGc 的耗时和次数以及总耗时。如果看到 gc 比较频繁,再针对 gc 方面做进一步分析

[root@VM_0_7_centos mblog]# jstat -gc 26550  1000
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT   
3008.0 3008.0  0.0   1902.1 24384.0   6904.6   60608.0    38192.6   83496.0 79692.4 11304.0 10656.9    259    1.081   5      0.365    1.446
3008.0 3008.0  0.0   1902.1 24384.0   6904.6   60608.0    38192.6   83496.0 79692.4 11304.0 10656.9    259    1.081   5      0.365    1.446
3008.0 3008.0  0.0   1902.1 24384.0   6904.6   60608.0    38192.6   83496.0 79692.4 11304.0 10656.9    259    1.081   5      0.365    1.446
3008.0 3008.0  0.0   1902.1 24384.0   6904.6   60608.0    38192.6   83496.0 79692.4 11304.0 10656.9    259    1.081   5      0.365    1.446
3008.0 3008.0  0.0   1902.1 24384.0   6904.6   60608.0    38192.6   83496.0 79692.4 11304.0 10656.9    259    1.081   5      0.365    1.446
3008.0 3008.0  0.0   1902.1 24384.0   7968.7   60608.0    38192.6   83496.0 79692.4 11304.0 10656.9    259    1.081   5      0.365    1.446
3008.0 3008.0  0.0   1902.1 24384.0   7968.7   60608.0    38192.6   83496.0 79692.4 11304.0 10656.9    259    1.081   5      0.365    1.446
3)上下文切换

使用vmstat命令来进行查看

[root@VM_0_7_centos mblog]# vmstat 26550
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 3  0      0  80832   7996 356880    0    0    17    37    2    2  1  1 99  0  0

cs(context switch)一列则代表了上下文切换的次数。 如果希望对特定的 pid 进行监控那么可以使用 pidstat -w pid命令,cswch 和 nvcswch 表示自愿及非自愿切换。

[root@VM_0_7_centos mblog]# pidstat  -w 26550
Linux 3.10.0-957.21.3.el7.x86_64 (VM_0_7_centos)     05/15/2020  _x86_64_    (1 CPU)

03:06:22 PM   UID       PID   cswch/s nvcswch/s  Command
03:07:04 PM     0         1      0.48      0.02  systemd
03:07:04 PM     0         3      1.84      0.00  ksoftirqd/0
03:07:04 PM     0         9     22.27      0.00  rcu_sched
03:07:04 PM     0        11      0.26      0.00  watchdog/0
03:07:04 PM     0        30      0.10      0.00  kswapd0
03:07:04 PM     0        99      0.24      0.00  kauditd
03:07:04 PM     0      1190      1.65      0.00  kworker/0:1H
03:07:04 PM     0      1281      0.60      0.00  jbd2/vda1-8
03:07:04 PM     0      1372      0.19      0.00  systemd-journal
03:07:04 PM   998      2534      0.07      0.00  lsmd
03:07:04 PM     0      2541      0.43      0.00  systemd-logind
03:07:04 PM    81      2542      0.81      0.00  dbus-daemon
03:07:04 PM     0      4631      0.05      0.00  sgagent
03:07:04 PM     0      6807      0.05      0.00  sshd
03:07:04 PM    38      7063      0.07      0.00  ntpd
03:07:04 PM     0      7311      0.05      0.00  crond
03:07:04 PM     0      8426      0.22      0.00  auditd
03:07:04 PM     0      9731      0.53      0.00  kworker/0:1
03:07:04 PM     0     12026      0.86      0.00  YDService
03:07:04 PM     0     12050      0.02      0.00  pidstat

2. 磁盘

直接使用df -hl来查看文件系统状态

[root@VM_0_7_centos mblog]# df  -hl
Filesystem      Size  Used Avail Use% Mounted on
devtmpfs        909M     0  909M   0% /dev
tmpfs           920M   32K  920M   1% /dev/shm
tmpfs           920M  988K  919M   1% /run
tmpfs           920M     0  920M   0% /sys/fs/cgroup
/dev/vda1        50G   11G   37G  22% /
tmpfs           184M     0  184M   0% /run/user/0
overlay          50G   11G   37G  22% /var/lib/docker/overlay2/6d3ac4731796a1e5eb0408384051439ef0e04fc1b0da8352f962ac0de5f79961/merged
shm              64M     0   64M   0% /var/lib/docker/containers/9a8b43b48d28261f7ca6a42269617b3360928c6f98e16cc0e0e2734f3aabbf09/mounts/shm
overlay          50G   11G   37G  22% /var/lib/docker/overlay2/356fa3e9b02cdb6249d63ee71f310083145f4e46b755b48f4c6b9e3312f5ed5b/merged
overlay          50G   11G   37G  22% /var/lib/docker/overlay2/d116b2316f31442a3b016bdfc948c21abb34e2c5334e6fca3f2b5300f2557afc/merged
overlay          50G   11G   37G  22% /var/lib/docker/overlay2/489a913865b84fd119290baef3f27fa84a4539172e5ca3d553553d19a1140b30/merged
shm              64M     0   64M   0% /var/lib/docker/containers/0aa0b495b88586620f95924fc2ec2ddf6c789f6c79b119b402851e17b839e656/mounts/shm
shm              64M     0   64M   0% /var/lib/docker/containers/ee708e3216dba7cd6284b0fef0115fcb0adb1e550b7357485af1fcdfc9942d1e/mounts/shm
shm              64M     0   64M   0% /var/lib/docker/containers/b844cd76ce1dc12aa6396fd7ef105d30c10c1a4cbc2559a37b87f650ea8a2a83/mounts/shm
overlay          50G   11G   37G  22% /var/lib/docker/overlay2/1c3f63084bb0845336968aef1b4179bfe0e7b3dd9904867a5b3a5805708312e1/merged
shm              64M     0   64M   0% /var/lib/docker/containers/1877103ed43f6dea45b98ad3f763d2d562b80e06125fa7b10350f7e42a16f408/mounts/shm
overlay          50G   11G   37G  22% /var/lib/docker/overlay2/3dd57c5b2119b45901d6b022e7b38d9f45c3fb6472c983a5d9cb598943eb7a99/merged
overlay          50G   11G   37G  22% /var/lib/docker/overlay2/64411f1ae1a535e4568d00e9de041de2a6c09f896f2cf666f752b684e84da35f/merged
shm              64M     0   64M   0% /var/lib/docker/containers/1e055f70660dbe8d3060ac34ec26347b310f857d61cadcc6cc3b5973023379a6/mounts/shm
shm              64M     0   64M   0% /var/lib/docker/containers/f555d33b406a2168ce91536bad302179d3cb8e621d4aa8616c4c08baf235d3f3/mounts/shm

磁盘问题还是性能上的问题,通过 iostat -d -k -x来进行分析

[root@VM_0_7_centos mblog]# iostat -d -k -x
Linux 3.10.0-957.21.3.el7.x86_64 (VM_0_7_centos)     05/15/2020  _x86_64_    (1 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
vda               0.01     2.72    0.41    4.86    16.90    36.95    20.44     0.03    7.13   23.12    5.79   0.33   0.18
scd0              0.00     0.00    0.00    0.00     0.00     0.00    67.86     0.00    0.44    0.44    0.00   0.33   0.00

另外还需要知道是哪个进程在进行读写,或者用 iotop 命令来进行定位文件读写的来源。

[root@VM_0_7_centos mblog]# iotop 

Total DISK READ :       0.00 B/s | Total DISK WRITE :       0.00 B/s
Actual DISK READ:       0.00 B/s | Actual DISK WRITE:       0.00 B/s
  TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN     IO>    COMMAND                                                                                                           
    1 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % systemd --system --deserialize 22
    2 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kthreadd]
    3 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [ksoftirqd/0]
    5 be/0 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kworker/0:0H]
    7 rt/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [migration/0]
    8 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [rcu_bh]
    9 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [rcu_sched]
   10 be/0 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [lru-add-drain]
   11 rt/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [watchdog/0]
   13 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kdevtmpfs]
   14 be/0 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [netns]
   15 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [khungtaskd]
   16 be/0 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [writeback]
   17 be/0 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kintegrityd]
   18 be/0 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [bioset]
   19 be/0 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [bioset]
   20 be/0 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [bioset]

不过这边拿到的是 tid,要转换成 pid,可以通过 readlink 来找到 pid

readlink -f /proc/*/task/tid/../..

找到 pid 之后就可以看这个进程具体的读写情况cat /proc/pid/io

[root@VM_0_7_centos mblog]# readlink -f /proc/1/
/proc/1
[root@VM_0_7_centos mblog]# cat /proc/1/io 
rchar: 322196383282
wchar: 45154675778
syscr: 400078452
syscw: 97216260
read_bytes: 156394731008
write_bytes: 39740551168
cancelled_write_bytes: 1688125440

还可以通过 lsof 命令来确定具体的文件读写情况lsof -p pid

[root@VM_0_7_centos mblog]# lsof -p 1
COMMAND PID USER   FD      TYPE             DEVICE SIZE/OFF       NODE NAME
systemd   1 root  cwd       DIR              253,1     4096          2 /
systemd   1 root  rtd       DIR              253,1     4096          2 /
systemd   1 root  txt       REG              253,1  1624512      12010 /usr/lib/systemd/systemd
systemd   1 root  mem       REG              253,1    20064       4637 /usr/lib64/libuuid.so.1.3.0
systemd   1 root  mem       REG              253,1   265600      17823 /usr/lib64/libblkid.so.1.1.0
systemd   1 root  mem       REG              253,1    90248       4230 /usr/lib64/libz.so.1.2.7
systemd   1 root  mem       REG              253,1   157424       4993 /usr/lib64/liblzma.so.5.2.2
systemd   1 root  mem       REG              253,1    23968       5358 /usr/lib64/libcap-ng.so.0.0.0
systemd   1 root  mem       REG              253,1    19896       4329 /usr/lib64/libattr.so.1.1.0
systemd   1 root  mem       REG              253,1    19288       3928 /usr/lib64/libdl-2.17.so
systemd   1 root  mem       REG              253,1   402384       4410 /usr/lib64/libpcre.so.1.2.0
systemd   1 root  mem       REG              253,1  2156160       3908 /usr/lib64/libc-2.17.so
systemd   1 root  mem       REG              253,1   142232       3935 /usr/lib64/libpthread-2.17.so
systemd   1 root  mem       REG              253,1    88776      11356 /usr/lib64/libgcc_s-4.8.5-20150702.so.1
systemd   1 root  mem       REG              253,1    43776      17769 /usr/lib64/librt-2.17.so
systemd   1 root  mem       REG              253,1   277808       8396 /usr/lib64/libmount.so.1.1.0
systemd   1 root  mem       REG              253,1    91800      12919 /usr/lib64/libkmod.so.2.2.10
systemd   1 root  mem       REG              253,1   127184       5361 /usr/lib64/libaudit.so.1.0.0
systemd   1 root  mem       REG              253,1    61672       8507 /usr/lib64/libpam.so.0.83.1

3. 内存

内存问题排查起来相对比 CPU 麻烦一些,场景也比较多。主要包括 OOM、GC 问题和堆外内存。一般来讲,会先用free命令先来检查一发内存的各种情况。

[root@VM_0_7_centos mblog]# free
              total        used        free      shared  buff/cache   available
Mem:        1882216     1437360       82932       15452      361924      266016
Swap: 
1)堆内内存

内存问题大多还都是堆内内存问题。表象上主要分为 OOM 和 Stack Overflo。

2)OOM

JVM中的内存不足,OOM 大致可以分为以下几种:

Exception in thread "main" java.lang.OutOfMemoryError: unable to create new native thread

这个意思是没有足够的内存空间给线程分配 Java 栈,基本上还是线程池代码写的有问题,比如说忘记 shutdown,所以说应该首先从代码层面来寻找问题, 使用 jstack 或者 jmap。如果一切都正常,JVM 方面可以通过指定Xss来减少单个 thread stack 的大小。 另外也可以在系统层面,可以通过修改/etc/security/limits.confnofile 和 nproc 来增大系统对线程的限制,AES除外和severless除外

Exception in thread "main" java.lang.OutOfMemoryError: Java heap space

这个意思是堆的内存占用已经达到-Xmx 设置的最大值,应该是最常见的 OOM 错误了。解决思路仍然是先应该在代码中找,怀疑存在内存泄漏,通过 jstack 和 jmap 去定位问题。如果说一切都正常,才需要通过调整Xmx的值来扩大内存。

Caused by: java.lang.OutOfMemoryError: Meta space

这个意思是元数据区的内存占用已经达到XX:MaxMetaspaceSize设置的最大值,排查思路和上面的一致,参数方面可以通过XX:MaxPermSize来进行调整(这里就不说 1.8 以前的永久代了,1.8之后是元数据区)。

Stack Overflow

栈内存溢出

Exception in thread "main" java.lang.StackOverflowError

表示线程栈需要的内存大于 Xss 值,同样也是先进行排查,参数方面通过Xss来调整,但调整的太大可能又会引起 OOM。

3)使用JMAP 定位代码内存泄漏

上述关于 OOM 和 Stack Overflo 的代码排查方面,一般使用 JMAP jmap -dump:format=b,file=filename pid来导出 dump 文件clear

[root@VM_0_7_centos mblog]# jmap -dump:format=b,file=filename 26550
Dumping heap to /usr/local/mblog/filename ...
File exists
[root@VM_0_7_centos mblog]# 
filename 

通过 mat(Eclipse Memory Analysis Tools;IDEA我还没找到合适的工具)导入 dump 文件进行分析,内存泄漏问题一般直接选 Leak Suspects 即可,mat 给出了内存泄漏的建议。另外也可以选择 Top Consumers 来查看最大对象报告(知识盲点,只听说过,有空研究)和线程相关的问题可以选择 thread overview 进行分析。 日常开发中,代码产生内存泄漏是比较常见的事,并且比较隐蔽,需要开发者更加关注细节。比如说每次请求都 new 对象,导致大量重复创建对象;进行文件流操作但未正确关闭;手动不当触发 gc;ByteBuffer 缓存分配不合理等都会造成代码 OOM。另一方面,可以在启动参数中指定-XX:+HeapDumpOnOutOfMemoryError来保存 OOM 时的 dump 文件。

4)gc 问题和线程

gc 问题除了影响 CPU 也会影响内存,排查思路也是一致的。一般先使用 jstat 来查看分代变化情况,比如 youngGC 或者 fullGC 次数是不是太多呀;EU、OU 等指标增长是不是异常呀等。线程的话太多而且不被及时 gc 也会引发 oom,大部分就是之前说的unable to create new native thread。除了 jstack 细细分析 dump 文件外,一般先会看下总体线程,通过pstreee -p pid |wc -l。

[root@VM_0_7_centos mblog]# pstree -p 26550 |wc -l
52
5)堆外内存

如果碰到堆外内存溢出,那可真是惨。首先堆外内存溢出表现就是物理常驻内存增长快,报错的话视使用方式都不确定, 如果由于使用 Netty 导致的,那错误日志里可能会出现OutOfDirectMemoryError错误,注意一下是否是线程阻塞了 如果直接是 DirectByteBuffer,那会报OutOfMemoryError: Direct buffer memory。 堆外内存溢出往往是和 NIO 的使用相关,一般先通过 pmap 来查看下进程占用的内存情况pmap -x pid | sort -rn -k3 | head -30, 这段意思是查看对应 pid 倒序前 30 大的内存段。这边可以再一段时间后再跑一次命令看看内存增长情况,或者和正常机器比较可疑的内存段在哪里。

[root@VM_0_7_centos mblog]# pmap -x 26550 | sort -rn -k3 | head -30
total kB         2588336  292516  285368
00000000ecd50000   60608   49504   49504 rw---   [ anon ]
00007fb7c8000000   37012   37004   37004 rw---   [ anon ]
00000000e3400000   30400   28192   28192 rw---   [ anon ]
00007fb7cc000000   24560   24320   24320 rw---   [ anon ]
00007fb7f8000000   23724   23420   23420 rw---   [ anon ]
00007fb7e9000000   20992   20388   20388 rwx--   [ anon ]
0000000100000000   11304   11228   11228 rw---   [ anon ]
00007fb7fe52a000    9028    9012    9012 rw---   [ anon ]
00007fb7fffcc000   13216    6108       0 r-x-- libjvm.so
00007fb7dc000000    4036    4028    4028 rw---   [ anon ]
00007fb7c0000000   11164    3028    3028 rw---   [ anon ]
00007fb7e4000000    2444    2444    2444 rw---   [ anon ]
00007fb7c70ae000    3064    2164    2164 rw---   [ anon ]
00007fb7e80ec000    3064    2140    2140 rw---   [ anon ]
00007fb7d55d8000    3064    2140    2140 rw---   [ anon ]
00007fb7c68aa000    3064    2112    2112 rw---   [ anon ]
00007fb7fd7d9000    2048    2048    2048 rw---   [ anon ]
00007fb7fd5d9000    2048    2048    2048 rw---   [ anon ]
00007fb7fca8f000    2048    2048    2048 rw---   [ anon ]
00007fb7fc88f000    2048    2048    2048 rw---   [ anon ]
00007fb7fc68f000    2048    2048    2048 rw---   [ anon ]
00007fb7fc48f000    2048    2048    2048 rw---   [ anon ]
00007fb7fc28f000    2048    2048    2048 rw---   [ anon ]
00007fb7fc08f000    2048    2048    2048 rw---   [ anon ]
00007fb7e8e00000    2048    2048    2048 rw---   [ anon ]
00007fb7e8c00000    2048    2048    2048 rw---   [ anon ]
00007fb7e8a00000    2048    2048    2048 rw---   [ anon ]
00007fb7d58d6000    2048    2048    2048 rw---   [ anon ]
00007fb7d53d5000    2048    2048    2048 rw---   [ anon ]

4. GC 问题

堆内内存泄漏总是和 GC 异常相伴。不过 GC 问题不只是和内存问题相关,还有可能引起 CPU 负载、网络问题等系列并发症,只是相对来说和内存联系紧密些,所以在此单独总结一下 GC 相关问题。在 CPU 章介绍了使用 jstat 来获取当前 GC 分代变化信息。而更多时候,是通过 GC 日志来排查问题的,在启动参数中加上-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps来开启 GC 日志。 常见的 Young GC、Full GC 日志含义在此就不做赘述了。 针对 gc 日志,就能大致推断出 youngGC 与 fullGC 是否过于频繁或者耗时过长。对 G1 垃圾收集器来做分析,建议使用 G1-XX:+UseG1GC。

1)youngGC 过频繁

youngGC 频繁一般是短周期小对象较多,先考虑是不是 Eden 区/新生代设置的太小了,看能否通过调整-Xmn、-XX:SurvivorRatio 等参数设置来解决问题。如果参数正常,但是 young gc 频率还是太高,就需要使用 Jmap 和 MAT 对 dump 文件进行进一步排查了。

2)youngGC 耗时过长

耗时过长问题就要看 GC 日志里耗时耗在哪一块了。以 G1 日志为例,可以关注 Root Scanning、Object Copy、Ref Proc 等阶段。Ref Proc 耗时长,就要注意引用相关的对象。Root Scanning 耗时长,就要注意线程数、跨代引用。 Object Copy 则需要关注对象生存周期。而且耗时分析它需要横向比较,就是和其他项目或者正常时间段的耗时比较。比如说图中的 Root Scanning 和正常时间段比增长较多,那就是起的线程太多了。

3)触发 fullGC

G1 中更多的还是 mixedGC,但 mixedGC 可以和 youngGC 思路一样去排查。触发 fullGC 了一般都会有问题,G1 会退化使用 Serial 收集器来完成垃圾的清理工作,暂停时长达到秒级别,可以说是半跪了。 fullGC 的原因可能包括以下这些,以及参数调整方面的一些思路: 并发阶段失败:在并发标记阶段,MixGC 之前老年代就被填满了,那么这时候 G1 就会放弃标记周期。这种情况,可能就需要增加堆大小,或者调整并发标记线程数-XX:ConcGCThreads。 晋升失败:在 GC 的时候没有足够的内存供存活/晋升对象使用,所以触发了 Full GC。这时候可以通过-XX:G1ReservePercent来增加预留内存百分比,减少-XX:InitiatingHeapOccupancyPercent来提前启动标记,-XX:ConcGCThreads来增加标记线程数也是可以的。 大对象分配失败:大对象找不到合适的 region 空间进行分配,就会进行 fullGC,这种情况下可以增大内存或者增大-XX:G1HeapRegionSize。 程序主动执行 System.gc():不要随便写就对了。

作者:我超有耐心的

源链接:https://juejin.cn/post/6844904159913705485

格式整理:IT运维技术圈

本文参与 腾讯云自媒体分享计划,分享自微信公众号。
原始发表:2022-10-13,如有侵权请联系 cloudcommunity@tencent.com 删除

本文分享自 IT运维技术圈 微信公众号,前往查看

如有侵权,请联系 cloudcommunity@tencent.com 删除。

本文参与 腾讯云自媒体分享计划  ,欢迎热爱写作的你一起参与!

评论
登录后参与评论
0 条评论
热度
最新
推荐阅读
目录
  • 1. CPU
    • 1)使用 jstack 分析 CPU 问题
      • 2)频繁GC
        • 3)上下文切换
        • 2. 磁盘
        • 3. 内存
          • 1)堆内内存
            • 2)OOM
              • 3)使用JMAP 定位代码内存泄漏
                • 4)gc 问题和线程
                  • 5)堆外内存
                  • 4. GC 问题
                    • 1)youngGC 过频繁
                      • 2)youngGC 耗时过长
                        • 3)触发 fullGC
                        相关产品与服务
                        容器服务
                        腾讯云容器服务(Tencent Kubernetes Engine, TKE)基于原生 kubernetes 提供以容器为核心的、高度可扩展的高性能容器管理服务,覆盖 Serverless、边缘计算、分布式云等多种业务部署场景,业内首创单个集群兼容多种计算节点的容器资源管理模式。同时产品作为云原生 Finops 领先布道者,主导开源项目Crane,全面助力客户实现资源优化、成本控制。
                        领券
                        问题归档专栏文章快讯文章归档关键词归档开发者手册归档开发者手册 Section 归档