一次内存泄露排查

018-04-20 11:36:01:ERROR http-bio-8888-exec-8 cn.shibei.feixia.handler.ControllerExceptionHandler.handledException(ControllerExceptionHandler.java:117) - 拦截到异常请求:
org.springframework.web.util.NestedServletException: Handler dispatch failed; nested exception is java.lang.OutOfMemoryError: Java heap space
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:978)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:897)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:650)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at cn.shibei.core.filter.AccessControlFilter.doFilter(AccessControlFilter.java:36)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:957)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:423)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1079)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:620)
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.OutOfMemoryError: Java heap space
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
at com.alibaba.com.caucho.hessian.io.JavaDeserializer.instantiate(JavaDeserializer.java:271)
at com.alibaba.com.caucho.hessian.io.JavaDeserializer.readObject(JavaDeserializer.java:155)
at com.alibaba.com.caucho.hessian.io.SerializerFactory.readObject(SerializerFactory.java:397)
at com.alibaba.com.caucho.hessian.io.Hessian2Input.readObjectInstance(Hessian2Input.java:2070)
at com.alibaba.com.caucho.hessian.io.Hessian2Input.readObject(Hessian2Input.java:2005)
at com.alibaba.com.caucho.hessian.io.Hessian2Input.readObject(Hessian2Input.java:1990)

 

从日志中可以看出 heap space发生了OOM

登陆飞侠服务器，通过jmap -heap发现堆内存使用率不到10%，完全正常。然后通过jstat -gc查看fullGC频率，也完全正常。  想看下GC日志发现feixia没加gc日志相关的jvm参数。 添加-XX:+PrintGCDetails  -Xloggc:XXX.log  -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC，重启，看下GC日志，GC发生前后的堆信息也完全正常。 

没线索了 只能添加-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=java_oom_dump.hprof 将oom时的heap space dump下来。

等待OOM再次发生。

几分钟后 OOM又发生了  但是没有找到java_oom_dump.hprof  问题很明确了  如果是java heap space报的OOM 那么dump文件不可能不存在。所以怀疑是native heap报的OOM。

看日志中的com.alibaba.com.caucho.hessian.io.JavaDeserializer.instantiate  可以联想到Dubbo使用的netty。 netty会创建大量的DirectByteBuffer占用直接内存。 而飞侠并没有设置-XX:MaxDirectMemorySize，可知直接内存只有默认的64M。 调大MaxDirectMemorySize 等待OOM的再次发生

等待的过程中， big uncle the smart感觉可能是dubbo将其他机器的异常信息抛到了feixia。于是查看re，10bei等机器， 发现re的堆内存使用率到了99%，相当可疑了。然后看下re的fullGC次数  一天里面竟然高达近5000次。。。而re日志确实也有OOM的错误存在。把re的xmx调成1G 问题解决。

总结下： 使用Dubbo等类似服务的情况下，除了排查本机的内存泄漏以外，还需要考虑整个调用链的内存泄漏情况。