记一次内存溢出排查，JVM调优-jmap,jstat,jstack

最新推荐文章于 2023-08-21 09:37:26 发布

忄季

最新推荐文章于 2023-08-21 09:37:26 发布

阅读量532

点赞数

文章标签： jvm jdk

本文链接：https://blog.csdn.net/qq_22804125/article/details/110632308

版权

本次JVM调优，是因为计算管理引擎在跑数计算时，突然报内存溢出，目前的数据量只有100W,之前200W跑数是正常的。

错误日志：

2020-12-03 08:47:15 78 [Thread-4] INFO  org.springframework.context.annotation.AnnotationConfigApplicationContext -Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@224edc67: startup date [Thu Dec 03 08:25:33 CST 2020]; root of context hierarchy
2020-12-03 08:47:15 79 [Thread-4] INFO  com.vprisk.engine.service.ContextHolder -Application Context Started
2020-12-03 08:47:15 89 [AlmEngineSystem-akka.actor.default-dispatcher-15] ERROR akka.actor.ActorSystemImpl -Uncaught error from thread [AlmEngineSystem-akka.actor.default-dispatcher-21] shutting down JVM since 'akka.jvm-exit-on-fatal-error' is enabled
java.lang.OutOfMemoryError: Java heap space
	at java.util.Arrays.copyOf(Arrays.java:3181) ~[na:1.8.0_211]
	at java.util.ArrayList.grow(ArrayList.java:265) ~[na:1.8.0_211]
	at java.util.ArrayList.ensureExplicitCapacity(ArrayList.java:239) ~[na:1.8.0_211]
	at java.util.ArrayList.ensureCapacityInternal(ArrayList.java:231) ~[na:1.8.0_211]
	at java.util.ArrayList.add(ArrayList.java:462) ~[na:1.8.0_211]
	at com.vprisk.quantlib.time.Schedule.<init>(Schedule.java:77) ~[app-vpalm-quantlib-4.4.0.jar:na]
	at com.vprisk.quantlib.time.Schedule.<init>(Schedule.java:28) ~[app-vpalm-quantlib-4.4.0.jar:na]
	at com.vprisk.quantlib.processer.assetliability.ProcesserOfFixedRateInstrument.prepare(ProcesserOfFixedRateInstrument.java:626) ~[app-vpalm-quantlib-4.4.0.jar:na]
	at com.vprisk.quantlib.processer.assetliability.ProcesserOfFixedRateInstrument.process(ProcesserOfFixedRateInstrument.java:532) ~[app-vpalm-quantlib-4.4.0.jar:na]
	at com.vprisk.quantlib.processer.ProcesserFactory.processLeg(ProcesserFactory.java:53) ~[app-vpalm-quantlib-4.4.0.jar:na]
	at com.vprisk.quantlib.Calculator.calculate(Calculator.java:20) ~[app-vpalm-quantlib-4.4.0.jar:na]
	at com.vprisk.prophet.engine.alm.ProcessProductCurrent.calcInstruments(ProcessProductCurrent.java:180) ~[app-vpalm-engine-service-4.4.0.jar:na]
	at com.vprisk.prophet.engine.alm.ProcessProductCurrent.processCurrentPositions(ProcessProductCurrent.java:125) ~[app-vpalm-engine-service-4.4.0.jar:na]
	at com.vprisk.prophet.engine.alm.ProcessProductCurrent.execute(ProcessProductCurrent.java:119) ~[app-vpalm-engine-service-4.4.0.jar:na]
	at com.vprisk.alm.engine.actor.AlmEngineActor.executeAlm(AlmEngineActor.java:199) ~[app-vpalm-engine-service-4.4.0.jar:na]
	at com.vprisk.alm.engine.actor.AlmEngineActor.onReceive(AlmEngineActor.java:106) ~[app-vpalm-engine-service-4.4.0.jar:na]
	at akka.actor.UntypedActor$$anonfun$receive$1.applyOrElse(UntypedActor.scala:167) ~[akka-actor_2.10-2.3.9.jar:na]
	at akka.actor.Actor$class.aroundReceive(Actor.scala:465) ~[akka-actor_2.10-2.3.9.jar:na]
	at akka.actor.UntypedActor.aroundReceive(UntypedActor.scala:97) ~[akka-actor_2.10-2.3.9.jar:na]
	at akka.actor.ActorCell.receiveMessage(ActorCell.scala:516) [akka-actor_2.10-2.3.9.jar:na]
	at akka.actor.ActorCell.invoke(ActorCell.scala:487) [akka-actor_2.10-2.3.9.jar:na]
	at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:254) [akka-actor_2.10-2.3.9.jar:na]
	at akka.dispatch.Mailbox.run(Mailbox.scala:221) [akka-actor_2.10-2.3.9.jar:na]
	at akka.dispatch.Mailbox.exec(Mailbox.scala:231) [akka-actor_2.10-2.3.9.jar:na]
	at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260) [scala-library-2.10.4.jar:na]
	at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339) [scala-library-2.10.4.jar:na]
	at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979) [scala-library-2.10.4.jar:na]
	at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107) [scala-library-2.10.4.jar:na]
