從頻繁告警到平穩發佈：服務冷啓動 CPU 風暴優化實踐详情 - 後端,服務器,性能優化,arthas,cpu過高 vivo互聯網技術日志

作者：vivo 互聯網服務器團隊- Xie Xiaopeng

本文針對服務啓動後幾分鐘內 CPU 持續處於高峯狀態的問題，提出了自己的分析思路與解決方案。最終線上效果比較顯著，成功解決了每次發版過程中頻繁告警、業務受損以及用户體驗不佳的問題，為服務的高可用性增添了一道重要保障。本文的重點在於問題的發現、分析及解決思路。對於 CPU 相關的問題，火焰圖和 Arthas 是非常有效的工具，建議大家在遇到類似情況時，積極嘗試使用這些工具進行排查和解決。

1分鐘看圖抓住核心觀點👇

一、背景

最近我們的服務在發佈或重啓時頻繁產生告警，這種情況從發版開始一直持續到發版結束後幾分鐘內，規律非常明顯。

起初，我們懷疑是流量接入過快導致了此問題。在服務啓動後，CICD會檢測 check.do 接口，以確認服務是否準備就緒。我們推測，check.do 接口成功返回後，CICD立即接入線上流量，這才引發非常多的異常告警。

為了解決這一問題，我們與運維團隊進行了溝通，決定將流量接入的時機延遲30秒。延遲30秒後問題還是沒有得到解決，告警依然持續不斷。

二、問題表象

以線上某一台機器為例，它的啓動步驟如下：

2024-09-0416:09:50 INFO - 啓動應用 ，執行成功。
2024-09-0416:12:36 WARN - 檢查接口：check.do，響應結果：ok
2024-09-0416:13:07 INFO - 啓動後等待時間（秒）：30
2024-09-0416:13:07 INFO - 恢復Dubbo流量成功
2024-09-0416:13:39 INFO - 恢復HTTP流量成功！

2.1 Dubbo 接口超時嚴重

恢復HTTP流量後，很多調用下游的Dubbo接口發生超時，以畫像接口為例，告警開始時間為：2024-09-04 16:14:07.251，結束時間為：2024-09-04 16:17:31.224，期間超時請求數為：578。

2.2 HTTP 接口超時嚴重

大部分HTTP接口也超時嚴重，P95響應時間從正常的幾十毫秒飆升至幾秒鐘，16:17:30後逐漸恢復至正常水平。

2.3 CPU異常

服務發佈前後CPU表現異常，啓動過程CPU存在突刺，接入線上流量後一段時間內CPU使用率將近100%，16:17:30後逐步下降，恢復到正常水平。下圖為服務發佈前後CPU的使用率截圖。

服務發佈前後CPU使用率

2.4 Runnable、Blocked線程突刺

下圖為線程數的相關監控指標，我們可以看到：在服務發佈期間，活躍線程數持續增加，啓動期間線程劇增，接入線上流量後線程逐步增加，16:17分之後趨於平穩，其中16:12:30-16:12:40期間活躍線程數從249增加到1026（啓動期間業務側有很多任務均會創建線程池，不影響本次分析）

Runnable線程數與Blocked線程數也有突刺，時間是16:13:30-16:17:30，與接入HTTP流量時間相符，與CPU突刺時間完全一致。

Runnable線程

Blocked線程

2.5 老年代上漲快

在查看GC老年代內存使用情況時，我們發現啓動後未接入流量時，老年代內存為985.84MB。而在接入流量後，截止到16:17:30，內存使用量已經上升至1.36GB，期間老年代的內存增長速度較快。

2.6 下游依賴正常

從上游視角查看下游依賴的情況，隨便挑一個Dubbo接口超時嚴重的下游依賴，我們查看一下服務的監控指標，發現服務的請求量在啓動期間有突刺（業務側在啓動期間會主動發起調用，刷新一些緩存，正常現象），啓動後流量幾乎沒變，但是成功率卻有明顯下降，且最大響應時間顯著增加。

上游視角

但是從下游視角再看服務相關指標，接口成功率正常，且最大響應時間也正常，説明不是下游服務的問題。

下游視角

三、原因初步判斷

從監控數據來看，在線上流量恢復後，我們的服務當前擁有的線程數不足以處理這些業務請求，因此導致系統大量創建業務線程。由於CPU的時間片調度策略，線程之間會頻繁發生上下文切換，從而引發CPU負載的劇烈上升，甚至達到飽和狀態。

因此通過初步分析，我們得到以下結論：

