物理内存耗尽、CMS GC碎片造成RT慢的两个Case

最近碰到的两个Case:一个是一个应用每天晚上集群里都有几台java进程退出的case;另一个是一个应用运行一段时间后在某种情况下RT突然变慢的Case,来看看排查过程。

Case I
第一个Case是每晚都有几台java进程退出,上机器看,dmesg | grep kill后发现是由于oom,所以os层面把进程给杀掉了,看了下当时的内存使用状况,发现物理内存快被用光了,说明这是一个堆外内存被用光的case,根据这个应用的特征,知道这个应用会用到大量的Direct Memory,看了下应用的启动参数,是没有配置MaxDirectMemorySize的,因此MaxDirectMemorySize的大小即等于-Xmx,从启动参数来看,-Xmx + MaxDirectMemorySize确实超过了物理内存的大小。

为什么会出现Direct Memory造成物理内存被耗光,就得说下Direct Memory的回收机制,Direct Memory是受GC控制的,例如ByteBuffer bb = ByteBuffer.allocateDirect(1024),这段代码的执行会在堆外占用1k的内存,Java堆内只会占用一个对象的指针引用的大小,堆外的这1k的空间只有当bb对象被回收时,才会被回收,这里会发现一个明显的不对称现象,就是堆外可能占用了很多,而堆内没占用多少,导致还没触发GC,那就很容易出现Direct Memory造成物理内存耗光。

为什么会有部分机器出现退出,而有些机器正常,按照上面的推测,主要就取决于有没有触发GC,从而回收堆外的Direct Memory,查看了正常的机器的gc log,确实触发了cms gc,而出问题的这些机器,则没有执行,这样就可以解释通了。

按照这样的分析,解决方法也就自然产生了,就是加上-XX:MaxDirectMemorySize,加上这个大小限制后,那么只要Direct Memory使用到达了这个大小,就会强制触发GC,这个大小如果设置的不够用,那么在日志中会看到java.lang.OutOfMemoryError: Direct buffer memory。

对于使用Direct Memory较多的场景,需要注意下MaxDirectMemorySize的设置,避免-Xmx + Direct Memory超出物理内存大小的现象。

Case II
有一个应用出现了非常奇怪的现象,就是运行了一段时间后会突然的出现rt从之前的50ms变成150ms左右的现象,但这个应用依赖的所有的后端的rt没什么变化,也就是应用的本身,但只要重启下应用就会恢复。

重启后就会恢复,因此决定用btrace一步一步跟,看看是哪里变慢了,但业务逻辑太复杂了,btrace不是很好跟,因此折腾了很久还是没看出太多的端倪。

业务方自己发现有个现象,就是在rt变慢的时候,gc的时间也会慢很多,在rt快的时候,ygc大概只需要15ms,而在rt变慢后,ygc大概需要45ms。

在采用cms gc的情况下,ygc变慢的原因通常是由于old gen出现了大量的碎片,因此猜测是这个问题,于是用jmap -histo:live强制执行了下full gc,执行完毕后,rt果然又从150ms降到了50ms。

因为是cms gc碎片问题造成的rt变慢,要解决还真的比较棘手,暂时只能是折腾成每天凌晨定时强制执行下full gc,悲催的碎片问题(所以还是那句话,如果不是因为heap size大,以及对rt比较敏感的话,能不用cms gc还是别用为妙)…

之前也碰过很多次cms gc的碎片问题,但通常是其造成的full gc导致的影响,而像这次case中这种对rt产生如此大影响的还真是第一次碰到(而且还有个诡异的现象,就是其实那些rt慢的机器在之前也有由于concurrent mode failure执行过full gc,但rt却没下降)。

—————————————————-
微信公众账号后台开放了之前青龙老贼透露的数据统计的功能,例如订阅公众账号的用户的增长状况、性别比例、省份比例,每篇文章的浏览、打开、原文链接和转发次数等,挺帅的。

我的这个账号的一些有趣的数字:
订阅者中MM的比例:5.81% (果然低呀)
订阅者中杭州用户的比例:31.92%(这样看来订阅者中阿里的不少)
文章的打开率: 50%左右… (真心不怎么高)

=============================
题图来源于:http://img.ifeng.com/tres/auto/9/2010/0531/107_4915254228_20100531165840.jpg
欢迎关注微信公众号:hellojavacases

