CPU占用过高、FGC频繁问题

CPU占用过高、FGC频繁问题

1. top 表现如下

   PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                                                                                                    
   94569 root      20   0   11.1g   1.5g  16416 S  1868  2.5   4025:49 java 
   

2. top -H -p 94569 查看

    PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND                                                                                                                                                                     
    94635 root      20   0   11.1g   1.5g  16416 R 99.9  2.5 157:45.41 java                                                                                                                                                                        
    94644 root      20   0   11.1g   1.5g  16416 R 99.9  2.5 157:39.16 java                                                                                                                                                                        
    94627 root      20   0   11.1g   1.5g  16416 R 99.9  2.5 157:38.31 java                                                                                                                                                                        
    94629 root      20   0   11.1g   1.5g  16416 R 99.9  2.5 157:41.29 java  
   

3. printf “%x\n” pid 转16进制

     [root@rabbitmq1 CLEService]# printf “%x\n” pid
   	“171a9”
   

4. jstack pid| grep 16进制线程pid

    [root@rabbitmq1 zz]# jstack 94569 | grep '0x171a9' -C5
   
   "GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007f2440062800 nid=0x171a6 runnable 
   
   "GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007f2440064000 nid=0x171a7 runnable 
   
   **"GC task thread#4 (ParallelGC)" os_prio=0 tid=0x00007f2440066000 nid=0x171a9 runnable** 
   
   "GC task thread#5 (ParallelGC)" os_prio=0 tid=0x00007f2440068000 nid=0x171aa runnable 
   
   "GC task thread#6 (ParallelGC)" os_prio=0 tid=0x00007f244006a000 nid=0x171ab runnable
   

5. 看信息是GC线程，再分析GC相关

   [root@rabbitmq1 zz]# jstat -gcutil 94569 2000
     S0     S1     E      O      M     CCS    YGC     YGCT    **FGC**    FGCT     GCT   
     0.00   0.00 100.00  99.99  94.61  92.49  45461 1679.444  9431 10069.071 11748.515
     0.00   0.00 100.00  99.99  94.61  92.49  45461 1679.444  9432 10070.225 11749.668
     0.00   0.00 100.00 100.00  94.61  92.49  45461 1679.444  9434 10072.497 11751.941
     0.00   0.00 100.00  99.99  94.61  92.49  45461 1679.444  9436 10074.888 11754.332
   FGC次数一直在增加
   

6. 查看内存中对象数据
   [root@rabbitmq1 zz]# jmap -histo:live 94569 > 111.txt
   或者
   [root@rabbitmq1 zz]# jmap -histo:live 94569 | head -n 20

   num     #instances         #bytes  class name
   

   ---

     1:       6612342      171271640  [B
     2:       4988325      137461760  [C
     3:       4987368      119696832  java.lang.String
     **4:        978912      117469440  com.dahuatech.jt.entity.LibraryVehicle**
     5:       2905088      116203520  java.math.BigDecimal
     6:        550281       57229112  [[B
     7:       1947276       46734624  java.lang.Long
     8:        550259       17608288  com.mysql.cj.protocol.a.result.ByteArrayRow
     9:         20068        9178256  [Ljava.lang.Object;
    10:        550259        8804144  com.mysql.cj.protocol.a.MysqlTextValueDecoder
    11:         31506        2772528  java.lang.reflect.Method
    12:         76432        2445824  java.util.concurrent.ConcurrentHashMap$Node
    13:         18228        2012784  java.lang.Class
    14:         26489        1059560  java.util.LinkedHashMap$Entry
    15:         10718         920456  [Ljava.util.HashMap$Node;
    16:         25643         820576  java.util.HashMap$Node
    17:           352         782768  [Ljava.util.concurrent.ConcurrentHashMap$Node;
   

   LibraryVehicle是业务对象，需要找到生成该对象的代码块

7. 可以生成dump文件查看调用链
   jmap -dump:file=文件名.dump [pid]

8. 使用工具查看大对象调用链

    堆遍历器-最大对象
   Session:	HPROF snapshot "1 - 副本.hprof"
   Time of export:	2021年6月30日 星期三 下午05时02分59秒 CST
    	 
   当前对象集: 	5,776个类的25,068,289个对象
   选择步骤: 	See below
   分组: 	无
   
   对象	保留大小
   com.test.jt.global.GlobalCache (0x258f)	 300 MB (35 %)
    298 MB (99.4%) static vehiclesCacheList   java.util.ArrayList
    298 MB (99.4%) elementData   java.lang.Object[ ]
    另一个550,259实例，总保留大小为294 MB，最大单个保留大小为928 字节
    1,883 kB (0.6%) static illegalDriverFaceInfoMap   java.util.concurrent.ConcurrentHashMap
    1,883 kB (0.6%) table   java.util.concurrent.ConcurrentHashMap$Node[ ]
   

   看到GlobalCache 类中vehiclesCacheList 过大，排查代码发现，该缓存2s定时任务刷新一次，库中数据为50万，大对象直接放老年代，一直FGC

9. 修改为相关获取缓存逻辑从数据库中根据索引字段获取后，打包重启服务后正常