引起CPU飆升的原因主要是由於過多的Runnable狀態線程以及頻繁的線程上下文切換所導致。我們觀察到系統中存在大量已啓動的線程，這些線程的狀態在Blocked（鎖等待、IO等待等）和Runnable之間不斷變化。當鎖競爭激烈時，CPU飆升的現象就很容易出現。

四、嘗試初步解決

4.1 流量逐步灰度

既然我們懷疑是流量全部接入後，線程不足導致的問題，因此需要嘗試流量緩慢接入是否能解決這個問題。

我們與運維同學線上隨機找了一台機器進行流量灰度實驗，具體時間節點如下：

2024-09-0509:55:21 啓動成功
2024-09-0509:56:17 灰度1%
2024-09-0509:57:19 灰度5%
2024-09-0509:58:31 灰度44%
2024-09-0510:03:51 開始操作全量
2024-09-0510:08:10 全量完成

再觀察一下相關指標，我們發現各項指標均正常：CPU使用率不再有突刺，Runnable線程數和Blocked線程數也保持穩定，之前的負載尖峯現象已消失。同時異常超時的日誌記錄也不再出現，老年代內存的增長速度緩慢，HTTP接口、Dubbo接口P95響應時間正常。由此可見，流量灰度可以解決該問題。

① CPU使用率情況如下：

CPU使用率

② 線程指標情況如下：

Runnable線程

Blocked線程

4.2 緩存預熱

在前文中提到，接入線上流量後，老年代的內存增長較快，因此我們推測在服務啓動初期，由於尚未加載相關的緩存數據，當大量請求涌入時，未命中緩存的情況頻繁發生，這迫使系統不斷向下遊請求以加載緩存，從而導致接口響應變慢。為此，我們需要驗證預熱緩存的有效性，以確定是否能夠改善這一問題。

緩存預熱的主要作用和目的如下：

提高緩存命中率：通過預先加載熱點數據，能夠顯著提升緩存的命中率，從而減少對後端數據源（如數據庫）的訪問，降低系統負載。
保持服務性能穩定：在服務啓動或緩存失效之後，緩存預熱可以有效防止請求對後端數據源施加突發壓力，從而確保服務性能的穩定性。
優化用户體驗：由於熱點數據已被預先加載到緩存中，用户在請求這些數據時能夠獲得更快的響應速度，從而顯著提升用户體驗。

方案如下：

我們將梳理本地緩存信息，根據訪問量和緩存大小區分數據的重要程度，定期將重要的緩存信息刷新至Redis中。在服務啓動後，未接入線上流量之前，我們將優先從Redis中進行數據的預加載。通過這一措施，確保系統在高流量環境下的穩定性和性能。

實驗結果顯示，增加緩存預熱後，問題並未得到有效解決，表現差異微乎其微。

僅僅預熱重要緩存無法解決當前問題。系統在啓動時需要預熱的內容相對較多，同時各類中間件也有自身的緩存需要預熱。因此僅預熱業務自定義的內存緩存，效果非常有限。

回顧之前的原因分析，我們僅僅關注了表面現象，如CPU的上漲和線程數的增加，而未深入挖掘問題的本質。我們需要探討線程數為何上升、CPU為何飆升，接下來將進行更深入的分析，以找出問題的根本原因。

五、分析問題

5.1 初步分析堆棧與CPU火焰圖

我們選擇了一台線上機器進行服務重啓，並在接入線上流量後的幾分鐘內導出了程序的線程堆棧信息，進行分析：

Runnable 線程數顯著增多，佔比達到29%，通常情況下，Runnable線程數約為70個，而此時卻激增至462個；
進一步查看 Runnable 線程，發現大部分線程為 catalina-exec 線程（380個），這是Tomcat用於執行Spring MVC應用中Servlet請求的線程。正常情況下，這類線程的數量僅有幾個；
在這些Runnable線程中，有201個線程均被阻塞在 org.springframework.beans.PropertyMatches.calculateStringDistance(PropertyMatches.java:170) 這個方法上，我們需要進一步分析其原因。

看了堆棧信息後，應該有個疑問：為什麼啓動了這麼多的tomcat線程？

我們推測原因在於服務剛啓動時，系統尚未加載任何緩存，所有數據都需要進行首次加載。在這種情況下，服務無法快速響應用户請求，導致接口的響應時間（RT）顯著上升。在相同的QPS的情況下，為了處理不斷增加的業務請求，系統不得不創建更多的Tomcat線程。

接下來我們接入Arthas工具，採集CPU火焰圖以進行深入分析，CPU火焰圖如下：

異常CPU火焰圖

分析結果顯示，CPU耗時主要集中在calculateStringDistance方法，這與我們之前的線程堆棧分析結果一致。在服務啓動時的CPU火焰圖中，calculateStringDistance方法的CPU消耗佔比高達16.68% + 39.09% + 8.38% = 64.15%，整體CPU使用率接近97%。

