解Bug之路-應用999線升高

来源:https://www.cnblogs.com/alchemystar/archive/2023/04/11/17305296.html
-Advertisement-
Play Games

前言 監控指標誠然是發現問題於微末之時的極佳手段，但指標往往有其表達的極限。在很多情況下，單獨看一個黃金指標並不能表徵系統的健康程度，反而有可能被其迷惑，進而忽略相關問題。(本文所提及的Linux Kernel源碼版本為4.18.10) Bug現場 某天中午，某應用的999線突然升高。由於是個QPS ...


前言

監控指標誠然是發現問題於微末之時的極佳手段，但指標往往有其表達的極限。在很多情況下，單獨看一個黃金指標並不能表徵系統的健康程度，反而有可能被其迷惑，進而忽略相關問題。(本文所提及的Linux Kernel源碼版本為4.18.10)

Bug現場

某天中午，某應用的999線突然升高。由於是個QPS高達幾十萬的查詢服務，1分鐘的升高就會影響數千個請求。初步判斷應用容量不夠，直接進行相關擴容，擴容後反而加劇了問題!不得已又做了一次緊急擴容，999線才恢復。這兩波操作過去，20多分鐘已經過去了。

 

 

為了防止問題再次發生，我們必須要徹查相關原因。於是筆者也就參與了調查。

Young GC升高

首先是去看常用的指標，例如CPU idle, GC Time。發現有一些機器的CPU達到了60%，而在這些機器中，young gc有一個大幅度的增長。

 

 

為什麼Young GC升高

看上去GC問題。那麼，筆者就開始思考為什麼young gc升高。翻看gc日誌。看到故障期間，不停的young gc。但這些young gc的表現很詭異。有時候young gc很快，只有數十毫秒，有時確達到了數百毫秒。而且這個耗時的跳躍沒什麼規律，不是從某個時間點之後就一直是數百毫秒，而是數十和數百一直參雜著。

 

 

觀察young GC的詳細輸出，在數百毫秒的young GC時間里，大部分時間都在[Object Copy]上。令人奇怪的是。其Copy的Object大小確實差不多的。而這是個非常單純的查詢服務，故障期間，它的流量分佈以及對應的Object分佈不應該有非常大的變化。那麼究竟是什麼原因讓同樣大小以及數量的Object Copy會有十倍的差距呢？

再仔細觀察，不僅僅是Object Copy，在其它的GC階段也會出現時間暴漲的情況，只不過大部分集中在Object Copy而已。僅僅靠這些信息是無法看出來相關問題的。

為什麼只有部分機器Young GC升高

繼續觀察監控，發現問題出現在一部分機器上。而這部分機器都在一個機房(B機房)裡面。另一個機房(A機房)的機器沒有受任何影響。當然，出問題的機器都出現了Young GC飆高的現象。難道兩個機房的流量分佈不一樣？經過一番統計，發現介面的調用分佈只是略微有些不同。但細細思考一下，如果是機房流量分佈不一樣，由於同機房是負載均衡的。要出問題，也是同機房都出問題。但問題只集中B機房的一部分機器中。

 

 

尋找這些機器的共同特征

young gc都大幅升高

那麼既然只有一部分機器出問題。那麼筆者開始搜索起這些機器的共同特征。young gc在這部分機器耗時都大幅增長。但由於筆者尚不能通過gc日誌找出原因。那麼就尋找了其它特征。

CPU.Busy

首先，是CPU.busy指標。筆者發現，出問題的機器CPU都在60%左右。但是，正常的節點CPU也有60%的，也有50%的，特征不是很明顯。

 

 

delta_nr_throttled和delta_throttled_time

在筆者觀察某台故障機器監控指標的時候發現，發現delta_nr_throttled和delta_throttled_time這個指標大幅度升高。

 

 

我們看下這兩個指標的含義

nr_throttled: 
   Linux Doc: Number of times the group has been throttled/limited. 
   中文解釋: CGROUP被限制的數量
