ICode9
精准搜索请尝试： 精确搜索
首页
编程语言>
数据库
系统相关
互联网
其他分享
Python
Java
JavaScript
android
PHP
首页 > 其他分享> 文章详细

【Netty】ByteBuf.release() was not called before it's garbage-collected

2021-02-28 11:36:43  阅读：314  来源： 互联网

标签：Netty java garbage netty XX 内存 io collected 日志


1 现象

  • 线上应用运行一段时间就发生应用重启，临时调整内存大小，降低重启频率，给定位问题和修复缺陷腾点时间，对业务使用降低影响(重启存在短时不可用状态，秒级别)；
  • 线上使用过程中发现文件无法上传；文件下载没问题；业务增删改查使用正常；
  • 日志报错：
    • 提示无法申请直接内存，已超出最大可申请的直接内存；
    • 提示存在垃圾回收前ByteBuf未释放；
2021-02-18 16:17:58.399	2021-02-18 16:17:58.399 ERROR 1 --- [oServerWorker-2] c.c.c.g.p.i.ClientToProxyConnection : (AWAITING_INITIAL) [id: 0xedf191be, L:/172.30.173.45:8080 - R:/172.30.146.1:35754]: Caught an exception on ClientToProxyConnection
2021-02-18 16:17:58.399	io.netty.util.internal.OutOfDirectMemoryError: failed to allocate 16777216 byte(s) of direct memory (used: 2781194413, max: 2793406464)
2021-02-18 16:17:58.399	at io.netty.util.internal.PlatformDependent.incrementMemoryCounter(PlatformDependent.java:725) ~[netty-all-4.1.42.Final.jar:4.1.42.Final]

2021-02-18 16:33:59.636	2021-02-18 16:33:59.636 ERROR 1 --- [oServerWorker-0] i.n.u.ResourceLeakDetector : LEAK: ByteBuf.release() was not called before it's garbage-collected. See https://netty.io/wiki/reference-counted-objects.html for more information.
2021-02-18 16:33:59.636	Recent access records:
2021-02-18 16:33:59.636	#1:
2021-02-18 16:33:59.636	io.netty.handler.codec.http.HttpObjectAggregator$AggregatedFullHttpMessage.release(HttpObjectAggregator.java:379)

2021-02-18 17:13:36.840 ERROR 55896 --- [oServerWorker-3] i.n.u.ResourceLeakDetector               : LEAK: ByteBuf.release() was not called before it's garbage-collected. See https://netty.io/wiki/reference-counted-objects.html for more information.
Recent access records:
Created at:
     io.netty.buffer.PooledByteBufAllocator.newDirectBuffer(PooledByteBufAllocator.java:349)
     io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:187)
     io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:178)
     io.netty.buffer.CompositeByteBuf.allocBuffer(CompositeByteBuf.java:1835)
     io.netty.buffer.CompositeByteBuf.copy(CompositeByteBuf.java:1487)
     io.netty.buffer.AbstractByteBuf.copy(AbstractByteBuf.java:1209)
     io.netty.buffer.WrappedCompositeByteBuf.copy(WrappedCompositeByteBuf.java:493)
	 io.netty.buffer.AdvancedLeakAwareCompositeByteBuf.copy(AdvancedLeakAwareCompositeByteBuf.java:681)
io.netty.handler.codec.http.HttpObjectAggregator$AggregatedFullHttpRequest.copy(HttpObjectAggregator.java:405)
	org.littleshoot.proxy.impl.ClientToProxyConnection.copy(ClientToProxyConnection.java:848)
org.littleshoot.proxy.impl.ClientToProxyConnection.doReadHTTPInitial(ClientToProxyConnection.java:163)
	org.littleshoot.proxy.impl.ClientToProxyConnection.readHTTPInitial(ClientToProxyConnection.java:140)
	org.littleshoot.proxy.impl.ClientToProxyConnection.readHTTPInitial(ClientToProxyConnection.java:56)
	org.littleshoot.proxy.impl.ProxyConnection.readHTTP(ProxyConnection.java:116)
	org.littleshoot.proxy.impl.ProxyConnection.read(ProxyConnection.java:101)
	org.littleshoot.proxy.impl.ProxyConnection.channelRead0(ProxyConnection.java:477)
io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)

2 分析

  • Netty依赖于ByteBuf管理直接内存，但ByteBuf的引用由JVM管理，当ByteBuf引用置为空，但实际申请的直接内存未释放就会导致直接内存溢出；
  • 从提示中定位到org.littleshoot.proxy.impl.ClientToProxyConnection.copy方法；查询Github LittleProxy的issue，也有小伙伴遇到同样的问题，参考他的实现，不返回copy，而是直接返回original试试看。

3 改造

（1）添加直接内存检测日志

int maxMemoryInKb = (int) (PlatformDependent.maxDirectMemory() / 1024);
int used = (int) (PlatformDependent.usedDirectMemory() / 1024);
log.info("netty_direct_memory:used({}k) max({}k)", memoryInKb, used, maxMemoryInKb);

（2）ClientToProxyConnection的copy方法修复