2020-12-03 08:47:15 92 [Thread-4] INFO  org.springframework.cache.ehcache.EhCacheManagerFactoryBean -Shutting down EhCache CacheManager
2020-12-03 08:47:15 92 [Thread-4] WARN  org.springframework.beans.factory.support.DisposableBeanAdapter -Invocation of destroy method 'close' failed on bean with name 'sqlSession': java.lang.UnsupportedOperationException: Manual close is not allowed over a Spring managed SqlSession

1.内存调整
根据报错 “Java heap space” 首先怀疑是堆内存不够，通过参数调整内存资源。这里将内存加到14G

JAVA_OPTS="-Xms14336M  -Xmx14336M -XX:PermSize=2048M -XX:MaxPermSize=2048M -XX:SurvivorRatio=6 -XX:MaxTenuringThreshold=15"

堆大小设置参数说明：

java -Xmx14336M -Xms14336M -Xmn2g –Xss128k

-Xmx14336M：设置JVM最大可用内存为14336M。

-Xms14336M：设置JVM促使内存为14336M。此值可以设置与-Xmx相同，以避免每次垃圾回收完成后JVM重新分配内存。

-Xmn2g：设置年轻代大小为2G。整个堆大小=年轻代大小 + 年老代大小 + 持久代大小。持久代一般固定大小为64m，所以增大年轻代后，将会减小年老代大小。此值对系统性能影响较大，Sun官方推荐配置为整个堆的3/8。

-Xss128k：设置每个线程的堆栈大小。JDK5.0以后每个线程堆栈大小为1M，以前每个线程堆栈大小为256K。更具应用的线程所需内存大小进行调整。在相同物理内存下，减小这个值能生成更多的线程。但是操作系统对一个进程内的线程数还是有限制的，不能无限生成，经验值在3000~5000左右。

java -Xmx14336M -Xms14336M -Xss128k -XX:NewRatio=4 -XX:SurvivorRatio=4 -XX:MaxPermSize=16m -XX:MaxTenuringThreshold=5

-XX:NewRatio=4:设置年轻代（包括Eden和两个Survivor区）与年老代的比值（除去持久代），默认为2。设置为4，则年轻代与年老代所占比值为1：4，年轻代占整个堆栈的1/5

-XX:SurvivorRatio=4：设置年轻代中Eden区与每一个Survivor区的比值。设置为4，则两个Survivor区与一个Eden区的比值为2:4，一个Survivor区占整个年轻代的1/6

-XX:MaxPermSize=16m:设置持久代大小为16m。

-XX:MaxTenuringThreshold=0：在可自动调整对象晋升老年代年龄阈值的GC中，该参数用于设置上述年龄阈值的最大值，参数值最大为15，Parallel Scavenge中默认值为15，CMS中默认值为6，G1中默认值为15。如果设置为0的话，则年轻代对象不经过Survivor区，直接进入年老代。对于年老代比较多的应用，可以提高效率。如果将此值设置为一个较大值，则年轻代对象会在Survivor区进行多次复制，这样可以增加对象再年轻代的存活时间，增加在年轻代即被回收的概率。

更多详细说明可参考：https://www.cnblogs.com/andy-zhou/p/5327288.html

2.内存使用监控
增加了内存后还是报溢出，通过以下命令进行内存监控。

top
首先我们可以使用top命令查看系统CPU的占用情况，如下是系统CPU较高的一个示例：
这里11603 刚好是我们运行的服务，如果不确定哪个服务占用率高时，可以先通过top命令查看当前占用最多的进程 PID。

