JDK大量占用主机资源的BUG的探讨与分析

摘要
2019年11月，资产系统使用人员经常反馈系统使用卡顿，页面打开缓慢，各项系统功能经常无法正常使用。而运维人员却经常看到应用服务器主机cpu无故达到90%，严重时直接打到100%直至主机hang死，只能通过重启主机后再拉起中间件节点恢复系统。中间件集群所在的主机基本每天都会出现该情况，严重影响系统稳定运行
问题基本分析
1.在主机cpu过高时，通过top命令查看，使用率过高的进程均为对应的中间件java进程，正常情况下java进程使用率在200%下；出现问题时对于相关java进程使用率会达到5000%以上，从而引发主机服务器cpu使用率过高，直至宕机。至此可以确定出现的问题中间件进程导致，不存在其他的异常服务引发主机异常。
2.进一步检查java进程对应的weblogic中间件节点，发现出现问题的节点均存在共性问题：出现问题前，突发的中间件业务处理能力不足，存在用户请求排队，然后中间件开始大量创建线程，但是线程使用率也在同步飙升。到线程创建到400以上时，由于中间件配置了线程上限400，不在创建新线程，但是线程使用率会飙升到100%左右，然后开始出现持续cpu使用率过高。
3.以较近一次为例，xx.xx.xx.xx主机上监听端口为xx节点，在11月12日16点50分左右收到用户反馈使用缓慢，cpu使用率过高。查看节点运行数据，在16点05分出现用户排队，伴随着线程数达到300+,使用率也达到100%;此后主机cpu使用率开始提升。而正常情况下，节点线程数不超过30。
（如下监控图为采集到的中间件指标，THREADTOTAL 为线程总数，THEEADUSEDPERCENT 为线程使用率， 服务状态down or hang 为服务线程池耗尽，无法采集到服务状态）

4.查看出现问题时的线程执行情况的dump文件，发现大量线程在执行业务上的请求服务，详情如下：

5.在出现问题时，有近200个线程在执行该服务

6.该类任务实际的请求内容如下:
“[ACTIVE] ExecuteThread: ‘392’ for queue: ‘weblogic.kernel.Default (self-tuning)’” daemon prio=10 tid=0x00007ff32c2cd000 nid=0x960b runnable [0x00007fee705c2000]
java.lang.Thread.State: RUNNABLE
at org.springframework.web.util.UriUtils.decode(UriUtils.java:351)
at org.springframework.web.util.UrlPathHelper.decodeInternal(UrlPathHelper.java:406)
at org.springframework.web.util.UrlPathHelper.decodeRequestString(UrlPathHelper.java:397)
at org.springframework.web.util.UrlPathHelper.getContextPath(UrlPathHelper.java:286)
at org.springframework.web.util.UrlPathHelper.getPathWithinApplication(UrlPathHelper.java:199)
at org.springframework.web.util.UrlPathHelper.getPathWithinServletMapping(UrlPathHelper.java:175)
at org.springframework.web.util.UrlPathHelper.getLookupPathForRequest(UrlPathHelper.java:154)
at org.springframework.web.servlet.mvc.condition.PatternsRequestCondition.getMatchingCondition(PatternsRequestCondition.java:212)
at org.springframework.web.servlet.mvc.method.RequestMappingInfo.getMatchingCondition(RequestMappingInfo.java:181)
at org.springframework.web.servlet.mvc.method.RequestMappingInfoHandlerMapping.getMatchingMapping(RequestMappingInfoHandlerMapping.java:72)
at org.springframework.web.servlet.mvc.method.RequestMappingInfoHandlerMapping.getMatchingMapping(RequestMappingInfoHandlerMapping.java:54)
at org.springframework.web.servlet.handler.AbstractHandlerMethodMapping.addMatchingMappings(AbstractHandlerMethodMapping.java:289)
at org.springframework.web.servlet.handler.AbstractHandlerMethodMapping.lookupHandlerMethod(AbstractHandlerMethodMapping.java:256)
at org.springframework.web.servlet.handler.AbstractHandlerMethodMapping.getHandlerInternal(AbstractHandlerMethodMapping.java:223)
at org.springframework.web.servlet.handler.AbstractHandlerMethodMapping.getHandlerInternal(AbstractHandlerMethodMapping.java:56)
at org.springframework.web.servlet.handler.AbstractHandlerMapping.getHandler(AbstractHandlerMapping.java:298)
at org.springframework.web.servlet.DispatcherServlet.getHandler(DispatcherServlet.java:1091)
at org.springframework.web.servlet.DispatcherServlet.getHandler(DispatcherServlet.java:1076)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:896)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:936)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:827)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:812)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:844)
at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:280) at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:254)
at weblogic.servlet.internal.StubSecurityHelper.invokeServlet(StubSecurityHelper.java:136)
at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:341)
at weblogic.servlet.internal.TailFilter.doFilter(TailFilter.java:25)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:198)
at net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:176)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at com.comtop.top.sys.login.action.SessionFilter.doFilter(SessionFilter.java:177)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at com.comtop.sproc.system.filter.SprocRequestFilter.doFilter(SprocRequestFilter.java:62)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at com.comtop.bizp.security.framework.csrf.filter.CsrfGuardFilter.doFilter(CsrfGuardFilter.java:114)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at com.comtop.top.component.app.sna.SessionShareFilter.doFilter(SessionShareFilter.java:166)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at com.comtop.bizp.security.framework.http.filter.HttpSecurityFilter.doFilterInneral(HttpSecurityFilter.java:203)
at com.comtop.bizp.security.framework.http.filter.HttpSecurityFilter.doFilter(HttpSecurityFilter.java:77)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at weblogic.servlet.internal.RequestEventsFilter.doFilter(RequestEventsFilter.java:27)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:79)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.wrapRun(WebAppServletContext.java:3388) at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3354)
at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:120)
at weblogic.servlet.provider.WlsSubjectHandle.run(WlsSubjectHandle.java:57)
at weblogic.servlet.internal.WebAppServletContext.doSecuredExecute(WebAppServletContext.java:2238)
at weblogic.servlet.internal.WebAppServletContext.securedExecute(WebAppServletContext.java:2154)
at weblogic.servlet.internal.WebAppServletContext.execute(WebAppServletContext.java:2132)
at weblogic.servlet.internal.ServletRequestImpl.run(ServletRequestImpl.java:1564)
at weblogic.servlet.provider.ContainerSupportProviderImpl$WlsRequestExecutor.run(ContainerSupportProviderImpl.java:255)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:312)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:264)

