iT邦幫忙

2026 iThome 鐵人賽

DAY 7
0

今天要做一件有點反直覺的事:故意不裝任何監控工具,只用 kubectl 去查昨天埋的那三個故障。

為什麼要花一天做一件註定失敗的事?因為我認為實際體驗一次少了工具的幫助,在環境中要手動查詢出問題是多困難的一件事情,這樣可以快速理解各個工具它們各自解決了哪一向具體的痛點。

所以今天要當一次沒有可觀測性的工程師。

打開我們設定的故障

kubectl set env deploy/pricing BUG_SILENT_DISCOUNT=true LEAK_KB_PER_REQUEST=64
kubectl set env deploy/catalog BUG_N_PLUS_ONE=true
kubectl get pods -w      # 等新的 Pod 起來,Ctrl-C 離開

今天要展示的就是「什麼都查不到」,所以三個故障一起開。

LEAK_KB_PER_REQUEST 是每處理一件商品要洩漏幾 KB,我調到 64,實測下來大約 4 分鐘出頭就會 OOMKilled 一次,剛好夠我們看到 RESTARTS 的數字往上跳。這裡主要是示範用途,真實的記憶體洩漏不會這麼快。

⚠️ 注意:明天記得關掉,不然裝 Prometheus 的時候 pricing 一直重啟,指標圖會全是斷點。

先看看叢集裡到底跑了什麼

在開始查之前,先把手上有的東西列一次。這也順便回答前面留下的一個問題:控制平面裡面到底跑了些什麼。

kubectl get pods -A          # -A 是看所有命名空間,包含系統自己的

https://ithelp.ithome.com.tw/upload/images/20260907/20180570kJ4YZbpEvz.png

default 那四個是我們自己的,剩下的都是叢集自己在跑的東西。

簡單講一下這些系統元件:

  • etcd:存整個叢集的狀態,所有資料都在這裡
  • kube-apiserver:所有指令的唯一入口,我們打的每一個 kubectl 都是在跟它講話
  • kube-scheduler:決定 Pod 要放到哪個節點
  • kube-controller-manager:負責在「實際狀態跟我們的願望不符」的時候去修正它,例如 Pod 掛了要補一個新的
  • CoreDNS:讓 http://pricing 這種名字解析得到,跑兩份是為了自己不要變成單點
  • kube-proxy:處理網路轉發,每個節點一份,所以有三個
  • kindnet:kind 自己的網路外掛,讓不同節點上的 Pod 能互相通,一樣每個節點一份
  • local-path-provisioner:kind 附的儲存空間分配器,之後 Prometheus 要存資料會用到它

前面四個的名字後面都直接掛著 obs-control-plane,也就是它們跑在控制平面那個節點上,這就是前面說「控制平面負責排程和維護叢集狀態」的具體長相。

平常我們不會去碰它們,只要知道它們的存在就好。

今天只會使用這幾個指令

指令 作用
kubectl get 現在有哪些東西、狀態是什麼
kubectl describe 某個東西的詳細資料,含最近發生的事件
kubectl logs 某個 Pod 印出來的文字
kubectl get events 叢集裡最近發生的事
kubectl exec 進到容器裡面下指令
kubectl top Pod 或節點當下的 CPU / 記憶體用量

最後一個現在還不能用,等一下會說為什麼。

查故障一:算錯價錢但不會回報錯誤

先看服務狀態:

kubectl get pods

全部 Running,看起來很健康。

那就看 log:

kubectl logs deploy/pricing --tail=50
{"service": "pricing", "path": "/price", "status": 200, "duration_ms": 70.1, "event": "request", "level": "info", "timestamp": "2026-09-07T09:54:11.711050Z"}
INFO:     10.244.2.4:41290 - "GET /price?product_id=P044 HTTP/1.1" 200 OK
{"service": "pricing", "path": "/price", "status": 200, "duration_ms": 61.6, "event": "request", "level": "info", "timestamp": "2026-09-07T09:54:11.774627Z"}
INFO:     10.244.2.4:41290 - "GET /price?product_id=P017 HTTP/1.1" 200 OK
...

一行警告都沒有,全部都是 200。

我第一個反應是故障沒開成功,跑去確認了一下環境變數,結果是好好的開著。真正的原因是這 50 行只涵蓋大約 2 秒,而且一半是 uvicorn 自己印的 access log,真正的請求大概只有 25 筆。50 個商品裡面只有 2 個查不到規則,25 筆抽中的期望值連 2 次都不到,抽到 0 次一點也不奇怪。