[vp@localhost ~]$ top
top - 10:24:21 up 282 days, 17:28, 14 users,  load average: 1.99, 1.85, 1.83
Tasks: 345 total,   1 running, 343 sleeping,   1 stopped,   0 zombie
%Cpu(s):  0.1 us,  0.0 sy,  0.0 ni, 99.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 32946688 total, 20490544 free,  9668696 used,  2787448 buff/cache
KiB Swap:  4194300 total,  4180460 free,    13840 used. 22594404 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                                       
11603 vp        20   0 19.548g 5.217g  17568 S   1300 16.6  47:48.58 java                                                                                                          
13249 vp        20   0 16.312g 1.730g  19844 S   1.0  5.5   8:26.76 java                                                                                                          
    1 root      20   0  216132  30480   2336 S   0.0  0.1  10:08.04 systemd                                                                                                       
    2 root      20   0       0      0      0 S   0.0  0.0   0:02.70 kthreadd                                                                                                      
    3 root      20   0       0      0      0 S   0.0  0.0   0:01.68 ksoftirqd/0                                                                                                   
    7 root      rt   0       0      0      0 S   0.0  0.0   0:02.68 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   0:00.00 rcuob/0

top -Hp 11603
查看该进行下的线程，找到CPU占用率高的线程

[vp@localhost ~]$ top -Hp 11603
top - 10:26:40 up 282 days, 17:30, 14 users,  load average: 2.00, 1.91, 1.85
Threads:  57 total,   0 running,  57 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.1 us,  0.1 sy,  0.0 ni, 99.9 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 32946688 total, 20482212 free,  9677060 used,  2787416 buff/cache
KiB Swap:  4194300 total,  4180460 free,    13840 used. 22586072 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND                                                                                                        
13244 vp        20   0 19.548g 5.217g  17568 S  99.7 16.6  11:40.31 java                                                                                                           
13227 vp        20   0 19.548g 5.217g  17568 S  99.7 16.6   2:03.16 java                                                                                                           
13194 vp        20   0 19.548g 5.217g  17568 S  99.0 16.6   0:00.00 java                                                                                                           
13195 vp        20   0 19.548g 5.217g  17568 S  99.0 16.6   0:02.59 java                                                                                                           
13196 vp        20   0 19.548g 5.217g  17568 S  99.0 16.6   0:00.79 java                                                                                                           
13197 vp        20   0 19.548g 5.217g  17568 S  99.0 16.6   0:00.68 java                                                                                                           
13198 vp        20   0 19.548g 5.217g  17568 S  99.0 16.6   0:00.76 java                                                                                                           
13199 vp        20   0 19.548g 5.217g  17568 S  99.0 16.6   0:00.76 java                                                                                                           
13200 vp        20   0 19.548g 5.217g  17568 S  99.0 16.6   0:00.74 java                                                                                                           
13201 vp        20   0 19.548g 5.217g  17568 S  99.0 16.6   0:00.73 java

jstat

jstat命令可以查看堆内存各部分的使用量，以及加载类的数量。命令的格式如下：

 jstat [-命令选项] [vmid] [间隔时间/毫秒] [查询次数]

1.类加载统计

 jstat -class pid

2.编译统计

 jstat -compiler pid

3.垃圾回收统计

 jstat -gc pid

4.堆内存统计

jstat -gccapacity pid

5.新生代垃圾回收统计

jstat -gcnew pid

6.新生代内存统计

jstat -gcnewcapacity  pid

7.老年代垃圾回收统计

在这里插入代码片

8.老年代内存统计

jstat -gcoldcapacity PID

9.元数据空间统计

jstat -gcmetacapacity PID

10.总结垃圾回收统计

jstat -gcutil PID

更多说明，请参考：https://www.cnblogs.com/lizhonghua34/p/7307139.html

以下是本次监控使用情况：
注意：使用的jdk版本是jdk8.

[vp@localhost ~]$ jstat -gcutil 11603  10000
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
  0.00   0.00  66.88  91.65  95.41  91.81     18   17.404    15  370.763  388.167
  0.00 100.00 100.00   5.70  95.45  91.91     19   17.404    16  376.879  394.283
  0.00 100.00  28.01  55.58  95.37  92.68     21   22.705    16  376.879  399.583