关于此微信号:
分享Java问题排查的Case、Java业界的动态和新技术、Java的一些小知识点Test,以及和大家一起讨论一些Java问题或场景,这里只有Java细节的分享,没有大道理、大架构和大框架。

公众号上发布的消息都存放在http://hellojava.info上。

微信互动问答

最近微信上的几个问题,我觉得还是有必要单独发一条信息来回答,:),也欢迎大家继续发送问题,分享你排查的case(如果有投稿,那是极度的欢迎),还有Java使用中碰到的一些“坑”。

问:btrace能否介绍一下调试经验?
答:btrace绝对是我排查问题工具集中的神器(内核级别systemtap也是神器,但它对性能的影响显然要比btrace大多了),btrace是生产环境运行时可使用的(也有些小问题,例如退出的时候可能有些残留等),btrace的使用非常简单,从官网上把btrace的tgz包下载解压后,通常修改下bin/btrace,主要是增加JAVA_HOME,将btrace改为可执行,接着就可以编写Java作为脚本来执行了,具体btrace使用的一些简单脚本的例子可见此篇文章,另外我可以给的建议是btrace这东西想用的熟练的话,就在自己本机的java代码里多试试就OK了,例如随便写段程序,跟踪下里面java.util.HashMap.put的调用堆栈,跟踪下调用时间消耗、传入的参数和返回值等,话说前几天我在生产环境用btrace还碰到个问题,我跟踪的那个方法输出的信息太多,结果为了让btrace停止,我按了多次ctrl+c,然后回车,估计按太多次了,竟然导致目标进程的heap被用满了,一直fgc。

问:最近有人说,在java里。尽量不要用大的try catch. 因为那样try块中的代码执行效率会降低,我也是第一次听说,之前我们都会在业务层把所有的代码的异常都捕获掉。这个问题还没找到答案。你怎么看的。
答:话说这个说法我还真不知道理由是什么,按照我知道的Java执行原理来说,不要在一个方法体里写过多行数的代码倒是有道理的,因为确实会导致性能下降,这种情况下性能下降的原因有两个:一是因为Java对运行时从bytecode–>native code的编译的方法默认有大小的限制,默认限制的大小为8000bytes,当一个方法超过8000bytes时,将不会对其进行编译,可通过-XX:-DontCompileHugeMethods来强制允许编译,但那样会导致codecache的区域被用满的可能性大增(上一个RT下降的Case就是因为code cache被用满);二是因为Java对inline方法的大小也有大小的限制,inline方法的大小限制通常很小,例如默认值是35bytes(可用jinfo -flag MaxInlineSize [pid]来查看),inline后方法的执行会加快一些(毕竟少了跳的步骤)。

问:你好,请问有办法查看java线程的网络流量么。我有一个程序要访问很多网络服务,运行一段时间后带宽就被占满了,并且一直维持这个状态。请问怎么排查这种情况。谢谢。
答:这种我还真不知道,我能想到的办法就是tcpdump看看主要是哪些频繁的请求,或者就是根据使用的网络框架等用btrace跟踪收发包部分的代码(例如可跟踪序列化/反序列化部分的代码),看看是什么地方在频繁做动作或收发较大的包。

问:jdbc和hibernate的选择
答:我的回答是对性能要求很高的场景,还是直接用jdbc吧,hibernate固然好用,但有个主要的问题是生成的sql看起来很痛苦,另外是还得等运行时生成,对于很多对性能敏感的应用而言,最好是所有用到的sql都能提前评估。

问:也碰见’占用系统内存不释放’查到os:malloc占用大多数”’没有思路了
答:这个问题的背景就是堆外内存被耗光,显然这已经用google perf-tools跟踪过了,看到了os::malloc占用了最多,这个时候可以进一步用pprof –gv来图形化的跟踪下os::malloc的堆栈,如果看到是unsafe_allocate,又如果是server端程序,那基本上可以肯定是由于Direct ByteBuffer造成的(因为Java中通常只有Direct ByteBuffer和AWT会调用unsafe来做allocate,实在不行还可以用btrace跟跟),这种情况下通过增加-XX:MaxDirectMemorySize可解决(具体也可参见这篇文章中的几个Case)。