經過一段時間的運行後，再觀察正常情況下的CPU火焰圖，calculateStringDistance方法的CPU消耗佔比降至3.39% + 8.57% + 1.78% = 13.74%，整體CPU使用率則徘徊在25%至42%之間。

這一變化表明，隨着系統的穩定運行，CPU負載逐漸得到緩解，但calculateStringDistance方法仍然是性能瓶頸之一。它雖然不是CPU使用率飆升的根因，但它在服務啓動後進一步加劇了CPU的負載。

5.1.1 calculateStringDistance加劇CPU暴漲

在相同QPS的情況下，為什麼在服務啓動後的幾分鐘內calculateStringDistance方法消耗的CPU資源嚴重，而經過一段時間後，這一消耗又有所減小？

前文的分析指出，服務剛啓動時，流量瞬間恢復，導致系統需要創建大量的業務線程。這些線程在處理請求時，都會執行calculateStringDistance方法。由於該方法本身的計算開銷較大，且併發執行的線程數量越多，CPU的消耗就會越顯著。因此在服務啓動初期，CPU的負載急劇上升。隨着運行時間的延長，業務線程的創建和執行也趨於平衡，併發執行的線程數量大大減小，CPU消耗也隨之減小。

5.1.2 calculateStringDistance源碼分析

calculateStringDistance方法的功能是根據Levenshtein算法計算給定兩個字符串之間的距離或相似度。通過分析其源代碼，我們可以發現，在比較兩個字符串時，該方法採用了嵌套的for循環結構。在這些循環中，涉及到length、chatAt和Math.min函數的調用，這使得該方法的計算複雜度相對較高。調用量越大，CPU消耗就會越嚴重。根據CPU火焰圖的分析，發現這三個函數的CPU消耗佔比與calculateStringDistance方法的CPU消耗佔比之間的比例高達78%。因此在調用該方法時要小心，在高併發場景下，該方法很有可能成為系統的性能瓶頸，對CPU產生影響。

private static int calculateStringDistance(String s1, String s2){
  if (s1.isEmpty()) {
    return s2.length();
  }
  if (s2.isEmpty()) {
    return s1.length();
  }

  int[][] d = newint[s1.length() + 1][s2.length() + 1];
  for (int i = 0; i <= s1.length(); i++) {
    d[i][0] = i;
  }
  for (int j = 0; j <= s2.length(); j++) {
    d[0][j] = j;
  }

  for (int i = 1; i <= s1.length(); i++) {
    char c1 = s1.charAt(i - 1);
    for (int j = 1; j <= s2.length(); j++) {
      int cost;
      char c2 = s2.charAt(j - 1);
      if (c1 == c2) {
        cost = 0;
      }
      else {
        cost = 1;
      }
      d[i][j] = Math.min(Math.min(d[i - 1][j] + 1, d[i][j - 1] + 1), d[i - 1][j - 1] + cost);
    }
  }

  return d[s1.length()][s2.length()];
}
}

calculateStringDistance方法是如何觸發的？通過查詢堆棧信息並查看源代碼，我們發現這是Spring框架在解析請求參數並注入屬性的過程中所觸發的。堆棧信息如下，從上到下逐步分析堆棧，我們重點分析setPropertyValues和createNotWritable-

PropertyException這兩個方法。