100.00   0.00   0.00  80.52  95.37  92.68     22   25.635    17  376.879  402.514
100.00   0.00   0.00  80.52  95.37  92.68     22   25.635    17  376.879  402.514
  0.00  99.99   0.00  82.32  95.39  92.68     23   33.473    18  466.279  499.752
  0.00  99.99   0.00  82.32  95.39  92.68     23   33.473    18  466.279  499.752
  0.00   0.00  25.33  88.51  95.39  92.68     23   33.473    18  552.576  586.048
  0.00   0.00 100.00  88.51  95.39  92.68     23   33.473    19  552.576  586.048
  0.00   0.00 100.00  88.51  95.39  92.68     23   33.473    19  552.576  586.048
  0.00   0.00 100.00 100.00  95.39  92.68     23   33.473    20  656.183  689.655
  0.00   0.00 100.00 100.00  95.39  92.68     23   33.473    20  656.183  689.655
  0.00   0.00  96.49 100.00  95.43  92.68     23   33.473    21  800.797  834.269
  0.00   0.00  96.49 100.00  95.43  92.68     23   33.473    21  800.797  834.269
  0.00   0.00  86.84 100.00  95.46  92.69     23   33.473    22  935.317  968.790
  0.00   0.00  86.84 100.00  95.46  92.69     23   33.473    22  935.317  968.790

说明：
S0：幸存1区当前使用比例
S1：幸存2区当前使用比例
E：伊甸园区使用比例
O：老年代使用比例
M：元数据区使用比例
CCS：压缩使用比例
YGC：年轻代垃圾回收次数
FGC：老年代垃圾回收次数
FGCT：老年代垃圾回收消耗时间
GCT：垃圾回收消耗总时间

jmap
jmap命令是一个可以输出所有内存中对象的工具；可以打印出某个java进程（使用pid）内存内的，所有对象的情况。

命令格式：

jmap [option] <pid>
    (to connect to running process) 连接到正在运行的进程

jmap [option] <executable <core>
    (to connect to a core file)     连接到核心文件

jmap [option] [server_id@]<remote server IP or hostname>
    (to connect to remote debug server) 连接到远程调试服务

参数说明：

>    pid:    目标进程的PID，进程编号，可以采用ps -ef | grep java 查看java进程的PID;
>    executable:     产生core dump的java可执行程序;
>    core:     将被打印信息的core dump文件;
>    remote-hostname-or-IP:     远程debug服务的主机名或ip;
>    server-id:     唯一id,假如一台主机上多个远程debug服务;

-dump:[live,]format=b,file= 使用hprof二进制形式,输出jvm的heap内容到文件=. live子选项是可选的，假如指定live选项,那么只输出活的对象到文件.

命令：jmap -dump:live,format=b,file=file.txt PID
-finalizerinfo 打印正等候回收的对象的信息

命令：jmap -finalizerinfo PID
-heap 打印heap的概要信息，GC使用的算法，heap（堆）的配置及JVM堆内存的使用情况

命令：jmap -heap PID
-histo[:live] 打印每个class的实例数目,内存占用,类全名信息. VM的内部类名字开头会加上前缀”*”. 如果live子参数加上后,只统计活的对象数量

命令：jmap -heap PID
-permstat 打印classload和jvm heap长久层的信息. 包含每个classloader的名字,活泼性,地址,父classloader和加载的class数量. 另外,内部String的数量和占用内存数也会打印出来

命令：jmap -permstat PID
-F 强迫.在pid没有相应的时候使用-dump或者-histo参数. 在这个模式下,live子参数无效.
-h | -help 打印辅助信息

-J 传递参数给jmap启动的jvm

以下是本次查看信息：
jmap -heap PID：查看当前线程堆内存分配情况

[vp@localhost logs]$ jmap -heap 11603
Attaching to process ID 11603, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.211-b12

using thread-local object allocation.
Parallel GC with 13 thread(s)  ## 13线程并行GC

Heap Configuration:    ##堆配置情况
   MinHeapFreeRatio         = 0                        #堆最小使用比例
   MaxHeapFreeRatio         = 100                      #堆最大使用比例
   MaxHeapSize              = 15032385536 (14336.0MB)  #堆最大空间
   NewSize                  = 5010620416 (4778.5MB)    #新生代初始化大小
   MaxNewSize               = 5010620416 (4778.5MB)    #新生代可使用最大容量大小
   OldSize                  = 10021765120 (9557.5MB)   #老生代大小
   NewRatio                 = 2                        #新生代比例
   SurvivorRatio            = 6                        #新生代与suvivor的占比
   MetaspaceSize            = 21807104 (20.796875MB)   #元数据空间初始大小
   CompressedClassSpaceSize = 1073741824 (1024.0MB)    #类指针压缩空间大小, 默认为1G
   PermSize                 = 134217728 (128.0MB)      #perm区 永久代大小
   MaxPermSize              = 134217728 (128.0MB)      #最大可分配perm区 也就是永久代大小
   MaxMetaspaceSize         = 17592186044415 MB        #元数据空间的最大值, 超过此值就会触发 GC溢出( JVM会动态地改变此值)
   G1HeapRegionSize         = 0 (0.0MB)                #区块的大小