delta_nr_throttled: 是通過取間隔1分鐘的兩個點，計算出每分鐘CGROUP被限制的數量
throttled_time: 
   linux Doc: The total time duration (in nanoseconds) for which entities of the group have       been throttled.
   中文解釋: 某個CGroup被限制的時間
delta_throttled_time: 通過取間隔1分鐘的兩個點，計算出每分鐘CGROUP被限制的總時間

由於線上應用這邊採用的是docker容器，所以會有這兩個指標。而這兩個指標表明瞭，這個CGroup由於CPU消耗太高而被宿主機的Kernel限制運行。而令人奇怪的是，這些機器的CPU最多只有60%左右，按理來說只有達到100%才能被限制(throttled/limit)。

 

 

宿主機CPU飆升

既然是宿主機限制了相關docker容器，那麼很自然的聯想到宿主機出了問題。統計了一下出故障容器在宿主機上的分佈。發現出問題的所有容器都是集中出現在兩台宿主機上！

 

 

查看了下這兩台宿主機的CPU Busy，發現平均已經90%多了。

 

 

宿主機超賣

詳細觀察了下這兩個宿主機，發現它們超賣非常嚴重。而且當前這個出問題的應用非常集中的部署在這兩個宿主機上。一臺48核的宿主機，僅僅出問題的這個應用就分配了10個，而且分配的資源是每個容器8核(實際上是時間片)。那麼按照，每個容器使用了60%計算，正好用滿了這個宿主機的核

60% * 10 * 8 = 48 正好和宿主機的48核相對應。

 

 

為什麼第一次擴容後加劇了問題

因為這次是通過API自動擴容，而由於打散度計算的原因，還是擴容到了這兩台已經不堪重負的CPU上。同時應用啟動載入時候的CPU消耗也加劇了宿主機CPU的消耗。

為什麼第二次擴容之後999線恢復正常

因為第二次直接通過API手動擴容，一次性在10多台宿主機上機器上擴了一倍的機器。這樣分配在這兩台不堪重負的宿主機上的應用流量降低到一半左右。進而使得999線恢復正常。

為什麼容器相關的CPU busy在宿主機已經接近100%的情況下，依舊只展示60%的

很明顯的，容器的CPU Busy在很大程度上誤導了我們的決策。在之前的容量壓測中，壓到期望的TPS時候CPU Busy只有50%多，而且基本是按照TPS線性增長的，就使得我們覺得這個應用在當前的資源下容量是綽綽有餘。畢竟CPU Busy顯示的還是非常健康的。

但沒想到，在壓測CPU 50%多的時候，其實已經到了整個應用容量的極限。線上的流量和壓測流量的構造有稍微一點的區別，讓CPU漲了個5%左右,過了那個宿主機CPU的臨界點，進而就導致了應用出現了非常高的999線。

容器CPU busy和idle的計算

為了探究這個問題，筆者就不得不看下容器的CPU busy是如何計算出來的。畢竟Linux的CGroup並沒有提供CPU Busy這個指標。翻閱了一下監控的計算公式。

每隔5秒取一下cpuacct.usage的數據
cat /sys/fs/cgroup/cpu/cpuacct.usage
CPU.busy =  (cpuacct.usage(T秒) - cpuacct.usage(T-5秒))/((5秒)*CPU核數)
CPU.idle = 1- CPU.busy

 

 

那麼我們可以看一下cpuacct.usage是如何計算的。Kernel的代碼實現為:

cpuusage_read
  |->__cpuusage_read
          |->cpuacct_cpuusage_read

static u64 __cpuusage_read(struct cgroup_subsys_state *css,
               enum cpuacct_stat_index index)
{
  /* 獲取當前對應cgroup中的cpuacct結構體*/
    struct cpuacct *ca = css_ca(css);
    ...... 
    /* 遍歷所有可能的CPU */
    for_each_possible_cpu(i)
        totalcpuusage += cpuacct_cpuusage_read(ca, i, index);