"catalina-exec-485" #975 daemon prio=5 os_prio=0 tid=0x00007f50e825f000 nid=0x3375 runnable [0x00007f5043ea4000]
   java.lang.Thread.State: RUNNABLE
      at org.springframework.beans.PropertyMatches.calculateStringDistance(PropertyMatches.java:170)
      at org.springframework.beans.PropertyMatches.access$100(PropertyMatches.java:44)
      at org.springframework.beans.PropertyMatches$BeanPropertyMatches.calculateMatches(PropertyMatches.java:208)
      at org.springframework.beans.PropertyMatches$BeanPropertyMatches.<init>(PropertyMatches.java:193)
      at org.springframework.beans.PropertyMatches.forProperty(PropertyMatches.java:68)
      at org.springframework.beans.PropertyMatches.forProperty(PropertyMatches.java:58)
      at org.springframework.beans.BeanWrapperImpl.createNotWritablePropertyException(BeanWrapperImpl.java:237)
      at org.springframework.beans.AbstractNestablePropertyAccessor.processLocalProperty(AbstractNestablePropertyAccessor.java:435)
      at org.springframework.beans.AbstractNestablePropertyAccessor.setPropertyValue(AbstractNestablePropertyAccessor.java:290)
      at org.springframework.beans.AbstractNestablePropertyAccessor.setPropertyValue(AbstractNestablePropertyAccessor.java:278)
      at org.springframework.beans.AbstractPropertyAccessor.setPropertyValues(AbstractPropertyAccessor.java:95)
      at org.springframework.validation.DataBinder.applyPropertyValues(DataBinder.java:860)
      at org.springframework.validation.DataBinder.doBind(DataBinder.java:756)
      at org.springframework.web.bind.WebDataBinder.doBind(WebDataBinder.java:192)
      at org.springframework.web.bind.ServletRequestDataBinder.bind(ServletRequestDataBinder.java:106)
      at org.springframework.web.servlet.mvc.method.annotation.ServletModelAttributeMethodProcessor.bindRequestParameters(ServletModelAttributeMethodProcessor.java:152)
      at org.springframework.web.method.annotation.ModelAttributeMethodProcessor.resolveArgument(ModelAttributeMethodProcessor.java:111)
      at org.springframework.web.method.support.HandlerMethodArgumentResolverComposite.resolveArgument(HandlerMethodArgumentResolverComposite.java:121)
      at org.springframework.web.method.support.InvocableHandlerMethod.getMethodArgumentValues(InvocableHandlerMethod.java:158)
      at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest$original$3Q7HrFjh(InvocableHandlerMethod.java:128)
      at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest$original$3Q7HrFjh$accessor$ykGmQRZT(InvocableHandlerMethod.java)
      at org.springframework.web.method.support.InvocableHandlerMethod$auxiliary$Wny4v5BZ.call(Unknown Source)
      at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java)
      at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97)
      at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:849)
      at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:760)
      at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)
      at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967)
      at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901)
      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 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
      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.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
      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.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
      at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:347)
      at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:263)
      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.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:347)
      at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:263)
      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.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
      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$original$Y7IhKDGv(StandardWrapperValve.java:219)
      at org.apache.catalina.core.StandardWrapperValve.invoke$original$Y7IhKDGv$accessor$4IDmuys6(StandardWrapperValve.java)
      at org.apache.catalina.core.StandardWrapperValve$auxiliary$1SL1DIkO.call(Unknown Source)
      at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java)
      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
      at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:494)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
      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:1136)
      at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
      at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1775)
      at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1734)
      - locked <0x000000070f1dc100> (a org.apache.tomcat.util.net.NioChannel)
      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)

先分析setPropertyValues方法，該方法負責將請求中的參數映射到目標對象的屬性上，主要是遍歷屬性列表進行賦值並進行異常統一處理，單個屬性的注入繼續看setPropertyValue方法。

public void setPropertyValues(PropertyValues pvs, boolean ignoreUnknown, boolean ignoreInvalid)
      throws BeansException {
    // 聲明PropertyAccessException集合，保存單個屬性注入時拋出的PropertyAccessException異常
  List<PropertyAccessException> propertyAccessExceptions = null;
    // 獲取屬性列表
  List<PropertyValue> propertyValues = (pvs instanceof MutablePropertyValues ?
      ((MutablePropertyValues) pvs).getPropertyValueList() : Arrays.asList(pvs.getPropertyValues()));
  for (PropertyValue pv : propertyValues) {
    try {
      // 單個屬性的注入，注意：此方法可能會引發任意的BeansException，如果存在嚴重故障（例如沒有匹配的字段），則不會在此處捕獲該異常。我們可以嘗試只處理不太嚴重的異常。
      setPropertyValue(pv);
    }
    catch (NotWritablePropertyException ex) {
            // 默認是true，忽略未知屬性，因此不會拋異常
      if (!ignoreUnknown) {
        throw ex;
      }
      // Otherwise, just ignore it and continue...
    }
    catch (NullValueInNestedPathException ex) {
      if (!ignoreInvalid) {
        throw ex;
      }
      // Otherwise, just ignore it and continue...
    }
    catch (PropertyAccessException ex) {
      if (propertyAccessExceptions == null) {
        propertyAccessExceptions = new LinkedList<PropertyAccessException>();
      }
      propertyAccessExceptions.add(ex);
    }
  }

  // 如果 propertyAccessExceptions 不為空，需要整合起來，拋一個複合異常 PropertyBatchUpdateException
  if (propertyAccessExceptions != null) {
    PropertyAccessException[] paeArray =
        propertyAccessExceptions.toArray(new PropertyAccessException[propertyAccessExceptions.size()]);
    thrownew PropertyBatchUpdateException(paeArray);
  }
}

propertyValues 屬性的結構如下，它包含了從上游傳遞過來的所有參數。這些參數被封裝成一個集合，便於後續的處理和注入。

