记一次java应用启动失败问题排查过程

╰+攻爆jí腚メ 2024-03-17 09:02 75阅读 0赞

> 内存充足，但是jvm启动还是报分配不到内存

#### 文章目录 ####

*  一、问题现象
 *  二、排查过程
 *  三、问题原因
 *  总结

--------------------

`应用启动日志：Caot allocate memory`  
`/proc/sys/vm/swappiness` 使用SWAP分区的积极程度，值越大越积极  
`/proc/sys/vm/overcommit_memory` 进程内存分配超额机制  
`/proc/sys/vm/overcommit_ratio` overcommit\_memory=2时，总物理内存\*overcommit\_memory/100则是内存申请的大小上限

--------------------

## 一、问题现象 ##

最近在处理一个线上问题，已经出了补丁在测试环境验证，今天下午在测试环境观察了以下jvm内存和日志，都正常就去看别的了。没想到还没几分钟，测试微信问我是不是重启过服务，我一脸懵逼。虽然不知道具原因，但是我知道接下来要忙起来了。

## 二、排查过程 ##

第一反应是测试自己敲错了命令，手动重启了服务；如果不是这种情况，那么就是一个绕不过去的bug了，需要深入分析定位。  
首先，我确认自己这边history操作是没有重启命令执行的，测试那边也确认是没有手动执行。  
使用我司封装的命令查看该应用的状态，一直在starting和initing切换，说明在不断尝试重启，这也说明不是手动操作的。这也是好事，不断重启就说明问题一直在，有了一定的跟踪时间。

应用一直重启，那么肯定是有原因的，对应的原因一般情况都会输出在日志中。遂找到对应应用的启动日志，发现提示如下：  
![在这里插入图片描述][0256eb6d65f24932b3210553818ccd26.png]  
主要信息为：无法给jvm申请到内存资源。

于是，用free命令看了当时的内存占用，表示内存占用并不高，这个应用的初始堆内存为3G，根据free结果，应该是可以满足的：  
![在这里插入图片描述][0d8a1dba5b5d46df94d5abfa9111a63c.png]  
于是根据第一张图的提示，看hs\_err\_pid.log文件：  
![在这里插入图片描述][cb82d04f09074f768c361d38c65bb950.png]  
日志表示，确实是没有足够的内存分配给这个新进程了，新进程需要的初始内存刚好也是3G。  
那这就奇怪了，明明free看到的内存是充足的，新的进程启动却无法给分配，操作系统傻缺了吗？  
又想到前两天，也是在这个环境，我打算启动arthas监控一下jvm，也是报一样的错，无法分配内存，想起来和今天遇到的问题是一样的，操作系统的内存分配一定有问题，猫腻也应该是出在这里。

怎奈操作系统的只是储备不够，只好求助CSDN的经验，搜索关键词：“内存充足 但是jvm启动还是报分配不到内存”  
![在这里插入图片描述][75253b3283994043b099347dac31077a.png]  
帖子中说明是系统内存分配策略参数被修改过导致，我问了测试，果然修改过系统参数：  
![在这里插入图片描述][36e3dd3e5df74ebbb1d58ce63a3feaa2.png]  
到这里，问题大方向变成了系统参数。

## 三、问题原因 ##

那么，具体是修改了什么系统参数，这个参数又是如何影响进程的内存分配的呢？这个改动是否是这个导致问题的根本原因？

操作系统上会运行很多进程，为了每个进程有一块独立的内存空间，互不干扰易于管理和使用，同时可以最大程度的利用好有限的物理内存资源。诞生了MMU（Memory Management Unit），内存管理单元负责统一管理虚拟内存和物理内存的映射。由于虚拟内存和物理内存的这种映射关系（mmap），所以虚拟内存当然是可以超过物理内存的，那么这种超额总会有个限制，具体的限制策略就是`overcommit机制`。  
overcommit\_memory有以下三种超额策略：

*  0 ------默认值，进程启动时申请的内存和剩下的物理内存做比较，如果超过就申请失败
 *  1 ------Always overcommit，不做限制，不过后续会策略kill某些进程来释放物理内存
 *  2 ------当请求申请的内存 >= SWAP内存大小 + 总物理内存 \* N，则拒绝此次内存申请（N为overcommit\_ratio）