    return totalcpuusage;
}
static u64 cpuacct_cpuusage_read(struct cpuacct *ca, int cpu,
         enum cpuacct_stat_index index) 
{            
            // 從當前cgroup中獲取對應相應的cpuusage結構體
            struct cpuacct_usage *cpuusage = per_cpu_ptr(ca->cpuusage, cpu);
            ......
            /* i=0計算的是user space的usage，i=1計算的是kernel space的usage */
      for (i = 0; i < CPUACCT_STAT_NSTATS; i++)
        data += cpuusage->usages[i];
}

由代碼可見，其計算是將所有CPU中的關於當前CGroup的cpuusage->usages中的user和system time相加，進而獲取到最終此。那麼我們可以進一步看下CGroup中的cpuusage是如何計算的。這邊筆者以我們常用的CFS(完全公平調度的代碼實現為例):

/* 相關的一條cpuusage代碼路徑如下 *.
pick_next_task_fair
    |->put_prev_entity
        |->update_curr
            |->cgroup_account_cputime /* 其中還包含對當前cgroup的parentGroup的修正*/
                |->cpuacct_charge
void cpuacct_charge(struct task_struct *tsk, u64 cputime)
{
    struct cpuacct *ca;
    int index = CPUACCT_STAT_SYSTEM;
    struct pt_regs *regs = task_pt_regs(tsk);
    /* 判斷是system time還是user time */
    if (regs && user_mode(regs))
        index = CPUACCT_STAT_USER;
    rcu_read_lock();
  /* 將相關的CPU運行時間入賬 */
    for (ca = task_ca(tsk); ca; ca = parent_ca(ca))
        this_cpu_ptr(ca->cpuusage)->usages[index] += cputime;

    rcu_read_unlock();
}

由上面代碼可知，kernel會在進程間切換的時候，將當前進程的運行時間記入到相關。那麼就是這個cputime的計算了。

/* 一個cfs_rq可以是一個task進程，也可以是一個cgroup，代表的是完全公平調度runqueue中的一個元素 */
static void update_curr(struct cfs_rq *cfs_rq){
     /* 這個now=rq->clock_task，clock_task返回的rq->clock減去處理IRQs竊取的時間，其計算不在本文描述範圍內 , 不考慮IRQ的話，可以認為等於此rq的總運行時間*/
     u64 now = rq_clock_task(rq_of(cfs_rq));
     /* 這個delta_exec表明瞭在這一次的運行中，此cfs_rq(進程orCgroup)實際運行了多長時間*/
     delta_exec = now - curr->exec_start;
     curr->exec_start = now;
     ......
     /* 將這一次進程在當前CFS調度下運行的時間更新如相關cgroup的usage */
     cgroup_account_cputime(curtask, delta_exec);
     .....
}

好了，翻了一大堆代碼，我們的cpuusage實際上就是這個cgroup在這一次CFS的kernel調度時間片中實際運行的時間。而我們的應用主要是一個Java進程，那麼其基本就是這個Java進程運行了多長時間。值得註意的是，每個CPU的調度都會進行這樣的計算。如下圖所示:

 

 

 

那麼我們來看一下在超賣情況下的表現。如下圖所示:

 

 

 

(圖中1.25s只是為了繪圖方便，實際調度時間切片非常小)

如果超賣了，而且進程都比較繁忙，那麼每個CGroup肯定不能完全的占用宿主機的CPU。指定到某個CPU上就勢必會有多個CGroup交替進行。而之前的容器CPU.Busy計算公式

CPU.busy =  (cpuacct.usage(T秒) - cpuacct.usage(T-5秒))/((5秒)*CPU核數)

反應的實際上是這個容器在這個CPU(核)上運行了多長時間。而完全不能反應CPU的繁忙程度。

如果不超賣，每個CGroup被均勻的分到各自的CPU上互不影響(當然如果cgroup綁核了那隔離性更好)，那麼這個計算公式才能夠比較準確的反映CPU的情況。