7.出现问题为org.springframework.web.util.UriUtils.decode(UriUtils.java:351)，但Spring源代码显示，并没有Java代码在行351附近执行循环
[https://github.com/spring-projects/spring-framework/blob/v3.2.4.RELEASE/spring-web/src/main/java/org/springframework/web/util/UriUtils.java
335   /**
336    * Decodes the given encoded source String into an URI. Based on the following rules:
337    *

338    *
• Alphanumeric characters {@code “a”} through {@code “z”}, {@code “A”} through {@code “Z”}, and
  339    * {@code “0”} through {@code “9”} stay the same.

340    *
• Special characters {@code “-”}, {@code “_”}, {@code “.”}, and {@code “*”} stay the same.

341    *
• A sequence “{@code %xy}” is interpreted as a hexadecimal representation of the character.

342    *

343    * @param source the source string
344    * @param encoding the encoding
345    * @return the decoded URI
346    * @throws IllegalArgumentException when the given source contains invalid encoded sequences
347    * @throws UnsupportedEncodingException when the given encoding parameter is not supported
348    * @see java.net.URLDecoder#decode(String, String)
349    */
350   public static String decode(String source, String encoding) throws UnsupportedEncodingException {
351     Assert.notNull(source, “‘source’ must not be null”);
352     Assert.hasLength(encoding, “‘encoding’ must not be empty”);
353     int length = source.length();
354     ByteArrayOutputStream bos = new ByteArrayOutputStream(length);
355     boolean changed = false;

8.问题重现时通过 pstack / jstack -m 收集Jdk C++代码栈，显示此高CPU代码来自Jdk内部:
Thread 441 (Thread 0x7f53fe40f700 (LWP 6031)):
#0 0x0000003b51e0b43c in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1 0x00007f559d15b0b3 in os::PlatformEvent::park() () from <JAVA_HOME>/jre/lib/amd64/server/libjvm.so
#2 0x00007f559d122188 in Monitor::ILock(Thread*) () from <JAVA_HOME>/jre/lib/amd64/server/libjvm.so
#3 0x00007f559d1223bf in Monitor::lock_without_safepoint_check() () from <JAVA_HOME>/jre/lib/amd64/server/libjvm.so
#4 0x00007f559cd64e33 in CodeCache::largest_free_block() () from <JAVA_HOME>/jre/lib/amd64/server/libjvm.so
#5 0x00007f559cd8fae5 in CompileBroker::compile_method(methodHandle, int, int, methodHandle, int, char const*, Thread*) () from <JAVA_HOME>/jre/lib/amd64/server/libjvm.so
#6 0x00007f559cd7b9c9 in SimpleCompPolicy::method_back_branch_event(methodHandle, int, JavaThread*) () from <JAVA_HOME>/jre/lib/amd64/server/libjvm.so
#7 0x00007f559cd7bd03 in NonTieredCompPolicy::event(methodHandle, methodHandle, int, int, CompLevel, nmethod*, JavaThread*) () from <JAVA_HOME>/jre/lib/amd64/server/libjvm.so
#8 0x00007f559cf38097 in InterpreterRuntime::frequency_counter_overflow_inner(JavaThread*, unsigned char*) () from <JAVA_HOME>/jre/lib/amd64/server/libjvm.so
#9 0x00007f559cf3c026 in InterpreterRuntime::frequency_counter_overflow(JavaThread*, unsigned char*) () from <JAVA_HOME>/jre/lib/amd64/server/libjvm.so
…

9.自此，可以确定为JDK导致的系统问题。查看相关资料及官方资料，该方法确认确实会引发cpu使用率过高，org.springframework.web.util.UriUtils.decode 类异常为jdk1.7 低版本下的一个BUG，需升级到小版本121+ 以上；
10.查看中间件异常节点的jdk信息，确认版本为jdk1.7.0_79，即确认小版本号为79 存在该bug。见下图1 和图2

 图1 为服务器上中间件进程信息

图 2为服务器上中间件用的jdk的版本信息
问题基本定位
1.这是Jdk的已知问题，参阅 https://bugs.openjdk.java.net/browse/JDK-8006952
2.建议系统升级到jdk1.7的高版本，如121以后版本。