# 内存超限策略
    	/proc/sys/vm/overcommit_memory
    	# 内存超限策略2中的内存比例
    	/proc/sys/vm/overcommit_ratio

测试恢复后的系统配置：  
![在这里插入图片描述][f7414b3c8a094ed089b2f89f207149f8.png]

当前环境中swap空间始终为0，overcommit\_memory策略被修改为2的情况下，overcommit\_ratio默认为50，总内存为31G。根据以上公式，可以算出所有的进程可以申请到的内存大小为：0+31\*50/100=15G。也就是说，在该环境中内存申请上限大约为15G,如果超过这个限制，操作系统将会启动OOM-kill机制。进一步的，在尝试重新启动进程的时候，比如一个java应用初始堆内存大小配置为3G，那么启动该进程需要申请的内存空间至少为3G，如果资源不足则进程启动失败。  
至此，问题已经清楚。得到的经验教训为，在一般情况下可以通过free命令初步看到剩余可申请内存大小空间。如果现象比较反常，需要考虑一下是否是内核默认参数被有意或者无意的改动过。

那么，我们现在知道如何通过free命令和overcommit参数计算出，可供申请的内存地址空间上限。我们如何准确的计算出，当前环境上已经申请的内存空间大小呢？通过top命令依次求和计算吗？虽然这也不是不可以，不过对于这个已经申请的内存大小，内核中有一个专门的描述，即Committed\_AS，该信息保存在/proc/meminfo中：

cat /proc/meminfo | grep --color Commit

![在这里插入图片描述][ff5dfffe75074493ad0395c91c3d8da0.png]  
以上截图是我们将/proc/sys/vm/overcommit\_memory参数后将所有java应用正常运行一天后的截图，可以看到：  
CommitLimit（总内存空间\*overcommit\_ratio/100的结果），大约为15.6G  
Committed\_AS（已经申请的内存空间大小），大约为36.17G  
很明显已经申请的内存空间大小远超过了物理内存，这里就需要区分清楚两个概念：申请内存大小和分配内存大小。

那么，在OOM-kill后，java应用在自动尝试重启失败时生成的hs\_err\_pid.log文件中也可以看到/proc/meminfo的内容：

grep --color ^Commit  /home/xxx/xxx/xxx/hs_err_pid13783.log

![在这里插入图片描述][76903c75802144a59535301f9a39003a.png]  
可以看到，CommitLimit数值不变，因为物理内存总大小和overcommit\_ratio始终不变。  
Committed\_AS大约为14.99G，是始终小于CommitLimit的，因为这个时候overcommit\_memory参数为2，所以根据never-overcommit的内存申请超限策略，再申请3G内存就超过了限制，导致应用使用无法自己拉起来。

--------------------

## 总结 ##

1.  **内存申请**不等于**内存分配**，当内存在实际用到的时候才真正分配使用
2.  掌握内存申请限制内核参数：/proc/sys/vm/overcommit\_memmory和overcommit\_ratio
3.  对于进程内存申请的具体流程学习，可以通过以下博文了解

参考：  
[Linux kernel内存管理之overcommit相关参数][Linux kernel_overcommit]

[0256eb6d65f24932b3210553818ccd26.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/17/5ad94e0b04c842bf844ed86c802ac7a1.png
[0d8a1dba5b5d46df94d5abfa9111a63c.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/17/6ec21e9dfd1d484d9758e4ff9abcd68f.png
[cb82d04f09074f768c361d38c65bb950.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/17/43e583e827414aeb8237724089fd1fec.png
[75253b3283994043b099347dac31077a.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/17/b7d272aab4454d9eb5fa4a9abcf4647d.png
[36e3dd3e5df74ebbb1d58ce63a3feaa2.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/17/a394c9c1c5e44a4fab83f60b4a53fd34.png
[f7414b3c8a094ed089b2f89f207149f8.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/17/f8f7058666b447afa3c337715b08137b.png
[ff5dfffe75074493ad0395c91c3d8da0.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/17/bca8bdfe6ec740fbb04ec63af1331562.png
[76903c75802144a59535301f9a39003a.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/03/17/a5e7f4cbe8cc4b41b646678c2cedecc1.png
[Linux kernel_overcommit]: http://t.csdn.cn/ZdYYY