propertyValues 屬性

分析setPropertyValue方法，該方法主要作用是解析屬性值，如果存在嵌套屬性，則遞歸解析設置最終對應的屬性值，方法最後都會調用setPropertyValue(tokens, pv)方法。

public void setPropertyValue(PropertyValue pv) throws BeansException {
  PropertyTokenHolder tokens = (PropertyTokenHolder) pv.resolvedTokens;
  if (tokens == null) {
    String propertyName = pv.getName();
    AbstractNestablePropertyAccessor nestedPa;
    try {
           // 確定給定屬性路徑中的第一個嵌套屬性分隔符，忽略鍵中的點（如 “map[my.key]”）。
         // 當配置的屬性名propertyName中包含'.'這樣字符時，代表需要設置嵌套屬性
       // 如果存在嵌套屬性，Spring會遞歸向下獲取最終設置的屬性，比如：a.b.c，Spring會遞歸調用獲取到b，c是需要設置的屬性
       // 如果沒有嵌套屬性的話。會返回自身
      nestedPa = getPropertyAccessorForPropertyPath(propertyName);
    }
    catch (NotReadablePropertyException ex) {
      thrownew NotWritablePropertyException(getRootClass(), this.nestedPath + propertyName,
          "Nested property in path '" + propertyName + "' does not exist", ex);
    }
        // 將給定的屬性名稱解析為相應的屬性名稱令牌，如果沒有[]，則tokens中的keys為空，且actualName、canonicalName都等於 propertyName 
    tokens = getPropertyNameTokens(getFinalPath(nestedPa, propertyName));
    if (nestedPa == this) {
      pv.getOriginalPropertyValue().resolvedTokens = tokens;
    }
        // 設置屬性
    nestedPa.setPropertyValue(tokens, pv);
  }
  else {
       // 設置屬性
    setPropertyValue(tokens, pv);
  }
}

分析setPropertyValue(tokens, pv)方法，該方法是用來區分數組類型跟非數組類型的，大部分屬性都是非數組類型，我們分析非數組類型方法。

protected void setPropertyValue(PropertyTokenHolder tokens, PropertyValue pv) throws BeansException {
    // 如果屬性中存在[]，説明是數組，則進入該方法
  if (tokens.keys != null) {
    processKeyedProperty(tokens, pv);
  }
  else {
        // 大部分都走這個方法
    processLocalProperty(tokens, pv);
  }
}

processLocalProperty方法的作用就是獲取屬性值，利用反射完成屬性注入。

private void processLocalProperty(PropertyTokenHolder tokens, PropertyValue pv){
    // 獲取屬性對應的 PropertyHandler
  PropertyHandler ph = getLocalPropertyHandler(tokens.actualName);
    // 如果不存在對應的handler 或者 屬性是不可寫的（沒有setter方法）
  if (ph == null || !ph.isWritable()) {
        // 如果屬性是optional類型，則直接返回
    if (pv.isOptional()) {
      if (logger.isDebugEnabled()) {
        logger.debug("Ignoring optional value for property '" + tokens.actualName +
            "' - property not found on bean class [" + getRootClass().getName() + "]");
      }
      return;
    }
    else {
      // 其他情況則拋出不可寫屬性異常，佔用CPU較多的方法由此進入
      throw createNotWritablePropertyException(tokens.canonicalName);
    }
  }

  Object oldValue = null;
  try {
        // 獲取屬性值
    Object originalValue = pv.getValue();
    Object valueToApply = originalValue;
        // 如果需要轉換，則進入此分支
    if (!Boolean.FALSE.equals(pv.conversionNecessary)) {
      // 如果已經完成類型轉換，則直接使用
      if (pv.isConverted()) {
        valueToApply = pv.getConvertedValue();
      }
      else {
        // 如果需要讀取舊值，默認是false && 值可讀（有getter方法）
        if (isExtractOldValueForEditor() && ph.isReadable()) {
          try {
            oldValue = ph.getValue();
          }
          catch (Exception ex) {
            if (ex instanceof PrivilegedActionException) {
              ex = ((PrivilegedActionException) ex).getException();
            }
            if (logger.isDebugEnabled()) {
              logger.debug("Could not read previous value of property '" +
                  this.nestedPath + tokens.canonicalName + "'", ex);
            }
          }
        }
        // 類型轉換
        valueToApply = convertForProperty(
            tokens.canonicalName, oldValue, originalValue, ph.toTypeDescriptor());
      }
      pv.getOriginalPropertyValue().conversionNecessary = (valueToApply != originalValue);
    }
    // 完成屬性注入
    ph.setValue(this.wrappedObject, valueToApply);
  }
  catch (TypeMismatchException ex) {
    throw ex;
  }
  catch (InvocationTargetException ex) {
    PropertyChangeEvent propertyChangeEvent = new PropertyChangeEvent(
        this.rootObject, this.nestedPath + tokens.canonicalName, oldValue, pv.getValue());
    if (ex.getTargetException() instanceof ClassCastException) {
      thrownew TypeMismatchException(propertyChangeEvent, ph.getPropertyType(), ex.getTargetException());
    }
    else {
      Throwable cause = ex.getTargetException();
      if (cause instanceof UndeclaredThrowableException) {
        // May happen e.g. with Groovy-generated methods
        cause = cause.getCause();
      }
      thrownew MethodInvocationException(propertyChangeEvent, cause);
    }
  }
  catch (Exception ex) {
    PropertyChangeEvent pce = new PropertyChangeEvent(
        this.rootObject, this.nestedPath + tokens.canonicalName, oldValue, pv.getValue());
    thrownew MethodInvocationException(pce, ex);
  }
}