換句話說,我如果只是「看一下 log」,我會得到一個結論:這個服務很正常。

要找到它得用 grep:

kubectl logs deploy/pricing --tail=100000 | grep -c "discount rule not found"

https://ithelp.ithome.com.tw/upload/images/20260907/2018057017fv68gtmR.png

127 次。 線索一直都在,只是被大量的正常訊息埋著。

但是接下來發生的事情才是重點。我過一分鐘再跑一次同樣的指令,數字掉到剩下十幾,整份 log 也只剩兩百行不到。

我一開始以為自己指令打錯,查了才發現原因:pricing 這個 Pod 剛剛被殺掉重啟了,也就是等一下要講的故障三。而 kubectl logs 只給我「當前這個容器」的輸出,Pod 一換,計數就從零開始。

所以那個 127 到底代表什麼?它代表「上一個容器從出生到死掉之間累積的次數」。這個區間不是我選的,是 Pod 的壽命決定的。

換個方式問:我想知道「過去一小時發生幾次」,做得到嗎?

做不到。我沒辦法給 kubectl logs 一個時間範圍去數,它給我的區間是由容器的生死決定的。是變多還是變少?也不知道,沒有昨天的數字可以比。影響了幾筆訂單?一樣不知道,一筆訂單有好幾件商品,這 127 次可能集中在少數幾筆,也可能散在 127 筆不同的訂單裡。

還有一個更前面的問題:我為什麼會想到要去 grep 這個字串? 今天是因為故障是我自己埋的,所以我知道要找什麼。真實情況下沒有人回報異常、狀態全綠、也沒有錯誤,我根本不會打開 pricing 的 log。

順帶一提,上面那段輸出還看得到另一個問題:同一件事被印了兩遍,一行是我自己寫的 JSON,一行是 uvicorn 的純文字。格式混在一起,之後要拿去查詢的時候會很麻煩,這個後面講結構化日誌的時候會處理。

天花板一:kubectl logs 給我文字,不給我數字。 無法聚合、無法比較,答不出「多嚴重」。

查故障二:某些請求特別慢

這個更難,因為我甚至不知道它慢

kubectl 沒有任何一個指令會告訴我「這個服務的回應時間變長了」。它管的是 Pod 活著沒有,不管 Pod 回應得快不快。

假設今天有使用者抱怨,我知道要查了,那我能做的是:

kubectl logs deploy/catalog --tail=100

https://ithelp.ithome.com.tw/upload/images/20260907/201805707FpkZ1CqUZ.png

上半段是幾筆正常的小車:item_count 3、4、2,modebatchcalls 是 1,duration_ms 66 到 68 毫秒。下半段忽然變成一長串 GET /price?product_id=...,那就是一台大車走進 N+1 那條路,一件商品一次呼叫。

看起來好像查得出來對吧?但這裡要先承認一件事:modecalls 這兩個欄位是我自己寫進去的,因為故障是我埋的,我知道要記什麼。真實的服務不會有一個欄位貼心地告訴你「這次走的是壞掉的那條路」。把這兩個欄位拿掉,畫面上就只剩一堆 200。

而且就算有這兩個欄位,我還是看不出哪幾筆 GET /price 屬於同一次結帳。那 12 次呼叫在 log 裡就是 12 行各自獨立的紀錄,中間沒有任何東西把它們串起來。每秒有十筆結帳同時在跑,它們的 GET 交錯在一起,人腦拼不回來。

那延遲呢?我確實算得出來,duration_ms 就在 log 裡。但方法是這樣:

kubectl logs deploy/catalog --tail=100000 | grep '"path": "/items"' | python3 -c "..."

把 log 倒出來,自己寫一段程式去解 JSON、排序、抓百分位數。跑出來是這樣:

筆數 5246   P50 73ms   P95 718ms   P99 818ms   max 1766ms

P50 是 73 毫秒,跟批次路徑的 66 毫秒幾乎一樣;P95 卻是它的十倍。 這就是昨天說的長尾:多數人完全無感,少數人等了快一秒。昨天我用算的估「12 次乘以 60 毫秒大概 700 毫秒」,實測 P95 是 718,數字對上了。

但這組數字得來的方式本身就是問題。第一,kubectl 沒有算百分位數的能力,我得自己寫程式。第二,它只涵蓋容器活著的這段期間,跟剛才數 127 那次遇到的是同一個限制。第三,也是最麻煩的——我得先知道要算什麼。是我先知道故障在延遲上,才會去挑 duration_ms 來算。如果我什麼都不知道,我不會想到要做這件事。