nr_throttled和throttled_time

在Kernel中這兩個參數表示由於分配給Cgroup的cfs_quota_us時間片額度用完。進而導致被內核限制,限制的次數為nr_throttled，限制的總時間為throttled_time。

cat /sys/fs/cgroup/cpuacct/cpu.cfs_period_us 100000(100ms)
cat /sys/fs/cgroup/cpuacct/cpu.cpu.cfs_quota_us 800000(800ms) 因為有8個核，所以分配了800ms
cat /sys/fs/cgroup/cpuset/cpuset.cpus 基本打散到所有的CPU上

但這邊和上面的推論有一個矛盾的點,如果由於CPU超賣而引起的問題的話。那麼每個CGroup並不能分到800ms這樣總的時間片。因為按照上面的推算，每個CGroup最多分到60% * 800=480ms的時間片。而這個時間片是不應該觸發nr_throttled和throttled_time的！

 

就在筆者對著Kernel源碼百思不得其解之際，筆者發現Linux Kernel在5.4版本有個優化

https://lwn.net/Articles/792268/
sched/fair: Fix low cpu usage with high throttling by removing expiration of cpu-local slices

也就是說在5.4版本之前，在一些場景下low cpu usage依舊能導致cgroup被throttled。而這個場景即是:

that highly-threaded, non-cpu-bound applications
running under cpu.cfs_quota_us constraints can hit a high percentage of
periods throttled
高度線程化，非CPU密集的應用程式在CPU.cfs_quota_us約束下運行時，可能會有很高的周期被限制，同時不會消耗分配的配額。

出故障的應用使用了大量的線程去處理請求，同時也有大量的IO操作(操作分散式緩存)，符合此Bug的描述。

# 那麼到底是內核Bug還是超賣是主因呢？

這個疑問當然靠對比來解決，我們在故障之後，做了一次壓測(CPU.Busy > 60%)，這次應用是不超賣的。這次delta_nr_throttled和delta_throttled_time依舊存在，不過比故障時的數量少了一個數量級。

 

 

同時999線從故障時候的暴漲6倍變成了只增長1倍。

 

 

很明顯的，宿主機超賣是主因！而且宿主機超賣後的宿主機CPU負載過高還加重了這個Bug的觸發。

關於Cgroup的核數分配

線上的Cgroup(容器)的核數分配實際上是按照(核數=cfs_quota_us/cfs_period_us)這個模型去分配的，同時並不會在cpuset進行綁核。也就是說一個48核的容器，應用的各個線程可以跑在任何一個核上，只不過只分配了8核的時間片額度。這就利用了Cgroup的帶寬控制機制CFS_BANDWITH。

改進措施

很明顯的改進措施可以是下麵幾種:

針對超賣:
   1) 宿主機不超賣，但不是一個好的選擇，因為資源利用率上不去，存在大量CPU利用率很低的應用
   2) 根據應用的CPU利用率情況進行高低錯配放到宿主機上，在利用資源利用率的同時又不至於互相影響
針對內核的Bug
   1) 可以打Patch或者升級到5.4

為什麼Young GC會變慢

回過頭來看看young gc為什麼會慢就很明顯了。因為在young gc時候，被shedule出去了，而且沒有其它的空閑CPU讓jvm可以schedule回來，白白浪費了很長時間。

因為object copy在這個應用的young gc中是最耗費CPU以及時間的操作，所以自然在object copy階段出現變慢的現象。

 

當然，進程schedule可以處在各種時間點，所以並不僅僅是Young GC變慢了，在請求處理階段也可能變慢。

總結

指標雖然能夠比較準確且客觀的反映兩個時間點的變化。但指標的定義和對指標的解讀確實比較主觀的，沒有理解清楚指標所能表達的極限以及使用場景。往往會讓我們排查問題進入誤區！


您的分享是我們最大的動力!