问:请教您一个经验问题,就是缓存系统一般设置访问超时时间是多少?我们一个后台核心系统最近上了缓存memcached,用于实时计数,但是由于环境以及压测不够的原因,系统上线后跑了一段时间后突然出现大量缓存访问超时,而我们的超时时间是设置了两秒,导致整个系统都处理缓慢了。。我想要的是即使缓存在出问题的时候也不要拖慢系统。所以想问下您这里缓存系统的访问超时时间一般是多少比较合理?
答:对于大访问量系统而言,超时时间绝对是个超级敏感的值,当年我上线一个系统的时候就是由于其中一个远程调用的默认超时时间是1分钟而导致了一次严重故障,缓存这种无论如何都应该是非常快速完成的一个动作,因此通常建议其超时时间设置为50ms或100ms,即使是复杂逻辑的远程调用,我们通常也会把超时时间控制在1s以下,避免依赖的服务端变慢而导致自己的请求线程被耗光。

ps: 最近的一个排查了将近一周多时间的case是和Groovy相关的case,之后再来专门写篇文章说说Groovy的使用,要在生产环境中用好Groovy(尤其是大量使用)还是要小心不少“坑”的,但Groovy确实有一些好处,所以有些事。

=============================
欢迎关注微信公众号:hellojavacases

关于此微信号:
分享Java问题排查的Case、Java业界的动态和新技术、Java的一些小知识点Test,以及和大家一起讨论一些Java问题或场景,这里只有Java细节的分享,没有大道理、大架构和大框架。

公众号上发布的消息都存放在http://hellojava.info上。

答:CMS GC会不会回收Direct ByteBuffer的内存

微信上有同学(也是同事)发消息问我这个问题,回答是:Oracle JDK 6u32前的版本不会。

Direct ByteBuffer是在Java Heap外分配内存,NIO等东西里使用的比较多,但Direct ByteBuffer分配出去的内存其实也是由GC负责回收的,而不像之前一篇文章里的Unsafe是完全自行管理的,Hotspot在GC时会扫描Direct ByteBuffer对象是否有引用,如没有则同时也会回收其占用的堆外内存,但不幸的是在6u32前的版本里,CMS GC有bug会导致可能回收不掉,具体的bug id为7112034,在链接的Backport信息里,可以看到这个bug是在hotspot 20.7的版本里修复的(hotspot的版本号通过java -version的最后一行Java Hotspot Version之类的可以看到),6u32带的就是这个版本,所以6u32是会回收的。

回收不掉的情况下会造成的问题是明明已经不用了,但堆外内存仍然被消耗掉,悲惨的情况下可能会导致堆外内存耗光。

Direct ByteBuffer除了上面这个bug可能造成堆外内存耗光外,还有一种场景也可能会造成堆外内存耗光,如Direct ByteBuffer对象晋升到了Old区,那这个时候就只能等Full GC触发(CMS GC的情况下等CMS GC),因此在Direct ByteBuffer使用较多,存活时间较长的情况下,有可能会导致堆外内存耗光(因为Direct ByteBuffer本身对象所占用的空间是很小的)。

对于上面这种类型的应用,最好是在启动参数上增加-XX:MaxDirectMemorySize=x[m|g],例如-XX:MaxDirectMemorySize=500m

这个参数默认的大小是-Xmx的值(在没设置MaxDirectMemorySize参数的情况下,用jinfo -flag等方式会看到默认值是-1,但VM.maxDirectMemory这个方法里发现是-1,则会以-Xmx作为默认值),此参数的含义是当Direct ByteBuffer分配的堆外内存到达指定大小后,即触发Full GC(这段逻辑请见Bits.reserveMemory的代码),如Full GC后仍然分配不出Direct ByteBuffer需要的空间,则会报OOM错误:
java.lang.OutOfMemoryError: Direct buffer memory

因为上面所说的状况,如碰到堆外内存占用较多的场景,可以尝试强制执行Full GC(强制的方法为执行jmap -histo:live)看看,多执行一两次,如堆外内存下降的话,很有可能就是Direct ByteBuffer造成的,对于这种情况,通常加上上面的启动参数就可解决。

很多情况下,我们会看到Java进程占用的内存超过-Xmx的大小,原因就是类似Direct ByteBuffer、Unsafe、GC、编译、自己写的JNI模块等这些是需要占用堆外空间的。

=============================
欢迎关注微信公众号:hellojavacases
关于此微信号:
用于分享Java的一些小知识点,Java问题排查的Cases,Java业界的动态,以及和大家一起互动讨论一些Java的场景和问题。

公众号上发布的消息都存放在http://hellojava.info上。