在該方法中，我們注意到堆棧信息中createNotWritablePropertyException方法的調用。實際上calculateStringDistance方法的高CPU消耗正是由此引發的。當拋出不可寫屬性異常時，系統會計算字符串的相似度，主要目的是為了向用户提供更友好的提示，幫助他們識別哪些屬性與當前屬性相似，從而判斷是否在傳遞參數時出現了錯誤。

Spring這種設計不僅提升了用户體驗，還降低了因參數錯誤而導致的調試難度。通過提供相似屬性的建議，用户能夠更快速地發現並糾正輸入錯誤，確保請求的正確性。以下為調試過程中的部分提示：

Bean property 'questionValidatorInterface' is not writable or has an invalid setter method. Does the parameter type of the setter match the return type of the getter?
bean property 'users' is not writable or has an invalid setter method. did you mean 'user'?

5.1.3 calculateStringDistance流程總結

結合Spring MVC解析HTTP的請求流程，calculateStringDistance方法的進入流程如下：

解析參數流程

Spring MVC在解析HTTP請求參數時會找到對應的參數解析器，因為我們的項目中大部分都是自定義的複雜對象，因此採用的參數解析器為ServletModelAttributeMethodProcessor。該解析器在數據綁定過程中，會循環遍歷每個參數，通過反射完成屬性注入。但是我們自定義的複雜對象在某些接口下，定義的屬性不合理，導致拋出createNotWritablePropertyException異常。

我們深入分析一下源碼，看看怎樣避免拋出createNotWritablePropertyException異常。

根據源碼，我們發現拋出不可寫屬性異常的條件是（屬性不存在對應的handler 或者屬性不可寫）並且屬性不是optional類型，只要我們保證不滿足這個條件，那麼就可以有效避免拋出該異常。

説明一下這三個條件：

屬性不存在對應的handler 即 request中不存在該屬性。比如請求參數中帶version字段，但是服務端在接受request中並未定義version字段，那麼此處ph == null判斷條件就成立
屬性不可寫，即屬性沒有對應的setter方法
屬性是optional類型，即屬性的數據類型是Optional類型

通過查看業務側的代碼，我們發現請求（request）中的所有屬性都已經定義了相應的 setter 方法，而且不存在optional類型的屬性。因此我們只需要關注請求中是否存在未定義的屬性。

5.1.4 排查大流量及核心接口參數

由於服務提供的接口非常多，因此僅排查流量較高和核心的接口。經過分析，我們發現幾乎所有接口都存在未定義的屬性。

這主要是因為客户端很多參數都是公參，在傳參時會將這些公參全部透傳給服務端，但是服務端並不需要處理所有的參數，因此沒有在request中定義。特別備註：接口若未定義請求參數接收，則不會走上述流程。

5.1.5 解決方案

既然已經明確問題的根源是請求中存在未定義的屬性，那麼接下來我們將針對這一情況進行優化。方案主要有兩個：

在底層請求中加入客户端公參：對所有公參進行接收，確保它們能夠被正確處理。需要注意的是，參數接收將會涉及屬性注入，而屬性注入是通過反射機制實現的。這一過程可能對CPU和接口性能產生影響，因此我們也需要進行實驗，以評估這些參數解析的實際效果。

在filter層針對接口去除相關字段：通過在過濾器層面過濾掉不必要的字段，避免接口中出現未定義的屬性。

最終我們混合兩種方案：對於大部分公共參數，定義到底層request中；對於非公共參數，針對接口進行移除。

我們針對大流量接口及核心接口進行了優化，優化後效果如下：

結論：整體效果顯著，但仍存在一些不足之處。