private HttpRequest copy(HttpRequest original) {
    if (original instanceof FullHttpRequest) {
        return original; // 注释掉 ((FullHttpRequest) original).copy();
    } else {
        HttpRequest request = new DefaultHttpRequest(original.protocolVersion(), original.method(), original.uri());
        request.headers().set(original.headers());
        return request;
    }
}

4 本地测试

（1）本地打包应用启动

java -jar -verbose:gc -Xloggc:/tmp/gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=3M -XX:-TraceClassUnloading -Djava.io.tmpdir=/tmp -XX:OnOutOfMemoryError=$JAVA_HOME/bin/killjava.sh  -XX:+ExitOnOutOfMemoryError -XX:+UseG1GC -Xss228K -Xmx317161K -Xms317161K -XX:MetaspaceSize=64M -XX:MaxMetaspaceSize=64M -Dio.netty.leakDetectionLevel=paranoid -Dio.netty.maxDirectMemory=67108864 gateway-app.jar > log.out
  • GC日志打印相关参数：-verbose:gc -Xloggc:/tmp/gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=3M -XX:-TraceClassUnloading -Djava.io.tmpdir=/tmp
  • OOM退出参数：-XX:OnOutOfMemoryError=$JAVA_HOME/bin/killjava.sh -XX:+ExitOnOutOfMemoryError
  • Netty相关参数：
    • -Dio.netty.leakDetectionLevel=paranoid 溢出检测级别
      • disabled：禁用；
      • 默认为simple：取样1%的ByteBuf是否发生泄漏，不打印详细泄露日志；
      • advanced：取样1%的ByteBuf是否发生泄漏，打印详细泄露日志；
      • paranoid：检测所有的ByteBuf是否发生泄漏，打印详细泄露日志；（正式上线需去掉，以免影响性能。）
    • -Dio.netty.maxDirectMemory=67108864 Netty最大直接内存设置
      • 参数需实际情况设置，关键指标为并发数，Netty性能再高也存在内存正常占用的情况，需要使用完后‘释放’，所以当并发50与并发100配置的大小差距很大；
      • 默认不配置时，取系统中最大可用的直接内存；
  • 分代GC相关参数：-XX:+UseG1GC -Xss228K -Xmx317161K -Xms317161K -XX:MetaspaceSize=64M -XX:MaxMetaspaceSize=64M
  • 日志输出：gateway-app.jar > log.out

注：对溢出检测感兴趣可以看看ResourceLeakDetector、SimpleLeakAwareByteBuf、AbstractByteBufAllocator等几个类。

（2）压测

  • 使用Jmeter工具模拟文件上传，并发数缓慢提升，避免直接撑爆最大直接内存，持续压测30分钟；
  • 使用jvisualvm或jconsole观察JVM内存状态，只会发生10多次NewGC；
  • 查看log.out日志中，搜索'ERROR'级别日志；（原先版本基本高负载运行5~10分钟便可以看到内存溢出的提示日志）
  • 查看log.out日志中，查看直接内存增长情况；

5 测试环境

（1）提交代码自动化部署至测试环境

（2）压测

  • 使用Jmeter工具模拟文件上传，并发数缓慢提升，避免直接撑爆最大直接内存，持续压测30分钟；
  • 查看log.out日志，搜索'ERROR'级别日志；（原先版本基本高负载运行5~10分钟便可以看到内存溢出的提示日志）；
  • 查看log.out日志中，查看直接内存增长情况；
  • jstat -gcutil pid interval：如：jstat -gcutil jvmPid 1000（1号进程每一秒输出jvm内存状态，百分比）；
  • jstat -gccapacity pid interval：如：jstat -gcutil jvmPid 1000（1号进程每一秒输出jvm内存状态，字节数）；
  • top 查看进程内存、CPU占用情况；

6 生产上线

  • 观察每天的请求量，请求量与原先差不多，内存短暂飙升后趋于稳定；
  • 观察直接内存使用情况：基本稳定使用163840k/2727936k = 6%；
  • 观察异常日志情况：暂无发现异常；

标签：Netty,java,garbage,netty,XX,内存,io,collected,日志
来源： https://www.cnblogs.com/linzhanfly/p/14458404.html

本站声明： 1. iCode9 技术分享网（下文简称本站）提供的所有内容，仅供技术学习、探讨和分享；
2. 关于本站的所有留言、评论、转载及引用，纯属内容发起人的个人观点，与本站观点和立场无关；
3. 关于本站的所有言论和文字，纯属内容发起人的个人观点，与本站观点和立场无关；
4. 本站文章均是网友提供，不完全保证技术分享内容的完整性、准确性、时效性、风险性和版权归属；如您发现该文章侵犯了您的权益，可联系我们第一时间进行删除；
5. 本站为非盈利性的个人网站，所有内容不会用来进行牟利，也不会利用任何形式的广告来间接获益，纯粹是为了广大技术爱好者提供技术内容和技术思想的分享性交流网站。

关于我们 | 联系我们 | 留言反馈

专注分享技术，共同学习，共同进步。侵权联系[81616952@qq.com]

Copyright (C)ICode9.com, All Rights Reserved.

ICode9版权所有