-Advertisement-
Play Games
更多相關文章
  • 全棧之前端 | 5.HTML表格列表標簽元素學習篇
    [ 點擊 👉 關註「 全棧工程師修煉指南」公眾號 ] 設為「⭐️ 星標」帶你從基礎入門 到 全棧實踐 再到 放棄學習！ 涉及 網路安全運維、應用開發、物聯網IOT、學習路徑 、個人感悟 等知識分享。 希望各位看友多多支持【關註、點贊、評論、收藏、投幣】，助力每一個夢想。 【WeiyiGeek Bl ...
  • 重試，讓程式更健壯
    任何通過網路與其它應用通訊地的程式，都應該有足夠的靈活性，來應對短暫的臨時性故障。因為這些故障很多時候是可以自恢復的。 例如，為了避免服務過載，很多應用會採取某些限流措施，在併發請求達到一定數量時，暫時性的拒絕新的請求加入。這種情況下，嘗試使用該應用的程式，一開始可能會被拒絕連接，但下一刻就好了。 ...
  • 【學習筆記】HTML+CSS
    HTML HTML教程 簡介 編輯器 基礎 元素 屬性 標題 段落 文本格式化 鏈接 頭部 CSS 圖像 表格 列表 區塊 佈局 表單和輸入 1、意義： 用於收集用戶的輸入信息 表示文檔中的一個區域，此區域包含交互控制項，將用戶收集到的信息發送到 Web 伺服器 一個文本欄位的預設寬度是20個字元 2 ...
  • 【學習筆記】JS
    JS JS教程 HTML 定義了網頁的內容 CSS 描述了網頁的佈局 JavaScript 控制了網頁的行為 簡介 1、什麼是JS？ JavaScript 是一種輕量級的編程語言。 JavaScript 是可插入 HTML 頁面的編程代碼。 JavaScript 插入 HTML 頁面後，可由所有的現 ...
  • 介紹一下js垃圾回收機制
    JavaScript中的垃圾回收機制負責自動管理記憶體，回收不再使用的對象所占用的記憶體空間。在JavaScript中，開發者不需要顯式地分配和釋放記憶體，垃圾回收器會自動完成這些操作。以下是關於JavaScript垃圾回收機制的一些關鍵概念： 記憶體生命周期：JavaScript記憶體生命周期包括分配、使用 ...
  • 全棧之前端 | 1.HTML基礎必備知識學習篇
    [ 點擊 👉 關註「 全棧工程師修煉指南」公眾號 ] 設為「⭐️ 星標」帶你從基礎入門 到 全棧實踐 再到 放棄學習！ 涉及 網路安全運維、應用開發、物聯網IOT、學習路徑 、個人感悟 等知識分享。 希望各位看友多多支持【關註、點贊、評論、收藏、投幣】，助力每一個夢想。 【WeiyiGeek Bl ...
  • 行為型：迭代器模式
    定義 迭代器模式提供一種方法按順序訪問一個聚合對象中的各個元素，而又不暴露該對象的內部表示。迭代器模式是目的性極強的模式，它主要是用來解決遍歷問題。 es6 中的迭代器 JS原生的集合類型數據結構，有Array（數組）和Object（對象），在ES6中，又新增了Map和Set。四種數據結構各自有著自 ...
  • 行為型：發佈訂閱模式
    定義 發佈訂閱模式是基於一個事件（主題）通道，希望接收通知的對象Subscriber （訂閱者）通過自定義事件訂閱主題，被激活事件的對象 Publisher （發佈者）通過發佈主題事件的方式通知訂閱者 Subscriber （訂閱者）對象。 簡單說就是發佈者與訂閱者通過事件來通信，這裡的發佈者是之前 ...