Heap Usage:                                            #堆使用情况
PS Young Generation
Eden Space:#伊甸区
   capacity = 4940365824 (4711.5MB) #伊甸区容量
   used     = 1982208968 (1890.3817825317383MB)#伊甸区使用
   free     = 2958156856 (2821.1182174682617MB)#伊甸区剩余容量
   40.12271638611352% used  #伊甸区使用比例
From Space:                                            #survior1区
   capacity = 19398656 (18.5MB)
   used     = 19392656 (18.494277954101562MB)
   free     = 6000 (0.0057220458984375MB)
   99.96907002217061% used
To Space:                                              #survior2 区
   capacity = 35127296 (33.5MB)
   used     = 0 (0.0MB)
   free     = 35127296 (33.5MB)
   0.0% used
PS Old Generation                                      #老年代使用情况
   capacity = 10021765120 (9557.5MB)
   used     = 47347800 (45.154380798339844MB)
   free     = 9974417320 (9512.34561920166MB)
   0.47244970754213805% used
Perm Generation:                                       #永久代使用情况

   capacity = 134217728 (128.0MB)                      #perm区容量

   used     = 47303016 (45.111671447753906MB)          #perm区已使用容量

   free     = 86914712 (82.8883285522461MB)            #perm区剩余容量

   35.24349331855774% used                             #perm区使用比例

17020 interned Strings occupying 1440352 bytes.

jmap -histo PID

[vp@localhost app-cal-service]$ jmap -histo 11603|head -100

 num     #instances(实例 ) #bytes(字节大小)  class name
----------------------------------------------
   1:     264341164     6344187936  com.vprisk.quantlib.time.QuantDate
   2:         46627     1264148272  [Ljava.lang.Object;
   3:         12791      152887392  [I
   4:        403980       28221072  [C
   5:         14794       14411056  [B
   6:        361860        8684640  java.lang.String
   7:            20        3605336  [D
   8:         13768        1211584  java.lang.reflect.Method
   9:          3038        1166592  com.vprisk.alm.engine.dao.entity.CurrentPosition
  10:         31315        1002080  java.util.HashMap$Node
  11:          8753         978368  java.lang.Class

jstack

jstack主要用于生成java虚拟机当前时刻的线程快照。线程快照是当前java虚拟机内每一条线程正在执行的方法堆栈的集合，生成线程快照的主要目的是定位线程出现长时间停顿的原因，如线程间死锁、死循环、请求外部资源导致的长时间等待等。
参数解释一下

-F：当正常输出的请求不被响应时，强制输出线程堆栈。例如：
```
Unable to attach to 64-bit process The -F option can be used when the target process is not respond
```
-l：除堆栈外，会打印出额外的锁信息，在发生死锁时可以用jstack -l pid来观察锁持有情况

-m：如果调用到本地方法的话，可以显示C/C++的堆栈

更多说明，请参考：https://www.imooc.com/article/43986?block_id=tuijian_wz

可以看到， com.vprisk.quantlib.time.QuantDate，这个类的实例很多，而且根据打印的错误日志，溢出的位置有循环实例化QuantDate操作，最后根据数据排查，此处死循环。后对term数据进行判断。

在这里插入图片描述

参考博文：
https://www.cnblogs.com/andy-zhou/p/5327288.html
https://www.imooc.com/article/43986?block_id=tuijian_wz
https://www.cnblogs.com/lizhonghua34/p/7307139.html

忄季

关注

0
点赞
踩
1

收藏

觉得还不错? 一键收藏
0
评论
记一次内存溢出排查，JVM调优-jmap,jstat,jstack

错误日志：2020-12-03 08:47:15 78 [Thread-4] INFO org.springframework.context.annotation.AnnotationConfigApplicationContext -Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@224edc67: startup date [Thu Dec 03 08:25:33 CST 2020]
复制链接

扫一扫