记一次使用OkHttpClient大量请求导致SocketTimeoutException再到OutOfMemoryError的问题

需求:因为做一个pc资讯站点,服务端需要主动缓存,所以写了一个调度每10分钟更新热点数据的页面缓存

场景:本地/开发/测试 环境的时候,因为主动缓存的html文件比较少,没有发现这个问题,功能上线后看到项目启动正常,测试通过后,就没管正式版服务器了,没想到凌晨的时候服务器宕机,提示OOM异常

bug复现:线上需要缓存的文件上万条,调度每次使用单线程的方式,主动发出请求内网访问我们的站点,触发生成更新缓存的动作

OOM之前出现了大量的连接超时

ERROR 2020-06-01 09:44:13,918 [schedule-pool-3] c.x.u.h.MyHttpClient.get 142 :java.net.SocketTimeoutException: timeout

大量连接超时后就出现了OOM

ERROR 2020-06-01 09:51:52,527 [catalina-exec-18] o.s.b.w.s.s.ErrorPageFilter.forwardToErrorPage 183 :Forwarding to error page from request [/videos/short/0123168.html] due to exception [unable to create new native thread]
java.lang.OutOfMemoryError: unable to create new native thread
        at java.lang.Thread.start0(Native Method)
        at java.lang.Thread.start(Thread.java:717)
        at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:957)
        at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1378)
        at okhttp3.ConnectionPool.put(ConnectionPool.java:135)
        at okhttp3.OkHttpClient$1.put(OkHttpClient.java:106)
        at okhttp3.internal.http.StreamAllocation.findConnection(StreamAllocation.java:182)
        at okhttp3.internal.http.StreamAllocation.findHealthyConnection(StreamAllocation.java:123)
        at okhttp3.internal.http.StreamAllocation.newStream(StreamAllocation.java:93)
        at okhttp3.internal.http.HttpEngine.connect(HttpEngine.java:296)
        at okhttp3.internal.http.HttpEngine.sendRequest(HttpEngine.java:248)
        at okhttp3.RealCall.getResponse(RealCall.java:243)
        at okhttp3.RealCall$ApplicationInterceptorChain.proceed(RealCall.java:201)
        at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:163)
        at okhttp3.RealCall.execute(RealCall.java:57)
        at com.xmz1.util.http.MyHttpClient.get(MyHttpClient.java:113)
        at com.xmz1.util.request.RequestUtil.getData(RequestUtil.java:143)
        at com.xmz1.util.request.RequestUtil.getDTO(RequestUtil.java:55)
        at com.qiuzhang.jserver.mobile.service.video.impl.ShortVideoServiceImpl.getDetail(ShortVideoServiceImpl.java:69)
        at com.qiuzhang.jserver.mobile.controller.video.VideoController.getDetail(VideoController.java:217)
        at sun.reflect.GeneratedMethodAccessor187.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
        at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
        at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)
        at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:893)
        at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:798)
        at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
        at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
        at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
        at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:634)
        at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at com.qiuzhang.jserver.mobile.conf.LogCostFilter.doFilter(LogCostFilter.java:43)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:176)
        at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145)
        at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92)
        at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:394)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:94)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.boot.web.servlet.support.ErrorPageFilter.doFilter(ErrorPageFilter.java:128)
        at org.springframework.boot.web.servlet.support.ErrorPageFilter.access$000(ErrorPageFilter.java:66)
        at org.springframework.boot.web.servlet.support.ErrorPageFilter$1.doFilterInternal(ErrorPageFilter.java:103)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
        at org.springframework.boot.web.servlet.support.ErrorPageFilter.doFilter(ErrorPageFilter.java:121)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:526)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
        at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:678)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408)
        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:860)
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1587)
        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.lang.Thread.run(Thread.java:748)
View Code

1、服务器配置上jmx参数,通过jconsole排查

配置了2台tomcat,其中项目启动后可以发现线程数和堆空间一直飙升,其中一台的数据可以感觉出线程数5分钟下降一次

一开始以为是连接太多导致所以修改了连接超时时间(connectTimeout、readTimeout)

结果发上去观察一段时间后还是没用

于是只好上网找答案,发现网上有人说是OkHttpClien源码中设定keepAlive时间为5分钟,瞬间恍然大悟

晚上给的解决方案:

在短时间内发起了大量网络连接,每个是一个线程,而且每个都默认保存5分钟,很快线程数就超标了。
考虑到我的每次请求都只是主动触发更新缓存动作,所以我修改了ConnectionPool的keepAliveDuration时间,让每次连接10后就关闭。

 

修改后发(11点发布),ok,解决问题!线程数不会在狂飙了,堆空间还要继续排查一下

 

堆空间排插

使用 java 自带的 jvisualvm

 

 

 

 使用 jconsle 的配置就可以直接连接上了,可以看出来堆空间一直居高不下

 

我们导出堆文件,等待一段时间后,从远程服务器上导入到 visualVM 

 

 

 

 点击第一个实例数量最多的可以看到,是我们页面缓存数据,ok 找到问题,然后就可以解决了,

这里我的解决方法是重写了ConcurrentLRUHashMap 方法限制了 map 的最大值

 

 

 

 

 

 

 

 

参考资料:https://blog.csdn.net/tianyaleixiaowu/article/details/78811488

posted @ 2020-06-01 11:55  oldboyooxx  阅读(5631)  评论(0编辑  收藏  举报