天花板二:跨服務的請求,kubectl 沒辦法把它們關聯起來。

查故障三:記憶體洩漏

這個是三個裡面唯一「看得到」的。

kubectl get pods -w      # -w 會持續盯著看

跑一陣子之後,pricingRESTARTS 會從 0 變成 1。

kubectl describe pod -l app=pricing

這裡順便講一個很實用的小技巧:-l app=pricing 是用標籤來選取,不用複製 Pod 名字。Pod 名字後面那串是隨機的、每次重建都會變,手動複製很快就會煩。而這個標籤就是我們昨天在 manifest 裡寫的那三處之一,它除了讓 Service 找得到 Pod,也讓我們自己找得到。同一招在這幾個指令都能用:

kubectl logs -l app=pricing --tail=50
kubectl logs -l app=pricing --previous    # 重啟前那個容器的 log
kubectl delete pod -l app=pricing         # 砍掉讓它重建

https://ithelp.ithome.com.tw/upload/images/20260907/20180570EF8JX1yMS2.png

Last State 那一段寫得很清楚:TerminatedReason: OOMKilledExit Code: 137。137 是 128 加 9,9 就是 SIGKILL,代表它不是自己結束的,是被作業系統強制砍掉的。上限寫在下面的 Limits: memory: 512Mi,也就是昨天 manifest 裡設的那條線。

好,我知道它是因為記憶體不足被殺掉的。然後呢?

第一,我不知道記憶體是怎麼漲上去的。 是緩慢爬升還是瞬間暴衝?從什麼時候開始?describe 只給我兩個時間戳,Started 17:59:21Finished 18:03:43,中間那 4 分 22 秒發生了什麼,一片空白。

第二,Restart Count 已經是 5 了,但我只看得到最後一次。 前面那四次各撐了多久?是愈來愈快還是穩定的?如果我想確認「洩漏速度是固定的」,我需要五個區間,而 describe 只給我一個。

想看當下的用量要用這個:

kubectl top pod

但是在 kind 上這行會直接報錯,因為它需要另外裝一個叫 metrics-server 的元件,而且在 kind 上還要多加參數才裝得起來。

我決定不裝它,因為這件事本身就是今天的論點:連「看一眼現在用了多少記憶體」都要另外裝東西,而且就算裝了,它給的也只是當下這一秒的數字,不留歷史。

還有一個問題是重啟前的 log 消失了

kubectl logs deploy/pricing --previous

--previous 只能撈前一個。再重啟一次,最早那次的紀錄就永遠不見了。而記憶體洩漏這種問題,往往要對照好幾次重啟才看得出規律。

天花板三:kubectl 只有現在,沒有歷史。

把天花板整理一下

我需要的 kubectl 能給的
過去一小時發生幾次 只有一堆未經整理的文字
這個數字比昨天高嗎 沒有歷史,無從比較
這 12 行 log 是同一個請求嗎 沒有任何關聯資訊
記憶體是怎麼漲上去的 只有它死掉那一刻的快照
有問題的時候主動通知我 沒有這個功能

歸納起來是四句話:

  1. 只有現在,沒有歷史
  2. 只有文字,不能聚合
  3. 只有單點,無法跨服務關聯
  4. 只能被動查,不會主動通知

而這四句話剛好對應接下來要裝的四種東西:Prometheus 給我歷史與聚合、Loki 給我可以查詢的 log、追蹤系統給我跨服務的關聯、Alertmanager 給我主動通知。

但是 kubectl 不是沒用

免得誤會,kubectl 還是每天都會用的工具,而且有些事只有它能做:看叢集狀態、進容器裡面測試、改設定重新部署。上面那三次查故障,describelogs 也都確實給了我線索,只是線索到此為止。

它不適合的是回答「為什麼」跟「多嚴重」。這是分工,不是取代,後面二十幾天我還是天天在用它。

小結

今天一樣沒有裝任何東西,但是從明天開始裝的每一樣工具,我都能說出它在解上面哪一句話。

明天裝第一個:Prometheus。目標是把「只有現在,沒有歷史」這句劃掉。


上一篇
Day 6:在 K8s 上部署一個「會壞」的示範服務:三種故意埋進去的故障
系列文
從看得到到看得懂:30 天在自架 K8s 上實踐可觀測性與告警7
圖片
  熱門推薦
圖片
{{ item.channelVendor }} | {{ item.webinarstarted }} |
{{ formatDate(item.duration) }}
直播中

尚未有邦友留言

立即登入留言