Chẩn đoán pod chậm

Pod hỏng hẳn thì dễ: có STATUS, có sự kiện, có mã thoát. Pod chạy được nhưng chậm khó hơn nhiều, vì mọi thứ đều hiện màu xanh.

Hai pod, cùng mã, khác mỗi limits.cpu

Cùng một máy chủ HTTP băm dữ liệu rồi trả lời. Một pod giới hạn 1 CPU, một pod giới hạn 100m.

Hai lần đầu, p50 gần như bằng nhau — 4,9 so với 3,9 ms. Nhìn vào con số trung vị thì pod bị bóp trông hoàn toàn bình thường.

p95 thì chênh 23 lần.

Vì sao đúng ~96 ms

Con số đó không ngẫu nhiên. Bộ lập lịch CFS chia thời gian thành chu kỳ 100 ms; limits.cpu: 100m nghĩa là mỗi chu kỳ được dùng 10 ms.

Yêu cầu nào rơi vào đầu chu kỳ, khi hạn ngạch còn nguyên, thì chạy xong ngay — đó là p50. Yêu cầu nào tiêu hết hạn ngạch giữa chừng thì phải đợi hết chu kỳ, và chu kỳ là 100 ms.

Nên độ trễ không phân bố đều: nó có hai cụm, một cụm nhanh và một cụm chậm gần đúng bằng chu kỳ. Trung bình cộng của hai cụm đó là một con số không mô tả trải nghiệm của ai cả.

Lần thứ ba cho thấy chỗ tệ hơn: tải kéo dài thì hạn ngạch không kịp hồi, và ngay cả p50 cũng sập xuống 96,7 ms.

Vì sao đồ thị CPU không thấy gì

Đọc cpu.stat của hai pod sau khi đo:

usage_usec gần như bằng nhau — cùng lượng công việc thì cùng lượng CPU, tất nhiên.

Đó chính là vấn đề: đồ thị "CPU usage" trên mọi bảng điều khiển vẽ đúng con số này. Hai pod trông y hệt nhau trên đồ thị, trong khi một cái chậm hơn 23 lần.

Bằng chứng nằm ở nr_throttled: 36 trên 50 chu kỳ bị chặn, tổng 3,28 giây bị treo.

Chỉ số nên đưa lên bảng điều khiển:

rate(container_cpu_cfs_throttled_periods_total[5m])
  / rate(container_cpu_cfs_periods_total[5m])

Trên 25% là có vấn đề. Ở phép đo trên, tỷ lệ là 72%.

Và đọc trực tiếp không cần Prometheus:

kubectl exec <pod> -- cat /sys/fs/cgroup/cpu.stat

Đây là lệnh đầu tiên nên gõ khi ai đó nói "ứng dụng chậm mà CPU vẫn thấp". Câu "CPU vẫn thấp" chính là triệu chứng, không phải bằng chứng ngoại phạm.

Xác nhận mà không khởi động lại pod

Từ Kubernetes 1.33, sửa được tài nguyên của pod đang chạy:

kubectl patch pod <ten> --subresource=resize --type=merge \
  -p '{"spec":{"containers":[{"name":"c",
       "resources":{"requests":{"cpu":"1"},"limits":{"cpu":"1"}}}]}}'

Đo được:

cpu.max   10000 100000  ->  100000 100000
p95       95,9 ms       ->  4,1 ms
restarts  0             ->  0

Pod không khởi động lại — cùng tuổi, cùng số restart, cùng địa chỉ IP. Trước đây đổi resources là pod bị dựng lại, và dựng lại thì mất luôn trạng thái đang gỡ: bộ nhớ đệm nguội, kết nối đứt, và nếu lỗi khó tái hiện thì có khi mất hẳn cơ hội.

Giờ nó thành một phép thử: đổi limit, đo lại, đổi về. Một phút, không ai bị ảnh hưởng.

Quy trình khi "ứng dụng chậm"

Thứ tự này loại trừ được phần lớn khả năng bằng bốn lệnh:

# 1. Bị bóp CPU?  -- nguyên nhân phổ biến nhất, và vô hình nhất
kubectl exec <pod> -- cat /sys/fs/cgroup/cpu.stat

# 2. Sắp OOM?  -- kernel thu hồi liên tục cũng làm chậm
kubectl exec <pod> -- sh -c 'grep -E "^(anon|inactive_file) " /sys/fs/cgroup/memory.stat; cat /sys/fs/cgroup/memory.max'

# 3. Chậm ở mạng hay ở ứng dụng?  -- so từ trong pod với từ ngoài
kubectl exec <pod> -- wget -qO- -T5 http://127.0.0.1:8080/    # chính nó
kubectl exec <pod-khac> -- wget -qO- -T5 http://<svc>/        # qua Service

# 4. Node có đang quá tải không?
kubectl top nodes

Bước 3 phân đôi bài toán: nếu gọi vào 127.0.0.1 đã chậm thì lỗi ở ứng dụng hoặc ở CPU; nếu chỉ chậm khi đi qua Service thì lỗi ở DNS, ở kube-proxy, hoặc ở một pod backend hỏng trong nhóm endpoint.

Bước 2 đáng làm dù memory.current còn xa limit: khi phần anon tiến sát limit, kernel bắt đầu thu hồi bộ đệm tệp liên tục, và ứng dụng chậm đi rất nhiều trước khi bị OOM. Trên đồ thị thì đó là một pod "chưa chạm limit" nên không ai nghi.

Ba nguyên nhân hay bị bỏ sót

Đặt limits.cpu bằng requests.cpu cho mọi thứ. Nghe kỷ luật, nhưng nó biến mọi đợt tăng tải ngắn thành độ trễ đuôi. Với dịch vụ phục vụ người dùng, cân nhắc bỏ hẳn limits.cpu và chỉ giữ requests — requests mới là thứ scheduler dùng, và nó vẫn bảo đảm phần chia tối thiểu khi node bận.

Đo bằng trung bình. Trung bình của phép đo trên là khoảng 20 ms — không mô tả cả cụm nhanh lẫn cụm chậm. Luôn xem p95 và p99.

Probe cũng bị bóp. livenessProbe chạy trong cùng cgroup, nên pod bị bóp nặng có thể trượt probe rồi bị giết — và bạn nhận được một CrashLoopBackOff che mất nguyên nhân thật là hiệu năng.

Thử ba mươi giây

Xếp hạng mọi pod theo tỷ lệ bị bóp CPU:

for p in $(kubectl get pods -A -o jsonpath='{range .items[?(@.status.phase=="Running")]}{.metadata.namespace}/{.metadata.name}{"\n"}{end}'); do
  ns=${p%%/*}; n=${p##*/}
  v=$(kubectl exec -n "$ns" "$n" -- sh -c \
    'awk "/^nr_periods/{a=\$2} /^nr_throttled/{b=\$2} END{if(a>0) printf \"%d %d\", b*100/a, a}" /sys/fs/cgroup/cpu.stat' 2>/dev/null)
  [ -n "$v" ] && echo "$v $p"
done | sort -rn | awk '$1>0 {printf "%3d%% bi bop  (%s chu ky)  %s\n", $1, $2, $3}'

Con số này là tích luỹ từ lúc container khởi động, nên nó phẳng hơn tỷ lệ theo thời gian thật — pod bị bóp dữ dội trong mười phút cao điểm mỗi ngày sẽ hiện ra một con số nhỏ. Thấy vài phần trăm cũng đáng xem, đừng chỉ tìm số lớn.

Phần sau: chẩn đoán sự cố mạng — từ pod không gọi được pod tới Service trả về lỗi lúc được lúc không.