一.故事背景

由于开辟新市场需要,开发了新的项部署在海外平台,其中最消耗内存的功能是消费kafka消息(最开始预计一天有1千万的量),部署完之后运行一段时间发现出现内存告警问题。

依赖的logback版本

日志相关依赖:slf4j+logback 
slf4j-api        == 1.7.15
jcl-over-slf4j   == 1.7.15
commons-logging  == 1.1.3
logback-classic  == 1.2.9
logback-core     == 1.2.9

二.分析问题

出现内存告警,(新项目是低配置机器 2C4G * 2台)第一个念头是去查看堆空间设置的情况,看到jvm启动命令中堆空间都是直接指定大小,说明问题不是出在堆空间

-Xmx3g -Xms3g

先不管这些,去查看总的内存使用情况,发现总的内存空间使用将近有92% = 3.68G,那么这多出来使用的0.68内存是用在哪儿? JVM的堆外空间吗?

看来需要开启NMT查看下堆外空间的情况

-XX:NativeMemoryTracking=detail #开启NMT
-XX:+UnlockDiagnosticVMOptions  #配合NMT使用
-XX:+PrintNMTStatistics

==========题外话==================================

当然在这之前可以先查看下堆空间的使用情况

jmap -heap PID




Kubernetes logback写日志导致容器内存上涨 logback导致内存溢出_java


如果看到堆空间使用不到50%,可以适当缩小堆空间大小 -Xmx -Xms ,这样可以空余更多堆外空间和系统可用空间

==========题外话==================================

(本项目通过-heap查看发现堆空间使用不到50%,如果没有继续往下探究,其中一个优化方向就是将堆空间放小,也能解决内存告警问题)

开启 NMT 并且把堆空间调小为之后发现堆外空间使用并没有多少变化

那么到底是哪儿占用了这块内存?

Kubernetes logback写日志导致容器内存上涨 logback导致内存溢出_日志文件_02

查看java活跃的内存,发现使用才800M,

Kubernetes logback写日志导致容器内存上涨 logback导致内存溢出_后端_03

 但是机器的整体内存使用接近3.5G,而且其中的buffer/cache 块使用非常高

Kubernetes logback写日志导致容器内存上涨 logback导致内存溢出_后端_04

通过寻找资料后得到答案:

Kubernetes logback写日志导致容器内存上涨 logback导致内存溢出_后端_05

那就是存在文件IO,之后我重启了项目发现cache是随着时间不断增长,达到3G之后会回收,每次回收 约等于 300M(这些信息很重要)

分析项目中有那个地方会不停IO文件,而且不停增长,并且阈值是3G

立马想到了Logback这个框架,日志文件输出就是不间断的,而且随着时间不断增长的,还有上限最多生成N个日志文件,再多进行删除,目前设置的是 300M一个日志文件,最多同时存在10个,那不就是3个G!!!

想到这个之后,立马进行实验,登录到服务器上,打开日志对应目录,因为cache走的是文件IO,如果文件不存在,cache肯定会在下一次检测的时候释放,那我删除一个log.*文件之后,内存肯定会释放300M

<删除前> 

Kubernetes logback写日志导致容器内存上涨 logback导致内存溢出_后端_06

<删除后>

Kubernetes logback写日志导致容器内存上涨 logback导致内存溢出_java_07

猜想验证成功

三.解决方案

1.调整 日志文件的打印大小300M ->100M   , 调整日志文件打印数量 10 -> 5

2.寻找logback针对日志文件进入内存缓存问题的处理方案<待补充,欢迎@我>