幾年前 Kubernetes 在 GitHub 官方部落格。從那時起，它已成為部署服務的標準技術。 Kubernetes 現在管理著很大一部分內部和公共服務。隨著叢集的成長和效能要求變得更加嚴格，我們開始注意到 Kubernetes 上的某些服務偶爾會出現延遲，而這種延遲無法用應用程式本身的負載來解釋。
本質上，應用程式會經歷看似隨機的高達 100 毫秒或更長的網路延遲，從而導致逾時或重試。服務回應請求的速度預計要快於 100 毫秒。但如果連接本身需要如此多的時間，這是不可能的。另外，我們觀察到 MySQL 查詢速度非常快，本應需要幾毫秒，而 MySQL 確實在幾毫秒內完成，但從請求應用程式的角度來看，回應花費了 100 毫秒或更長的時間。
很快就發現問題只發生在連接到 Kubernetes 節點時，即使呼叫來自 Kubernetes 外部。重現問題最簡單的方法是進行測試 ，它從任何內部主機運行，在特定連接埠上測試 Kubernetes 服務，並偶爾記錄高延遲。在本文中，我們將了解如何找到此問題的原因。
消除導致失敗的鏈條中不必要的複雜性
透過重現相同的範例，我們希望縮小問題的焦點並消除不必要的複雜性。最初，Vegeta 和 Kubernetes Pod 之間的流程有太多元素。要識別更深層的網路問題，您需要排除其中一些問題。
客戶端（Vegeta）與叢集中的任何節點建立 TCP 連線。 Kubernetes 作為覆蓋網路（在現有資料中心網路之上）運行，使用 ，即將覆蓋網路的IP封包封裝在資料中心的IP封包內。當連接到第一個節點時，執行網路位址轉換 (NAT) 有狀態，將 Kubernetes 節點的 IP 位址和連接埠轉換為覆蓋網路（具體來說，具有應用程式的 pod）中的 IP 位址和連接埠。對於傳入資料包，執行相反的操作順序。它是一個複雜的系統，具有大量狀態和許多元素，隨著服務的部署和移動，這些元素會不斷更新和變更。
效用 tcpdump 在 Vegeta 測試中，TCP 握手期間（SYN 和 SYN-ACK 之間）存在延遲。要消除這種不必要的複雜性，您可以使用 hping3 用於使用 SYN 封包進行簡單的「ping」。我們檢查響應資料包是否有延遲，然後重置連線。我們可以過濾數據，僅包含大於 100 毫秒的數據包，並獲得比 Vegeta 中完整網路第 7 層測試更簡單的方法來重現問題。以下是在服務“節點連接埠”（30927）上以 10 毫秒間隔使用 TCP SYN/SYN-ACK 的 Kubernetes 節點“ping”，並按最慢的回應進行過濾：
theojulienne@shell ~ $ sudo hping3 172.16.47.27 -S -p 30927 -i u10000 | egrep --line-buffered 'rtt=[0-9]{3}.'
len=46 ip=172.16.47.27 ttl=59 DF id=0 sport=30927 flags=SA seq=1485 win=29200 rtt=127.1 ms
len=46 ip=172.16.47.27 ttl=59 DF id=0 sport=30927 flags=SA seq=1486 win=29200 rtt=117.0 ms
len=46 ip=172.16.47.27 ttl=59 DF id=0 sport=30927 flags=SA seq=1487 win=29200 rtt=106.2 ms
len=46 ip=172.16.47.27 ttl=59 DF id=0 sport=30927 flags=SA seq=1488 win=29200 rtt=104.1 ms
len=46 ip=172.16.47.27 ttl=59 DF id=0 sport=30927 flags=SA seq=5024 win=29200 rtt=109.2 ms
len=46 ip=172.16.47.27 ttl=59 DF id=0 sport=30927 flags=SA seq=5231 win=29200 rtt=109.2 ms
可以立即做出第一次觀察。從序號和時間來看，很明顯這不是一次性擁塞。延遲通常會累積並最終處理。
接下來，我們要找出哪些元件可能涉及擁塞的發生。也許這些只是 NAT 中數百條 iptables 規則中的一部分？或者網路上的 IPIP 隧道是否有問題？測試這一點的一種方法是透過消除系統的每個步驟來測試它。如果刪除 NAT 和防火牆邏輯，只留下 IPIP 部分，會發生什麼事：
幸運的是，如果機器位於同一網路上，Linux 可以輕鬆直接存取 IP 覆蓋層：
theojulienne@kube-node-client ~ $ sudo hping3 10.125.20.64 -S -i u10000 | egrep --line-buffered 'rtt=[0-9]{3}.'
len=40 ip=10.125.20.64 ttl=64 DF id=0 sport=0 flags=RA seq=7346 win=0 rtt=127.3 ms
len=40 ip=10.125.20.64 ttl=64 DF id=0 sport=0 flags=RA seq=7347 win=0 rtt=117.3 ms
len=40 ip=10.125.20.64 ttl=64 DF id=0 sport=0 flags=RA seq=7348 win=0 rtt=107.2 ms
從結果來看，問題依然存在！這不包括 iptables 和 NAT。那麼問題出在TCP？讓我們看看常規 ICMP ping 的情況如何：
theojulienne@kube-node-client ~ $ sudo hping3 10.125.20.64 --icmp -i u10000 | egrep --line-buffered 'rtt=[0-9]{3}.'
len=28 ip=10.125.20.64 ttl=64 id=42594 icmp_seq=104 rtt=110.0 ms
len=28 ip=10.125.20.64 ttl=64 id=49448 icmp_seq=4022 rtt=141.3 ms
len=28 ip=10.125.20.64 ttl=64 id=49449 icmp_seq=4023 rtt=131.3 ms
len=28 ip=10.125.20.64 ttl=64 id=49450 icmp_seq=4024 rtt=121.2 ms
len=28 ip=10.125.20.64 ttl=64 id=49451 icmp_seq=4025 rtt=111.2 ms
len=28 ip=10.125.20.64 ttl=64 id=49452 icmp_seq=4026 rtt=101.1 ms
len=28 ip=10.125.20.64 ttl=64 id=50023 icmp_seq=4343 rtt=126.8 ms
len=28 ip=10.125.20.64 ttl=64 id=50024 icmp_seq=4344 rtt=116.8 ms
len=28 ip=10.125.20.64 ttl=64 id=50025 icmp_seq=4345 rtt=106.8 ms
len=28 ip=10.125.20.64 ttl=64 id=59727 icmp_seq=9836 rtt=106.1 ms
結果顯示問題並沒有消失。也許這是一個 IPIP 隧道？讓我們進一步簡化測試：
所有資料包都是在這兩台主機之間發送的嗎？
theojulienne@kube-node-client ~ $ sudo hping3 172.16.47.27 --icmp -i u10000 | egrep --line-buffered 'rtt=[0-9]{3}.'
len=46 ip=172.16.47.27 ttl=61 id=41127 icmp_seq=12564 rtt=140.9 ms
len=46 ip=172.16.47.27 ttl=61 id=41128 icmp_seq=12565 rtt=130.9 ms
len=46 ip=172.16.47.27 ttl=61 id=41129 icmp_seq=12566 rtt=120.8 ms
len=46 ip=172.16.47.27 ttl=61 id=41130 icmp_seq=12567 rtt=110.8 ms
len=46 ip=172.16.47.27 ttl=61 id=41131 icmp_seq=12568 rtt=100.7 ms
len=46 ip=172.16.47.27 ttl=61 id=9062 icmp_seq=31443 rtt=134.2 ms
len=46 ip=172.16.47.27 ttl=61 id=9063 icmp_seq=31444 rtt=124.2 ms
len=46 ip=172.16.47.27 ttl=61 id=9064 icmp_seq=31445 rtt=114.2 ms
len=46 ip=172.16.47.27 ttl=61 id=9065 icmp_seq=31446 rtt=104.2 ms
我們將情況簡化為兩個 Kubernetes 節點相互發送任何資料包，甚至是 ICMP ping。如果目標主機「不好」（有些比其他主機更糟），他們仍然會看到延遲。
現在最後一個問題：為什麼延遲只發生在 kube-node 伺服器上？當 kube-node 是發送者或接收者時，會發生這種情況嗎？幸運的是，透過從 Kubernetes 外部的主機發送資料包，但使用相同的「已知不良」接收者，這也很容易弄清楚。正如你所看到的，問題並沒有消失：
theojulienne@shell ~ $ sudo hping3 172.16.47.27 -p 9876 -S -i u10000 | egrep --line-buffered 'rtt=[0-9]{3}.'
len=46 ip=172.16.47.27 ttl=61 DF id=0 sport=9876 flags=RA seq=312 win=0 rtt=108.5 ms
len=46 ip=172.16.47.27 ttl=61 DF id=0 sport=9876 flags=RA seq=5903 win=0 rtt=119.4 ms
len=46 ip=172.16.47.27 ttl=61 DF id=0 sport=9876 flags=RA seq=6227 win=0 rtt=139.9 ms
len=46 ip=172.16.47.27 ttl=61 DF id=0 sport=9876 flags=RA seq=7929 win=0 rtt=131.2 ms
然後，我們將從先前的來源 kube-node 向外部主機執行相同的請求（不包括來源主機，因為 ping 包括 RX 和 TX 元件）：
theojulienne@kube-node-client ~ $ sudo hping3 172.16.33.44 -p 9876 -S -i u10000 | egrep --line-buffered 'rtt=[0-9]{3}.'
^C
--- 172.16.33.44 hping statistic ---
22352 packets transmitted, 22350 packets received, 1% packet loss
round-trip min/avg/max = 0.2/7.6/1010.6 ms
透過檢查延遲資料包捕獲，我們獲得了一些附加資訊。具體來說，發送者（底部）看到此超時，但接收者（頂部）沒有 - 請參閱 Delta 列（以秒為單位）：
此外，如果您查看接收方 TCP 和 ICMP 封包順序（按序號）的差異，您會發現 ICMP 封包始終按照發送時的相同順序到達，但時間不同。同時，TCP封包有時會交錯，並且其中一些會被卡住。特別是，如果您檢查 SYN 封包的端口，它們在發送方一側是有序的，但在接收方一側則不然。
方式上有細微的差別 現代伺服器（如我們資料中心的伺服器）處理包含 TCP 或 ICMP 的資料包。當封包到達時，網路適配器“對每個連接進行哈希處理”，也就是說，它嘗試將連接分成隊列並將每個隊列發送到單獨的處理器核心。對於 TCP，此雜湊值包括來源和目標 IP 位址以及連接埠。換句話說，每個連接的雜湊值（可能）不同。對於 ICMP，僅對 IP 位址進行雜湊處理，因為沒有連接埠。
另一個新的觀察結果：在此期間，我們看到兩台主機之間的所有通訊都有 ICMP 延遲，但 TCP 沒有。這告訴我們，原因很可能與 RX 佇列雜湊有關：擁塞幾乎肯定是在 RX 封包的處理中，而不是在發送回應中。
這消除了從可能原因清單中發送資料包的情況。我們現在知道封包處理問題出現在某些 kube-node 伺服器的接收端。
了解 Linux 核心中的資料包處理
為了理解為什麼某些 kube-node 伺服器上的接收方會出現問題，讓我們看看 Linux 核心是如何處理封包的。
回到最簡單的傳統實現，網路卡接收資料包並發送 Linux核心有一個套件需要處理。核心停止其他工作，將上下文切換到中斷處理程序，處理資料包，然後返回當前任務。
這種上下文切換速度很慢：在10 年代的90Mbps 網路卡上，延遲可能並不明顯，但在最大吞吐量為每秒10 萬個資料包的現代15G 卡上，小型八核心伺服器的每個核心可能會中斷數百萬個資料包每秒的次數。
為了不不斷處理中斷，Linux在很多年前就加入了 ：所有現代驅動程式都使用網路 API 來提高高速效能。在低速下，核心仍然以舊方式接收來自網卡的中斷。一旦到達的資料包數量超過閾值，核心就會停用中斷，轉而開始輪詢網路適配器並分塊拾取資料包。處理是在softirq中進行的，即在 在系統呼叫和硬體中斷之後，當核心（而不是用戶空間）已經運行時。
這要快得多，但會導致不同的問題。如果資料包太多，那麼所有時間都花在處理來自網路卡的資料包上，而用戶空間進程沒有時間實際清空這些佇列（從 TCP 連線讀取等）。最終隊列填滿，我們開始丟棄資料包。為了找到平衡，核心為軟中斷上下文中處理的資料包的最大數量設定了預算。一旦超過這個預算，就會喚醒一個單獨的線程 ksoftirqd （您將在其中看到其中之一 ps 每個核心）處理正常系統呼叫/中斷路徑之外的這些軟中斷。該執行緒使用標準進程調度程序進行調度，該調度程序嘗試公平地分配資源。
研究了核心是如何處理資料包的，可以看到有一定的可能發生擁塞。如果接收到軟中斷呼叫的頻率較低，則封包將必須在網路卡上的 RX 佇列中等待一段時間才能處理。這可能是由於某些任務阻塞了處理器核心，或是其他原因阻止了核心運行軟中斷。
將處理範圍縮小到核心或方法
Softirq 延遲目前只是一個猜測。但這是有道理的，我們知道我們看到了非常相似的東西。所以下一步就是證實這個理論。如果得到證實，那就找出延誤的原因。
讓我們回到慢速資料包：
len=46 ip=172.16.53.32 ttl=61 id=29573 icmp_seq=1953 rtt=99.3 ms
len=46 ip=172.16.53.32 ttl=61 id=29574 icmp_seq=1954 rtt=89.3 ms
len=46 ip=172.16.53.32 ttl=61 id=29575 icmp_seq=1955 rtt=79.2 ms
len=46 ip=172.16.53.32 ttl=61 id=29576 icmp_seq=1956 rtt=69.1 ms
len=46 ip=172.16.53.32 ttl=61 id=29577 icmp_seq=1957 rtt=59.1 ms
len=46 ip=172.16.53.32 ttl=61 id=29790 icmp_seq=2070 rtt=75.7 ms
len=46 ip=172.16.53.32 ttl=61 id=29791 icmp_seq=2071 rtt=65.6 ms
len=46 ip=172.16.53.32 ttl=61 id=29792 icmp_seq=2072 rtt=55.5 ms
如前所述，這些 ICMP 封包被雜湊到單一 RX NIC 佇列中並由單一 CPU 核心處理。如果我們想了解 Linux 的工作原理，了解這些套件在哪裡（在哪個 CPU 核心上）以及如何（軟中斷、ksoftirqd）被處理以便追蹤進程是很有用的。
現在是時候使用可以即時監控 Linux 核心的工具了。這裡我們使用了 。這套工具可讓您編寫小型 C 程序，掛鉤內核中的任意函數，並將事件緩衝到用戶空間 Python 程式中，該程式可以處理它們並將結果傳回給您。掛鉤核心中的任意函數是一件棘手的事情，但該實用程式旨在實現最大程度的安全性，並旨在準確追蹤在測試或開發環境中不易重現的生產問題。
這裡的計劃很簡單：我們知道核心處理這些 ICMP ping，因此我們將在核心函數上放置一個鉤子 ，它接受傳入的 ICMP 回顯請求封包並啟動發送 ICMP 回顯回應。我們可以透過增加 icmp_seq 編號來識別資料包，這表明 hping3 更高。
代碼 看起來很複雜，但其實並沒有看起來那麼可怕。功能 icmp_echo 傳達 struct sk_buff *skb：這是一個帶有“echo request”的資料包。我們可以追蹤它，提取序列 echo.sequence （與 icmp_seq 透過 hping3 выше)，並將其發送到用戶空間。捕獲當前進程名稱/id 也很方便。下面是核心處理資料包時我們直接看到的結果：
TGID PID 進程名稱 ICMP_SEQ 0 0 交換者/11 770 0 交換者/0 11 771 交換者/0 0 11 交換者/772 0 0 交換者/11 773 0 普羅米修斯 0 11 774 交換者/20041 20086 775 交換者/0 0 11 交換者/776 0 0 輻條報告-s 11
這裡要注意的是，在上下文中 softirq 進行系統呼叫的進程將顯示為“進程”，而實際上是核心在核心上下文中安全地處理資料包。
使用此工具，我們可以將特定進程與顯示延遲的特定套件關聯起來 hping3。讓我們簡單一點 grep 在此捕獲某些值 icmp_seq。與上述 icmp_seq 值相符的資料包連同我們在上面觀察到的 RTT 一起被標記（括號中是我們因 RTT 值小於 50ms 而過濾掉的資料包的預期 RTT 值）：
TGID PID 進程名稱 ICMP_SEQ ** RTT -- 10137 10436 顧問 1951 10137 10436 顧問 1952 76 76 ksoftirqd/11 1953 ** 99ms 76 76 ksoftirqd/11 1954 ** 89ms 76 76 ksoftirqd/11 1955 ** 79 毫秒 76 76 ksoftirqd/11 1956 ** 69ms 76 76 ksoftirqd/11 1957 ** 59ms 76 76 ksoftirqd/11 1958 ** (49ms) 76 76 ksoftirqd/11 1959 ** (39ms) 76 76 ksoftirqd/11 1960 ** (29ms) 76 76 ksoftirqd/11 1961 **（19 毫秒） 76 76 ksoftirqd/11 1962 **（9 毫秒） -- 10137 10436 顧問 2068 10137 10436 顧問 2069 76 76 ksoftirqd/11 2070 ** 75ms 76 76 ksoftirqd/11 2071 ** 65ms 76 76 ksoftirqd/11 2072 ** 55ms 76 76 ksoftirqd/11 2073 **（45 毫秒） 76 76 ksoftirqd/11 2074 **（35 毫秒） 76 76 ksoftirqd/11 2075 **（25 毫秒） 76 76 ksoftirqd/11 2076 **（15 毫秒） 76 76 ksoftirqd/11 2077 **（5 毫秒）
結果告訴我們幾件事。首先，所有這些套件都是由上下文處理的 ksoftirqd/11。這意味著對於這對特定的機器，ICMP 封包被散列到接收端的核心 11。我們也看到，每當出現堵塞時，都會在系統呼叫的上下文中處理資料包 cadvisor。 然後 ksoftirqd 接手任務並處理累積佇列：恰好是之後累積的資料包數量 cadvisor.
事實上，就在它總是有效之前 cadvisor，暗示他參與了問題。諷刺的是，目的 - “分析正在運行的容器的資源使用情況和性能特徵”而不是導致此性能問題。
與容器的其他方面一樣，這些都是非常先進的工具，並且在某些不可預見的情況下可能會遇到效能問題。
cadvisor 的哪些操作會減慢封包佇列的速度？
現在，我們對崩潰是如何發生的、導致崩潰的進程以及在哪個 CPU 上有了很好的了解。我們看到由於硬阻塞，Linux核心沒有時間調度 ksoftirqd。我們看到資料包是在上下文中處理的 cadvisor。假設是合乎邏輯的 cadvisor 啟動一個緩慢的系統調用，然後處理當時累積的所有資料包：
這是一個理論，但如何檢驗呢？我們能做的就是在整個過程中追蹤 CPU 核心，找到資料包數量超出預算並呼叫 ksoftirqd 的點，然後再往回看一下，看看該點之前 CPU 核心上到底運行了什麼。這就像每隔幾毫秒對 CPU 進行一次 X 光檢查。它看起來像這樣：
方便的是，所有這些都可以使用現有工具來完成。例如， 以指定的頻率檢查給定的 CPU 內核，並可以產生對正在運行的系統（包括用戶空間和 Linux 內核）的呼叫計劃。您可以使用該程式的一個小分支來獲取此記錄並對其進行處理 來自 Brendan Gregg，它保留了堆疊追蹤的順序。我們可以每 1 毫秒保存一次單行堆疊跟踪，然後在跟踪命中前 100 毫秒突出顯示並保存樣本 ksoftirqd:
# record 999 times a second, or every 1ms with some offset so not to align exactly with timers
sudo perf record -C 11 -g -F 999
# take that recording and make a simpler stack trace.
sudo perf script 2>/dev/null | ./FlameGraph/stackcollapse-perf-ordered.pl | grep ksoftir -B 100
結果如下：
(сотни следов, которые выглядят похожими)
cadvisor;[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];entry_SYSCALL_64_after_swapgs;do_syscall_64;sys_read;vfs_read;seq_read;memcg_stat_show;mem_cgroup_nr_lru_pages;mem_cgroup_node_nr_lru_pages cadvisor;[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];entry_SYSCALL_64_after_swapgs;do_syscall_64;sys_read;vfs_read;seq_read;memcg_stat_show;mem_cgroup_nr_lru_pages;mem_cgroup_node_nr_lru_pages cadvisor;[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];entry_SYSCALL_64_after_swapgs;do_syscall_64;sys_read;vfs_read;seq_read;memcg_stat_show;mem_cgroup_iter cadvisor;[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];entry_SYSCALL_64_after_swapgs;do_syscall_64;sys_read;vfs_read;seq_read;memcg_stat_show;mem_cgroup_nr_lru_pages;mem_cgroup_node_nr_lru_pages cadvisor;[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];[cadvisor];entry_SYSCALL_64_after_swapgs;do_syscall_64;sys_read;vfs_read;seq_read;memcg_stat_show;mem_cgroup_nr_lru_pages;mem_cgroup_node_nr_lru_pages ksoftirqd/11;ret_from_fork;kthread;kthread;smpboot_thread_fn;smpboot_thread_fn;run_ksoftirqd;__do_softirq;net_rx_action;ixgbe_poll;ixgbe_clean_rx_irq;napi_gro_receive;netif_receive_skb_internal;inet_gro_receive;bond_handle_frame;__netif_receive_skb_core;ip_rcv_finish;ip_rcv;ip_forward_finish;ip_forward;ip_finish_output;nf_iterate;ip_output;ip_finish_output2;__dev_queue_xmit;dev_hard_start_xmit;ipip_tunnel_xmit;ip_tunnel_xmit;iptunnel_xmit;ip_local_out;dst_output;__ip_local_out;nf_hook_slow;nf_iterate;nf_conntrack_in;generic_packet;ipt_do_table;set_match_v4;ip_set_test;hash_net4_kadt;ixgbe_xmit_frame_ring;swiotlb_dma_mapping_error;hash_net4_test ksoftirqd/11;ret_from_fork;kthread;kthread;smpboot_thread_fn;smpboot_thread_fn;run_ksoftirqd;__do_softirq;net_rx_action;gro_cell_poll;napi_gro_receive;netif_receive_skb_internal;inet_gro_receive;__netif_receive_skb_core;ip_rcv_finish;ip_rcv;ip_forward_finish;ip_forward;ip_finish_output;nf_iterate;ip_output;ip_finish_output2;__dev_queue_xmit;dev_hard_start_xmit;dev_queue_xmit_nit;packet_rcv;tpacket_rcv;sch_direct_xmit;validate_xmit_skb_list;validate_xmit_skb;netif_skb_features;ixgbe_xmit_frame_ring;swiotlb_dma_mapping_error;__dev_queue_xmit;dev_hard_start_xmit;__bpf_prog_run;__bpf_prog_run
這裡有很多東西，但最主要的是我們找到了我們之前在 ICMP 追蹤器中看到的「cadvisor before ksoftirqd」模式。這是什麼意思？
每行都是特定時間點的 CPU 追蹤。一行中堆疊中的每個呼叫都用分號分隔。在行的中間，我們看到系統呼叫被呼叫： read(): .... ;do_syscall_64;sys_read; ...。所以cadvisor花了大量的時間在系統呼叫上 read()與功能相關 mem_cgroup_* （呼叫堆疊頂部/行尾）。
在呼叫追蹤中查看到底正在讀取什麼內容很不方便，所以讓我們運行 strace 讓我們看看 cadvisor 做了什麼，並找到超過 100 毫秒的系統呼叫：
theojulienne@kube-node-bad ~ $ sudo strace -p 10137 -T -ff 2>&1 | egrep '<0.[1-9]'
[pid 10436] <... futex resumed> ) = 0 <0.156784>
[pid 10432] <... futex resumed> ) = 0 <0.258285>
[pid 10137] <... futex resumed> ) = 0 <0.678382>
[pid 10384] <... futex resumed> ) = 0 <0.762328>
[pid 10436] <... read resumed> "cache 154234880nrss 507904nrss_h"..., 4096) = 658 <0.179438>
[pid 10384] <... futex resumed> ) = 0 <0.104614>
[pid 10436] <... futex resumed> ) = 0 <0.175936>
[pid 10436] <... read resumed> "cache 0nrss 0nrss_huge 0nmapped_"..., 4096) = 577 <0.228091>
[pid 10427] <... read resumed> "cache 0nrss 0nrss_huge 0nmapped_"..., 4096) = 577 <0.207334>
[pid 10411] <... epoll_ctl resumed> ) = 0 <0.118113>
[pid 10382] <... pselect6 resumed> ) = 0 (Timeout) <0.117717>
[pid 10436] <... read resumed> "cache 154234880nrss 507904nrss_h"..., 4096) = 660 <0.159891>
[pid 10417] <... futex resumed> ) = 0 <0.917495>
[pid 10436] <... futex resumed> ) = 0 <0.208172>
[pid 10417] <... futex resumed> ) = 0 <0.190763>
[pid 10417] <... read resumed> "cache 0nrss 0nrss_huge 0nmapped_"..., 4096) = 576 <0.154442>
正如您所料，我們在這裡看到緩慢的調用 read()。從讀取操作的內容和上下文 mem_cgroup 很明顯，這些挑戰 read() 參考文件 memory.stat，它顯示了記憶體使用情況和cgroup限制（Docker的資源隔離技術）。 cadvisor工具查詢該文件以取得容器的資源使用資訊。讓我們檢查一下是否是內核或 cadvisor 做了一些意外的事情：
theojulienne@kube-node-bad ~ $ time cat /sys/fs/cgroup/memory/memory.stat >/dev/null
real 0m0.153s
user 0m0.000s
sys 0m0.152s
theojulienne@kube-node-bad ~ $
現在我們可以重現該錯誤並了解 Linux 核心正面臨一種病態。
為什麼讀取操作這麼慢？
在此階段，尋找其他用戶關於類似問題的訊息要容易得多。事實證明，在 cadvisor 追蹤器中，該錯誤被報告為 ，只是沒有人注意到延遲也隨機反映在網路堆疊中。確實注意到cadvisor消耗的CPU時間比預期的多，但這並沒有引起足夠的重視，因為我們的伺服器有大量的CPU資源，所以沒有仔細研究這個問題。
問題在於 cgroup 會考慮命名空間（容器）內的記憶體使用量。當這個cgroup中的所有程序退出時，Docker會釋放記憶體cgroup。然而，「記憶體」不僅僅是進程記憶體。雖然進程記憶體本身不再被使用，但看起來核心仍然分配快取的內容，例如dentry和inode（目錄和檔案元資料），它們緩存在記憶體cgroup中。從問題描述來看：
殭屍 cgroup：沒有進程且已刪除的 cgroup，但仍然分配了記憶體（在我的例子中，從 dentry 快取中分配，但也可以從頁面快取或 tmpfs 中分配）。
核心在釋放 cgroup 時檢查快取中的所有頁面可能會非常慢，因此選擇惰性進程：等到再次請求這些頁面，然後在實際需要記憶體時最終清除 cgroup。到目前為止，在收集統計資料時仍然會考慮 cgroup。
從效能的角度來看，他們犧牲了記憶體來換取效能：透過留下一些快取記憶體來加速初始清理。這可以。當核心使用最後的快取記憶體時，cgroup最終會被清除，因此不能稱為「洩漏」。不幸的是，搜尋機制的具體實現 memory.stat 在這個核心版本（4.9）中，加上我們伺服器上的大量內存，意味著恢復最新的快取資料和清除cgroup殭屍需要更長的時間。
事實證明，我們的一些節點有太多 cgroup 殭屍，導致讀取和延遲超過一秒。
cadvisor 問題的解決方法是立即釋放整個系統中的 dentry/inode 緩存，這會立即消除主機上的讀取延遲和網路延遲，因為清除快取會打開快取的 cgroup 殭屍頁面，並且它們也會被釋放。這不是解決方案，但它證實了問題的原因。
事實證明，在較新的核心版本（4.19+）中，呼叫效能得到了提高 memory.stat，因此切換到該核心解決了問題。同時，我們擁有工具來檢測 Kubernetes 叢集中有問題的節點，優雅地耗盡它們並重新啟動它們。我們梳理了所有集群，找到延遲足夠高的節點並重新啟動它們。這使我們有時間更新其餘伺服器上的作業系統。
總結
由於此錯誤使 RX NIC 佇列處理停止了數百毫秒，因此它同時導致短連線上的高延遲和中間連線延遲，例如 MySQL 請求和回應資料包之間的延遲。
了解和維護最基本系統（例如 Kubernetes）的效能對於基於這些系統的所有服務的可靠性和速度至關重要。您運行的每個系統都受益於 Kubernetes 效能改進。
來源： www.habr.com