CPU使用情況：在高峯期重啓應用時，CPU的突發情況明顯減弱，持續時間從5分鐘縮短至1分鐘。同時CPU和Runnable線程數仍會出現小幅波動，但Runnable線程數的波動持續時間已從6分鐘縮減至40秒，波動峯值也由600降低至280。
接口性能：接口的P95和P99耗時均有所降低，其中P95峯值從53秒降至3.4秒，P99峯值從1分50秒降至50秒。此外，響應時間較長的時間段也得到了縮短，持續時間從7分鐘減少到不到2分鐘。
發版及日常運行：在發版期間及日常運行中，CPU峯值普遍降低。與前1天和前7天的平均CPU使用率相比，最大和最小使用率均有所下降，幅度明顯。

① 啓動後CPU使用率情況如下：

CPU使用率

② 線程數情況如下：

Runnable線程數

Blocked線程數

③ 接口響應時間情況如下：

接口響應時間

④ 運行一段時間後，CPU使用率情況如下：

CPU使用率

5.2 優化後再次分析CPU火焰圖

優化後效果雖然好了很多，但是CPU和Runnable線程數仍會出現小幅波動，接口的響應時間在1分鐘內仍有上漲。這是我們接下來要繼續優化的目標。

5.2.1 編譯階段消耗CPU佔比高

再次使用arthas進行監測，查看正常情況與啓動後（異常情況）的CPU消耗情況，我們可以觀察到：

runWoker部分：

該部分的 CPU 佔用比例正常，與平時的表現一致，未見異常波動。

編譯相關的CPU佔用：

CompileBroker::invoke\_compiler\_on\_method(CompileTask) 佔用CPU較大，特別是C2Compiler::compile\_method(ciEnv, ciMethod*, int)的佔比顯著

由此我們得出結論：編譯階段的 CPU 消耗佔比異常，可能是導致CPU負載突刺的重要因素。

① 異常情況下CPU火焰圖：

異常CPU火焰圖

② 正常情況下CPU火焰圖：

正常CPU火焰圖

5.2.2 用arthas換個角度驗證

CPU 火焰圖是基於啓動後 3 分鐘內的綜合數據採集而生成的，雖然能夠提供整體的 CPU 使用情況，但無法反映 CPU 的實時變化。因此，為了更準確地驗證編譯階段是否確實消耗了 CPU，我們需要登錄到機器上，使用 Arthas 進行實時監測。

機器啓動後，運行dashboard命令，重點關注屏幕上方的進程信息，以識別哪些線程佔據了較高的CPU資源，以下為其中一次波動的截圖，前幾次波動CPU佔比都差不多：

dashboard命令

從圖中可以看到， CompilerThread 的三個線程佔用了較高的 CPU 資源，尤其是 C2 CompilerThread 的佔比明顯，這與之前通過火焰圖所反映的情況一致。

5.2.3 CompilerThread是什麼

C1 C2 CompilerThread 是 Java HotSpot 虛擬機中的兩個即時編譯器，主要作用是將 Java 字節碼在運行時編譯成本地機器碼，以提高程序的執行效率。

C1 Compiler（也稱為客户端編譯器），主要用於快速編譯，優化較少，適合需要快速啓動的應用。它的編譯速度較快，但生成的機器碼執行效率相對較低。
C2 Compiler（也稱為服務端編譯器），主要用於高性能的編譯，優化程度較高，適合長時間運行的應用。C2 編譯器會花費更多時間進行優化，以生成更高效的機器碼，適合對性能要求較高的場景。

在HotSpot虛擬機中，Java程序最初都是通過解釋器（Interpreter）進行解釋執行的，解釋器的優點是啓動快，省去編譯的時間，能夠快速運行代碼。但隨着程序的執行，某些方法或代碼塊可能會被多次調用，這些被頻繁調用的代碼被稱為“熱點代碼”（Hot Spot Code）。當虛擬機識別到熱點代碼時，它會啓動 JIT 編譯器（C1 或 C2）將這些代碼編譯成本地機器碼，以提高執行效率。

HotSpot虛擬機是解釋器與即時編譯器並存的架構，兩者經常是相輔相成地配合工作。由於即時編譯器編譯本地代碼需要佔用程序運行時間，編譯出優化程度更高的代碼所需的時間也會相應增加。此外為了實現更高的優化，解釋器需要為編譯器收集性能監控信息，這在一定程度上也會影響解釋執行階段的速度。為了解決這一問題，並在程序啓動響應速度與運行效率之間達到最佳平衡，HotSpot 虛擬機在其編譯子系統中引入了分層編譯的功能。通過這一機制，HotSpot 能夠根據代碼的執行頻率和性能需求，逐步將字節碼編譯為本地機器碼，從而在保證快速啓動的同時，優化長時間運行的代碼性能。

