文章详情

短信预约-IT技能 免费直播动态提醒

请输入下面的图形验证码

提交验证

短信预约提醒成功

什么!服务器内存又双叒叕打满了!

2024-11-30 00:23

关注

1、问题背景

深夜,小菜同学突然被一阵急促的报警声吵醒,原来是手机收到了一连串关于容器内存使用率过高的报警信息。赶紧打开电脑查看服务器状态,发现容器内存使用率持续高达99%,下面把排查的过程和分析记录下来,以供大家参考。

2、问题现象

接收到系统的报警后,小菜同学立即检查了容器状态,观察到以下现象:

服务使用的配置如下:

主要启动参数:-Xms4g -Xmx4g -Xmn2g -XX:+UseG1GC -XX:G1HeapRegionSize=8m -XX:G1ReservePercent=15 -XX:InitiatingHeapOccupancyPercent=50

容器配置:4C5G

3、定位原因

虽然容器内存已经使用了99%,但是JVM堆使用率在经过一次Full GC后已经降到了50%之后,所以并没有立马重启服务,还是先来看看造成Full GC的原因。

鉴于堆使用率已经恢复正常,查看当时的内存快照意义不大,因此决定首先从观察到的现象入手。因为凌晨1点的时候系统的流量不会很大,所以大概率是因为定时任务造成了,先排查报警服务凌晨1点执行的定时任务。幸运的是调度平台当时只有一个定时任务在执行,立马查看对应的逻辑,发现了以下代码片段中潜在的问题(简化之后):

public void job() {
    // ... do business
    int pageSize = 500;
    while ( xxx ) {
        // 每次查询500个订单 
        List orderNoList = orderService.getOrderPage(pageSize);
        // 查询500个订单对应的账单
        List orderBills = billService.findByOrderNos(orderNoList);
        // ... do business
    }
    // ... do business
}

由于大部分订单包含12至24期账单,导致此处的orderBills在平均情况下含有数千至数万条数据。经过粗略估算,这些对象的总大小大约为5MB左右。

看启动参数中G1HeapRegionSize=8m,代表每个Region的大小为8M,G1 GC会将大于Region一半大小的对象直接分配到老年代。所以orderBills对象会被直接分配到老年代,这也和在凌晨1点的时候年轻代使用无明显波动,老年代使用有直线上涨的现象相符合。在后续的循环中,由于垃圾收集器清理的速度赶不上内存分配的速度,导致垃圾逐渐积累并最终填满整个堆空间,触发了Full GC

不过小菜同学有点疑惑为什么GC之后容器的内存还是一直居高不下呢?

经过一番查阅资料,原来JVM启动时并不会立即实际占用全部Xms指定的内存。Xms参数指定的是堆的初始大小,JVM会按照这个值预留内存空间,但实际上只有在需要时才会逐渐使用这些预留的内存。

JVM在完成内存释放后,是否将释放的内存返回给操作系统,这一行为取决于具体的JVM实现及其采用的垃圾回收策略。在很多情况下,JVM在进行垃圾收集并释放了堆内存之后,并不会立即将这部分内存归还给操作系统。相反,它会保留这部分内存以备将来Java应用程序的使用,因为从操作系统重新申请内存通常会比从JVM内部管理的内存分配更为昂贵(时间成本上)。所以一般程序还会将XmsXmx配置为相等的大小,避免频繁申请和释放内存造成的性能开销。

上面两个问题找到原因了,小菜同学决定在本地复现一下进行验证。

新建一个memorytest项目,写一个方法模拟内存分配:


@RequestMapping("/memory/add/{num}/{size}")
public String add(@PathVariable("num") Integer num, @PathVariable("size") Integer size) {
    for (int i = 0; i < num; i++) {
        // 模拟查询出来的大对象
        byte[] allocation = new byte[size * 1024 * 1024];
    }
    return "";
}

用以下命令启动:

java -Xms2g -Xmx2g -Xmn1g -XX:+UseG1GC -XX:G1HeapRegionSize=8m -XX:G1ReservePercent=15 -XX:InitiatingHeapOccupancyPercent=50 -jar memorytest-0.0.1-SNAPSHOT.jar

使用Jdk自带的命令查询JVM内存分配情况,先使用jps -l查询进程ID:

jps -l
16988 sun.tools.jps.Jps
9068 memorytest-0.0.1-SNAPSHOT.jar

使用jmap -heap 查询堆内存分配:

jmap -heap 9068
Heap Usage:
G1 Heap:
   regions  = 256
   capacity = 2147483648 (2048.0MB)
   used     = 230686720 (220.0MB)
   free     = 1916796928 (1828.0MB)
   10.7421875% used
G1 Young Generation:
Eden Space:
   regions  = 26
   capacity = 1115684864 (1064.0MB)
   used     = 218103808 (208.0MB)
   free     = 897581056 (856.0MB)
   19.548872180451127% used
