记一次CPU飙升的问题排查

1.背景

通过公司监控工具监控，发现公司某个应用cpu利用率达到120%，也就是说这个应用自己单独占用一个cpu使用，为何占用这么高？让我们一起排查一下

2.开始排查

(1) 第一步获取cpu过高应用的进程信息 (top 命令监控)

(2)通过进程获取占用cpu过高的线程（Top -H -p ）

(3)通过jstack命令导出线程的堆栈信息

"http-bio-7051-exec-28" #33168 daemon prio=5 os_prio=0 tid=0x00007fe343f77000 nid=0xaa1 runnable [0x00007fe329287000]
   java.lang.Thread.State: RUNNABLE
    at java.lang.StringBuilder.append(StringBuilder.java:214)
    at sun.util.calendar.CalendarUtils.sprintf0d(CalendarUtils.java:171)
    at java.util.Date.toString(Date.java:1040)
    at java.lang.String.valueOf(String.java:2994)
    at java.lang.StringBuilder.append(StringBuilder.java:131)
    at com.jiuyescm.oms.wm.odo.action.service.impl.CommonOmsOrderSendAction.buildAppointKey(CommonOmsOrderSendAction.java:72)
    at com.jiuyescm.oms.wm.odo.controller.OmsDo2BController.queryStorage(OmsDo2BController.java:1007)
    at sun.reflect.GeneratedMethodAccessor2011.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.bstek.dorado.data.method.MethodAutoMatchingUtils.invokeMethod(MethodAutoMatchingUtils.java:602)
    at com.bstek.dorado.data.method.MethodAutoMatchingUtils.invokeMethod(MethodAutoMatchingUtils.java:695)
    at com.bstek.dorado.data.provider.manager.DataProviderInterceptorInvoker.invokeInterceptorByParamType(DataProviderInterceptorInvoker.java:542)
    at com.bstek.dorado.data.provider.manager.DataProviderInterceptorInvoker.invoke(DataProviderInterceptorInvoker.java:157)
    at com.bstek.dorado.util.proxy.ChainedMethodInvocation.proceed(ChainedMethodInvocation.java:73)
    at com.bstek.dorado.data.provider.DataProviderGetResultMethodInterceptor.invokeGetResult(DataProviderGetResultMethodInterceptor.java:29)
    at com.bstek.dorado.data.provider.AbstractDataProviderGetResultMethodInterceptor.invoke(AbstractDataProviderGetResultMethodInterceptor.java:55)
    at com.bstek.dorado.util.proxy.MethodInterceptorDispatcher.invoke(MethodInterceptorDispatcher.java:241)
    at com.bstek.dorado.data.provider.DirectDataProvider_$$_jvst349_17.getResult(DirectDataProvider_$$_jvst349_17.java)
    at com.bstek.dorado.view.service.LoadDataServiceProcessor.doExecute(LoadDataServiceProcessor.java:258)
    at com.bstek.dorado.view.service.DataServiceProcessorSupport.execute(DataServiceProcessorSupport.java:133)
    at com.bstek.dorado.view.resolver.ViewServiceInvoker.invoke(ViewServiceInvoker.java:32)
    at com.bstek.dorado.view.resolver.ViewServiceInvoker_$$_jvst349_16._d5invoke(ViewServiceInvoker_$$_jvst349_16.java)
    at sun.reflect.GeneratedMethodAccessor216.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.bstek.dorado.util.proxy.MethodInterceptorDispatcher$FinalJavassistMethodInterceptor.invoke(MethodInterceptorDispatcher.java:96)
    at com.bstek.dorado.util.proxy.ChainedMethodInvocation.proceed(ChainedMethodInvocation.java:73)
    at com.bstek.dorado.util.proxy.MethodInterceptorDispatcher$FinalAopallianceMethodInterceptor.invoke(MethodInterceptorDispatcher.java:67)
    at com.bstek.dorado.util.proxy.ChainedMethodInvocation.proceed(ChainedMethodInvocation.java:73)
    at com.jiuyescm.cfm.dorado.interceptor.SessionValidationRemoteServiceMethodInterceptor.invoke(SessionValidationRemoteServiceMethodInterceptor.java:33)
    at com.bstek.dorado.view.service.AbstractRemoteServiceMethodInterceptor.invoke(AbstractRemoteServiceMethodInterceptor.java:30)
    at com.bstek.dorado.util.proxy.ChainedMethodInvocation.proceed(ChainedMethodInvocation.java:73)
    at com.bstek.bdf2.core.exception.interceptor.AjaxMethodInterceptor.invoke(AjaxMethodInterceptor.java:26)
    at com.bstek.dorado.util.proxy.MethodInterceptorDispatcher.invoke(MethodInterceptorDispatcher.java:170)
    at com.bstek.dorado.util.proxy.MethodInterceptorDispatcher.invoke(MethodInterceptorDispatcher.java:241)
    at com.bstek.dorado.view.resolver.ViewServiceInvoker_$$_jvst349_16.invoke(ViewServiceInvoker_$$_jvst349_16.java)
    at com.bstek.dorado.view.resolver.ViewServiceResolver.processTask(ViewServiceResolver.java:154)
    at com.bstek.dorado.view.resolver.ViewServiceResolver.execute(ViewServiceResolver.java:244)
    at com.bstek.dorado.web.resolver.AbstractTextualResolver.doHandleRequest(AbstractTextualResolver.java:128)
    at com.bstek.dorado.web.resolver.WebContextSupportedController.handleRequestInternal(WebContextSupportedController.java:70)
    at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:154)
    at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:50)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:945)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:876)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:931)
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:833)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:650)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:807)
    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 com.alibaba.druid.support.http.WebStatFilter.doFilter(WebStatFilter.java:123)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:108)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at com.bstek.bdf2.core.security.filter.ControllerFilter.doFilter(ControllerFilter.java:64)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.rememberme.RememberMeAuthenticationFilter.doFilter(RememberMeAuthenticationFilter.java:146)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:54)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilter(BasicAuthenticationFilter.java:150)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:183)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:183)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.jasig.cas.client.session.SingleSignOutFilter.doFilter(SingleSignOutFilter.java:100)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at com.bstek.bdf2.core.security.filter.PreAuthenticatedProcessingFilter.doFilter(PreAuthenticatedProcessingFilter.java:41)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:105)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.session.ConcurrentSessionFilter.doFilter(ConcurrentSessionFilter.java:125)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at com.bstek.bdf2.core.security.filter.ContextFilter.doFilter(ContextFilter.java:36)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192)
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261)
    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:88)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:108)
    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:219)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
    at com.r.tomcat.session.management.RequestSessionHandlerValve.invoke(RequestSessionHandlerValve.java:30)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:962)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1115)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
    - locked <0x0000000724439528> (a org.apache.tomcat.util.net.SocketWrapper)
    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)

从以上日志中找出最魁祸首

at java.lang.StringBuilder.append(StringBuilder.java:214)
	at sun.util.calendar.CalendarUtils.sprintf0d(CalendarUtils.java:171)
	at java.util.Date.toString(Date.java:1040)
	at java.lang.String.valueOf(String.java:2994)
	at java.lang.StringBuilder.append(StringBuilder.java:131)
	at com.jiuyescm.oms.wm.odo.action.service.impl.CommonOmsOrderSendAction.buildAppointKey(CommonOmsOrderSendAction.java:72)
	at com.jiuyescm.oms.wm.odo.controller.OmsDo2BController.queryStorage(OmsDo2BController.java:1007)

(4)结合代码寻找真相

3.总结

跟我们的堆栈完全可以对应的上，性能耗费在循环调用字符串拼接这里。在这里要说一下字符串使用操作符"+"拼接的问题，如果你用”+”来连接固定长度的字符串，在性能上会有问题，但是如果你是在循环中来”+”多个串的话，性能将指数倍的下降。假设有一个字符串，我们将对这个字符串做大量循环拼接操作，使用”+”的话将得到最低的性能。网上有很多对比的文章随便一找一大把，如果不信自己可以写个demo调用1000次然后看自己cpu的情况。