一周排行
    -Advertisement-
    Play Games
  • C# + WPF 音頻播放器 界面優雅，體驗良好
    前言 本文介紹一款使用 C# 與 WPF 開發的音頻播放器，其界面簡潔大方，操作體驗流暢。該播放器支持多種音頻格式（如 MP4、WMA、OGG、FLAC 等），並具備標記、實時歌詞顯示等功能。 另外，還支持換膚及多語言（中英文）切換。核心音頻處理採用 FFmpeg 組件，獲得了廣泛認可，目前 Git ...
  • OAuth2.0授權-gitee授權碼模式
    OAuth2.0授權驗證-gitee授權碼模式 本文主要介紹如何筆者自己是如何使用gitee提供的OAuth2.0協議完成授權驗證並登錄到自己的系統，完整模式如圖 1、創建應用 打開gitee個人中心->第三方應用->創建應用 創建應用後在我的應用界面，查看已創建應用的Client ID和Clien ...
  • FastReport.OpenSource .Net下開源免費報表列印組件
    解決了這個問題：《winForm下，fastReport.net 從.net framework 升級到.net5遇到的錯誤“Operation is not supported on this platform.”》 本文內容轉載自：https://www.fcnsoft.com/Home/Sho ...
  • 如何在 ASP.NET Core Web API 方法執行前後 “偷偷“ 作一些 “壞“ 事？初識 ActionFilterAttribute
    國內文章 WPF 從裸 Win 32 的 WM_Pointer 消息獲取觸摸點繪製筆跡 https://www.cnblogs.com/lindexi/p/18390983 本文將告訴大家如何在 WPF 裡面，接收裸 Win 32 的 WM_Pointer 消息，從消息裡面獲取觸摸點信息，使用觸摸點 ...
  • 在 ASP.NET Core Web API 中使用異常篩選器捕獲和統一處理異常
    前言 給大家推薦一個專為新零售快消行業打造了一套高效的進銷存管理系統。 系統不僅具備強大的庫存管理功能，還集成了高性能的輕量級 POS 解決方案，確保頁面載入速度極快，提供良好的用戶體驗。 項目介紹 Dorisoy.POS 是一款基於 .NET 7 和 Angular 4 開發的新零售快消進銷存管理 ...
  • AbpHelper CLI積累與實戰分享
    ABP CLI常用的代碼分享 一、確保環境配置正確 安裝.NET CLI： ABP CLI是基於.NET Core或.NET 5/6/7等更高版本構建的，因此首先需要在你的開發環境中安裝.NET CLI。這可以通過訪問Microsoft官網下載並安裝相應版本的.NET SDK來實現。 安裝ABP ...
  • 記一次HttpClient使用問題分析
    問題 問題是這樣的：第三方的webapi，需要先調用登陸介面獲取Cookie，訪問其它介面時攜帶Cookie信息。 但使用HttpClient類調用登陸介面，返回的Headers中沒有找到Cookie信息。 分析 首先，使用Postman測試該登陸介面，正常返回Cookie信息，說明是HttpCli ...
  • .NET周刊【9月第3期 2024-09-15】
    國內文章 關於.NET在中國為什麼工資低的分析 https://www.cnblogs.com/thinkingmore/p/18406244 .NET在中國開發者的薪資偏低，主要因市場需求、技術棧選擇和企業文化等因素所致。歷史上，.NET曾因微軟的閉源策略發展受限，儘管後來推出了跨平臺的.NET ...
  • 我的網站集成ElasticSearch初體驗
    在WPF開發應用中，動畫不僅可以引起用戶的註意與興趣，而且還使軟體更加便於使用。前面幾篇文章講解了畫筆（Brush），形狀（Shape），幾何圖形（Geometry），變換（Transform）等相關內容，今天繼續講解動畫相關內容和知識點，僅供學習分享使用，如有不足之處，還請指正。 ...
  • 第23篇 委托的概述
    什麼是委托？ 委托可以說是把一個方法代入另一個方法執行，相當於指向函數的指針；事件就相當於保存委托的數組； 1.實例化委托的方式： 方式1：通過new創建實例： public delegate void ShowDelegate(); 或者 public delegate string ShowDe ...
所有分類