5.2.4 解決方案

截止到現在，問題的原因就變得十分清晰了：當流量涌入時，HotSpot 虛擬機啓動了分層編譯機制，期間大部分代碼迅速轉變為熱點代碼。在這個過程中，C2 編譯器需要頻繁佔用 CPU 資源進行編譯，導致 CPU 使用率顯著上升。隨着大部分熱點代碼的優化完成，C2 編譯器對 CPU 的佔用將逐漸減少，CPU 使用率也會隨之下降。這一編譯過程的持續時間與監控圖上的 CPU 波動情況高度一致。

C1 和 C2 編譯器雖然提供了關閉的參數選項，但關閉這些編譯器無疑會對服務的運行性能產生負面影響。網絡上也有相關實驗案例表明，對於需要長期運行的 Java 後端服務，禁用這些編譯器將導致性能顯著下降。因此這種關閉編譯器的方式並不值得嘗試。

解決方案一：

在前文中，我們已經驗證了流量逐步放量對機器的影響：採用灰度發佈，對機器幾乎沒什麼影響，各項指標表現都很平穩。由於歷史原因，我們的服務當前無法支持灰度發佈，因此還需要探索其他有效的解決方案。

我們可以換個角度思考：是否可以通過降低接口的請求 QPS，並將發版時間固定在每天流量最低的時段，以觀察對服務啓動的影響。

首先，我們可以優先關注大流量接口，並嘗試減少這些接口的 QPS。通過優化接口請求的頻率，我們或許能夠在發版過程中減輕對系統的壓力。

降低接口QPS，調整重啓服務的時間（非高峯期），12:13:59 恢復流量成功，實驗效果如下：

恢復流量後CPU最高峯值為61.5%（依舊有小突刺，但是對業務無影響）
Runnable、Blocked線程數不再有突刺
接口響應時間（RT）也比較平穩
日誌不再告警，無error錯誤日誌

① CPU使用率情況如下：

CPU使用率

② 線程指標如下：

Runnable線程數

Blocked線程數

③ 接口響應時間情況如下：

接口響應時間

解決方案二：

方案一雖然能夠在一定程度上緩解問題，但治標不治本。此外我們也無法固定發版時間，因此最有效的策略是進行預熱。與前文不同的點在於，此處是JVM預熱。

方案為：在系統成功啓動（監測check.do返回成功）後，接入線上HTTP流量之前，針對大流量接口及核心接口進行HTTP接口調用，頻控次數為配置項，方便線上動態調整。特別注意：在剛啓動時，如果機器或下游依賴出現故障，此處的額外調用會加劇系統或下游的負擔，因此調用次數需要合理配置。

此方式可以讓C2 編譯器提前對熱點代碼進行優化，在系統在系統穩定後再將流量接入生產環境，從而避免對用户造成任何影響。

觀察啓動後的各項指標，14:56:25 恢復HTTP流量成功，實驗效果如下：

整體表現與之前的方案一相似，但是有一個顯著的區別：在恢復 HTTP 流量之前，Runnable 線程數出現了明顯的突刺，而在流量恢復後，這種突刺現象則不再出現，線程數已經趨於平穩。我們注意到突刺出現的時間節點是14:55:25，這個時間點正好是我們預熱時發起HTTP接口調用的時間。

這表明通過預熱策略，我們有效地前置了系統的負載波動。當真正的用户請求到達時，系統已經趨於平穩，服務響應速度保持穩定，從而為用户提供了更加流暢的體驗。

① CPU使用率情況如下：

CPU使用率

② 線程指標如下：

Runnable線程數

Blocked線程數

六、總結

本文針對服務啓動後幾分鐘內 CPU 持續處於高峯狀態的問題，提出了自己的分析思路與解決方案。最終線上效果比較顯著，成功解決了每次發版過程中頻繁告警、業務受損以及用户體驗不佳的問題，為服務的高可用性增添了一道重要保障。最初的分析不夠深入，導致在內存緩存預熱方面的努力未能產生預期效果。因此在未來遇到類似問題時，我們必須深入挖掘，直至找到問題的根本原因。

本文的重點在於問題的發現、分析及解決思路。對於 CPU 相關的問題，火焰圖和 Arthas 是非常有效的工具，建議大家在遇到類似情況時，積極嘗試使用這些工具進行排查和解決。

此外HTTP 請求未定義屬性的問題普遍存在，特別是在服務未進行預熱啓動時，會加劇 CPU 的負載。對於大流量服務而言，遇到此類問題時，需規範請求參數，以減輕CPU負擔。