Survivor Space:
   regions  = 2
   capacity = 16777216 (16.0MB)
   used     = 16777216 (16.0MB)
   free     = 0 (0.0MB)
   100.0% used
G1 Old Generation:
   regions  = 0
   capacity = 1015021568 (968.0MB)
   used     = 0 (0.0MB)
   free     = 1015021568 (968.0MB)
   0.0% used

使用jstat -gcutil 1秒1次监控堆内存使用和GC情况(也可以使用jconsole可视化处理工具来查看内存的使用情况):

jstat -gcutil 9068 1000
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
  0.00 100.00  21.80   0.00  94.17  88.38      1    0.023     0    0.000    0.023

该命令返回的主要的参数的意义:
S0Survivor space 0区的使用率。
S1Survivor space 1区的使用率。
EEden区的使用率。
OOld区(老年代)的使用率。
YGC:年轻代垃圾收集事件的次数。
YGCT:年轻代垃圾收集所耗费的时间(秒)。
FGCFull GC(全堆垃圾收集)事件的次数。
FGCTFull GC所耗费的时间(秒)。
GCT:垃圾收集所耗费的总时间(秒)。

此时使用ps aux --sort -rss查看Java进程占用的本机内存才370MB左右,并没有直接占用Xms设置的2g。

ps aux --sort -rss
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root     9068  5.4  9.9 4718036 374536 pts/1  Sl+  15:10   0:09 java -Xms2g -Xmx2g -Xmn1g -XX:+UseG1GC -XX:G1HeapRegionSize=8m -XX:G1ReservePercent=15 -XX:InitiatingHeapOccupancyPercent=50 -jar memorytest-0.0.1-SNAPSHOT.jar

该命令返回的主要的参数的意义:
PID: 进程ID。
%CPU: 进程使用的CPU百分比。
%MEM: 进程使用的物理内存百分比。
RSS: 进程当前占用的物理内存大小,单位通常是KB。
COMMAND: 启动进程的命令行命令。

开始模拟业务分配内存,为了方便观察直接循环100000次,每次分配5MB空间:

http://127.0.0.1:8080/memory/add/100000/5

jstat此时监控到内存情况:

S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
  0.00 100.00  24.81   0.00  94.17  88.38      1    0.023     0    0.000    0.023
  0.00   0.00   1.48  61.36  93.38  89.74     12    0.192     0    0.000    0.192
  0.00 100.00   1.49  86.37  92.74  89.74     33    0.294     0    0.000    0.294
  0.00   0.00   2.27  99.41  92.74  89.74     56    0.395     0    0.000    0.395
  0.00   0.00   2.15  99.55  92.75  89.74     84    0.522     0    0.000    0.522
  0.00   0.00   1.94  99.77  92.20  89.00    119    0.663     0    0.000    0.663
  0.00   0.00   4.00  99.71  92.21  89.01    169    0.834     0    0.000    0.834
  0.00 100.00   0.75  21.43  92.22  89.01    232    0.998     1    0.051    1.049
  0.00 100.00   0.84  99.68  92.22  89.01    252    1.025     1    0.051    1.077
  0.00 100.00   0.88  99.87  92.25  89.01    274    1.064     1    0.051    1.115
  0.00   0.00   1.48  70.73  92.25  89.01    299    1.110     1    0.051    1.161
  0.00   0.00   1.48  75.90  92.25  89.01    327    1.168     1    0.051    1.219
  0.00   0.00   1.77  99.81  92.25  89.01    361    1.239     1    0.051    1.290
  0.00   0.00   2.41  99.92  92.27  89.01    409    1.340     1    0.051    1.392

此时可以看到对象都直接分配到了老年代,年轻代的内存使用没有多大的变化,并且当YGC(Young Generation Garbage Collection,年轻代垃圾回收)来不及回收时就会发生FGC(Full Garbage Collection,全堆垃圾回收)

此时再使用ps aux --sort -rss查看Java进程占用的本机内存已经到了2G了,并且在方法执行完成后(也包括FGC后)也没有释放此内存。

ps aux --sort -rss
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root     9068 77.1 60.4 4720084 2043996 pts/1 Sl+  15:10   6:03 java -Xms2g -Xmx2g -Xmn1g -XX:+UseG1GC -XX:G1HeapRegionSize=8m -XX:G1ReservePercent=15 -XX:InitiatingHeapOccupancyPercent=50 -jar memorytest-0.0.1-SNAPSHOT.jar

再模拟一次业务分配内存,为了方便观察直接循环100000次,这次每次分配2MB空间:

http://127.0.0.1:8080/memory/add/100000/2

jstat此时监控到内存情况:

S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
  0.00 100.00  15.04   0.00  94.14  88.45      1    0.027     0    0.000    0.027
  0.00 100.00  15.04   0.00  94.14  88.45      1    0.027     0    0.000    0.027
  0.00 100.00  93.18   0.00  93.15  89.36      2    0.043     0    0.000    0.043
  0.00 100.00  51.49   0.66  93.15  89.36     22    0.146     0    0.000    0.146
  0.00   0.00  68.15   1.48  93.15  89.36     44    0.167     0    0.000    0.167
  0.00   0.00  81.48   1.48  93.15  89.36     66    0.186     0    0.000    0.186
  0.00   0.00  16.30   1.48  93.15  89.36     89    0.207     0    0.000    0.207
  0.00   0.00  58.52   1.48  93.15  89.36    111    0.226     0    0.000    0.226
  0.00   0.00   4.44   1.48  93.16  89.36    134    0.246     0    0.000    0.246
  0.00 100.00  50.00   0.66  93.16  89.36    156    0.265     0    0.000    0.265
  0.00   0.00  88.15   1.49  93.16  89.36    178    0.284     0    0.000    0.284
  0.00   0.00  41.48   1.49  93.16  89.36    201    0.305     0    0.000    0.305
  0.00   0.00  87.41   1.49  93.16  89.36    223    0.324     0    0.000    0.324
  0.00   0.00  27.41   1.49  93.17  89.36    246    0.344     0    0.000    0.344
  0.00   0.00  89.63   1.49  93.17  89.36    263    0.358     0    0.000    0.358
  0.00   0.00  89.63   1.49  93.17  89.36    263    0.358     0    0.000    0.358

此时很明显可以看到对象都直接分配到了年轻代,年轻代的回收效率也比老年代高,并且没有产生FGC

再结合本次报警的现象,解决办法也呼之欲出:

4、问题小结

JVM内存问题可能不常有,但是一旦发生可能对我们系统造成极大的影响,此次内存飙升也给我们敲响了警钟,发现了我们在这边注重的不够,很多监控和日志并不完整,如启动参数中没有加上发生OOM时自动dump文件的参数等。好在此次服务未受到影响,所有有足够的时候给我们去排查和验证。特此结合此次排查的过程的一些收获记录一下,假设下次还有发生可以有所参考:

#jmap命令保存整个Java堆(在你dump的时间不是事故发生点的时候尤其推荐)
jmap -dump:format=b,file=heap.bin  

#jmap命令只保存Java堆中的存活对象, 包含live选项,会在堆转储前执行一次Full GC
jmap -dump:live,format=b,file=heap.bin 

#jcmd命令保存整个Java堆,Jdk1.7后有效
jcmd  GC.heap_dump filename=heap.bin

还有在启动参数中添加发生OOM时自动生成heapdump的参数:-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp/heap.bin启动参数中添加GC日志打印相关的参数:

# Java8及以下
-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:

# Java9及以上
-Xlog:gc*::time
jstat -gcutil  :监视Java堆状况,主要关注已使用空间的百分比和GC情况

jmap -heap  :显示Java堆详细信息

jmap -histo[:live]  :显示堆中对象统计信息:快速识别哪些类的实例占用了大量的堆内存

5、总结

面对内存使用率的异常,我们不仅要关注即时的解决方案,还需要考虑如何从根本上避免此类问题的再次发生。如使用优化数据结构、减少不必要的计算、采用懒加载等策略,以及建立细致的内存监控体系等。性能优化不应该仅仅是面对问题时的临时行动,而应该成为开发文化的一部分。

来源:转转技术内容投诉

免责声明:

① 本站未注明“稿件来源”的信息均来自网络整理。其文字、图片和音视频稿件的所属权归原作者所有。本站收集整理出于非商业性的教育和科研之目的,并不意味着本站赞同其观点或证实其内容的真实性。仅作为临时的测试数据,供内部测试之用。本站并未授权任何人以任何方式主动获取本站任何信息。

② 本站未注明“稿件来源”的临时测试数据将在测试完成后最终做删除处理。有问题或投稿请发送至: 邮箱/279061341@qq.com QQ/279061341

软考中级精品资料免费领

  • 历年真题答案解析
  • 备考技巧名师总结
  • 高频考点精准押题
  • 2024年上半年信息系统项目管理师第二批次真题及答案解析(完整版)

    难度     813人已做
    查看
  • 【考后总结】2024年5月26日信息系统项目管理师第2批次考情分析

    难度     354人已做
    查看
  • 【考后总结】2024年5月25日信息系统项目管理师第1批次考情分析

    难度     318人已做
    查看
  • 2024年上半年软考高项第一、二批次真题考点汇总(完整版)

    难度     435人已做
    查看
  • 2024年上半年系统架构设计师考试综合知识真题

    难度     224人已做
    查看

相关文章

发现更多好内容

猜你喜欢

AI推送时光机
位置:首页-资讯-后端开发
咦!没有更多了?去看看其它编程学习网 内容吧
首页课程
资料下载
问答资讯