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

ChicagoTypewriter

已于 2023-05-23 00:17:26 修改

阅读量1.5k

点赞数 2

分类专栏： linux 文章标签： jvm linux

于 2023-05-21 00:57:23 首次发布

本文链接：https://blog.csdn.net/niceHack/article/details/130784369

版权

linux 专栏收录该内容

9 篇文章 0 订阅

订阅专栏

文章描述了一个JVM启动时遇到的问题，即使系统内存充足，仍然报内存分配错误。通过排查，发现问题源于系统参数`overcommit_memory`被设置为2，导致内存超额分配策略改变。当进程申请内存超过限定值时，启动会被阻止。解决方案是理解和调整内核参数，确保内存申请和分配策略匹配应用需求。

摘要由CSDN通过智能技术生成

内存充足，但是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切换，说明在不断尝试重启，这也说明不是手动操作的。这也是好事，不断重启就说明问题一直在，有了一定的跟踪时间。

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

于是，用free命令看了当时的内存占用，表示内存占用并不高，这个应用的初始堆内存为3G，根据free结果，应该是可以满足的：
在这里插入图片描述
于是根据第一张图的提示，看hs_err_pid.log文件：

日志表示，确实是没有足够的内存分配给这个新进程了，新进程需要的初始内存刚好也是3G。
那这就奇怪了，明明free看到的内存是充足的，新的进程启动却无法给分配，操作系统傻缺了吗？
又想到前两天，也是在这个环境，我打算启动arthas监控一下jvm，也是报一样的错，无法分配内存，想起来和今天遇到的问题是一样的，操作系统的内存分配一定有问题，猫腻也应该是出在这里。

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

到这里，问题大方向变成了系统参数。

三、问题原因

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

操作系统上会运行很多进程，为了每个进程有一块独立的内存空间，互不干扰易于管理和使用，同时可以最大程度的利用好有限的物理内存资源。诞生了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

测试恢复后的系统配置：
在这里插入图片描述

当前环境中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

在这里插入图片描述
以上截图是我们将/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

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