CPU 100% ảo do hypervisor: khi top không nói thật

Một tình huống khó chịu trên Cloud VPS: dashboard Grafana báo cùng lúc nhiều máy "CPU gần 100%" hoặc mất hẳn dữ liệu giám sát, gồm cả balancer, máy database và minion. Lượng truy cập không tăng, không có dấu hiệu lỗi ở ứng dụng hay MySQL, và vài phút sau mọi thứ tự trở lại bình thường. Thủ phạm không nằm trong máy ảo: cả nhóm máy đã bị hypervisor giữ lại. Tài liệu này hướng dẫn cách chứng minh điều đó bằng dữ liệu, và giải thích vì sao top, công thức CPU Busy của Grafana, và cả chỉ số steal time đều không cho thấy sự thật trong trường hợp này.

Triệu chứng

• Một số máy có CPU Busy chạm gần 100%, load tăng vọt.
• Một số máy khác có biểu đồ bị đứt (GAP) vài phút, rồi vọt lên gần 100% ngay trước khi trở lại bình thường.
• Các máy bị ảnh hưởng thuộc nhiều vai trò khác nhau nhưng cùng biểu hiện trong đúng một khung giờ.
• Có thể kèm chỉ số gây nhiễu, như SWAP 100% trên một minion.

Nhìn biểu đồ, phản xạ đầu tiên là nghĩ tới DDoS hoặc một truy vấn MySQL nặng. Cả hai đều sai, và hiếm ai nghĩ ngay tới hypervisor.

Quy trình điều tra

Bước 1: có phải tải web tăng đột biến?

Đếm request theo phút trên balancer, quanh khung giờ sự cố. Cẩn thận với glob: nếu mỗi site ghi log riêng vào <domain>.access (không có đuôi .log), lệnh /var/log/nginx/*access*.log chỉ đọc file mặc định và cho ra một con số nhỏ đến vô lý. Đếm trên mọi file, gồm cả file đã nén:

zcat -f /var/log/nginx/*.access* \
  | awk '{print substr($4, 2, 17)}' | sort | uniq -c | tail -30

Dấu hiệu điển hình của máy bị giữ: lượng request mỗi phút giảm chứ không tăng trong lúc sự cố (balancer xử lý chậm hẳn), rồi dồn ra một đợt khi được thả. Không có dấu hiệu tấn công.

Bước 2: đọc bộ đếm CPU thô thay vì biểu đồ

Panel CPU Busy của dashboard Node Exporter Full dùng công thức:

1 - rate(node_cpu_seconds_total{mode="idle"}[1m])

Truy vấn thẳng Prometheus để lấy giá trị thô của bộ đếm idle trên một máy bị ảnh hưởng:

node_cpu_seconds_total{mode="idle", instance="balancer:9100"}[10m]

Trên máy 1 vCPU, scrape 30 giây, mỗi mẫu bình thường tăng khoảng 20 giây idle. Khi bị hypervisor giữ, bộ đếm idle gần như đứng yên qua nhiều mẫu liên tiếp. rate(idle) bằng 0, nên công thức trả về 100%. Thực tế, hypervisor gần như không cho vCPU của máy ảo được chạy.

Bước 3: tìm dấu vết trong kernel log

Trong journalctl -k của các máy bị ảnh hưởng thường có cùng một loại cảnh báo:

kernel: clocksource: Long readout interval, skipping watchdog check:
    cs_nsec: 2803125000 wd_nsec: 2803118000

Watchdog đồng hồ của kernel đọc hai lần cách nhau vài giây, trong khi chu kỳ bình thường chỉ khoảng nửa giây. Giữa hai lần đọc đó, vCPU của máy ảo không được cấp chu kỳ nào. Đây là dấu hiệu quen thuộc của máy ảo bị hypervisor tạm dừng hoặc bị kẹt I/O ở tầng lưu trữ bên dưới.

Bước 4: dựng dòng thời gian từ cron

Tác vụ chạy mỗi phút như schedule:run của Laravel bình thường xong trong vài giây. Journal của máy bị giữ cho thấy một mẫu rất đặc trưng:

T+0s     CRON[...]: session opened for user www-data
T+59s    CRON[...]: session opened for user www-data
T+103s   CRON[...]: session opened for user www-data
T+244s   CRON[...]: session opened for user www-data
T+281s   CRON[...]: session closed   ← cả bốn phiên cùng đóng
T+281s   CRON[...]: session closed
T+282s   CRON[...]: session closed
T+286s   CRON[...]: session closed

Các phiên mở rải rác suốt mấy phút nhưng cùng đóng trong vài giây. Máy không chậm dần: nó bị hypervisor giữ lại, rồi được thả ra cùng lúc. Trên một số máy, node_exporter còn không trả lời được Prometheus, nên biểu đồ bị đứt thay vì chạm 100%.

Bước 5: đối chứng cả cụm để khoanh vùng hypervisor

Nếu do hypervisor, các máy cùng host vật lý sẽ cùng bị, các máy khác thì không. Dùng một truy vấn khác: cộng mọi mode CPU (user, system, idle, iowait, steal…) rồi chia cho số vCPU. Bình thường tổng này xấp xỉ 1, vì mỗi giây thực của một vCPU phải được kernel ghi vào một mode nào đó.

# tỷ lệ thời gian CPU được kernel ghi nhận (bình thường ≈ 1)
sum by (instance) (rate(node_cpu_seconds_total[1m]))
  /
count by (instance) (node_cpu_seconds_total{mode="idle"})

# steal time: thời gian hypervisor lấy mất mà kernel máy ảo biết
rate(node_cpu_seconds_total{mode="steal"}[1m])

Khi hai nhóm tách bạch như vậy, dù cùng dải mạng và cùng loại dịch vụ, điều duy nhất giải thích được là nhóm bị ảnh hưởng nằm chung một host vật lý, tức chung một hypervisor, hoặc chung một vùng lưu trữ.

Điểm đáng chú ý nhất là cột steal. Steal time là phần thời gian vCPU sẵn sàng chạy nhưng hypervisor đang cho máy khác dùng CPU thật. Khi máy ảo bị dừng hẳn, phần thời gian bị lấy đi thường không vào steal, cũng không vào iowait. Nó biến mất khỏi mọi bộ đếm.

Vì sao top, vmstat, mpstat không thấy hypervisor

top, vmstat và mpstat đều đọc /proc/stat, cùng bộ đếm mà node_exporter đọc. Cột %st của chúng được tính trên tổng thời gian đã ghi nhận, không phải trên thời gian thực. Nếu trong 30 giây thực, kernel chỉ kịp ghi một ít user, system, softirq và gần như không có idle, top sẽ hiện phần lớn là us và sy, 0% id, chỉ khoảng 1% st. Nghĩa là "CPU bận, không có steal". Máy đang bị giữ thì phiên SSH chạy top cũng treo theo. Muốn thấy sự cố do hypervisor, phải nhìn từ một máy khác, như Prometheus đặt ngoài nhóm bị ảnh hưởng.

Nguyên nhân gốc: hypervisor dừng cấp CPU

Nhóm máy ảo bị hypervisor dừng hoặc gần như dừng cấp CPU, cùng lúc. Khi được thả, cron, timer, I/O và request bị dồn chạy cùng lúc, tạo một đỉnh tải thật rất ngắn, rồi về bình thường.

Chỉ nhà cung cấp mới xem được log của host vật lý. Giả thuyết hay gặp nhất khi sự cố rơi vào một mốc giờ tròn và cả nhóm cùng bị: một tác vụ định kỳ ở tầng host như snapshot volume, backup máy ảo hoặc live-migration, làm đóng băng I/O hoặc vCPU lâu hơn bình thường.

Hai hướng nghi sai đáng ghi lại:

• SWAP 100%: swapfile nhỏ đã đầy từ trước trong khi RAM available còn nhiều là trạng thái tĩnh, không liên quan sự cố. Nên nới swapfile để khỏi gây nhiễu lần sau.
• "Clock skew, server sai giờ": phản hồi hay gặp khi thấy chữ clocksource trong log. Kiểm tra timedatectl (System clock synchronized: yes) và so timestamp giữa các máy là loại trừ được. Dòng Long readout interval là hệ quả của việc vCPU bị giữ, không phải nguyên nhân. Nhiều máy độc lập cũng không thể cùng "sai giờ" trong đúng vài phút rồi cùng hết.

Khắc phục

Trong lúc sự cố: thường không cần can thiệp, hệ thống tự hồi phục. Điều cần làm là không làm sai: không restart MySQL, không chặn IP, không tối ưu truy vấn cho một sự cố nằm ở hypervisor.

Sau sự cố: gửi nhà cung cấp một gói bằng chứng gồm:

• Danh sách máy bị ảnh hưởng và khung giờ (ghi rõ múi giờ).
• Dòng clocksource kèm cs_nsec trong kernel log.
• Dòng thời gian cron cho thấy các phiên cùng đóng.
• Bảng đối chứng hai nhóm máy với tỷ lệ thời gian được ghi nhận.

Kèm đề nghị kiểm tra log hypervisor của host vật lý, lịch snapshot/backup quanh khung giờ đó, và dời các tác vụ ấy sang giờ thấp điểm.

Checklist phòng ngừa

• Thêm panel "thời gian CPU được ghi nhận" bên cạnh CPU Busy, dùng truy vấn ở bước 5. Giá trị tụt xa dưới 1 ở nhiều máy cùng lúc là dấu hiệu của hypervisor, không phải của ứng dụng.
• Cảnh báo theo nhóm, không theo từng máy: khi từ ba máy trở lên có tỷ lệ trên dưới 0,5 trong cùng một phút, gửi một cảnh báo "nghi sự cố hypervisor" thay vì hàng loạt cảnh báo CPU cao.
• Không tin một mình steal time. Steal hữu ích khi host bị chia CPU quá nhiều. Khi máy ảo bị dừng hẳn, steal có thể gần như không tăng.
• Đặt Prometheus ngoài vùng ảnh hưởng, để nó còn ghi được GAP và timeout của node_exporter, vốn cũng là một tín hiệu.
• Khi thấy CPU 100% đồng loạt: đếm request trên mọi file log, đọc bộ đếm thô, tìm clocksource trong journalctl -k, xem cron có đóng phiên cùng lúc không, so với nhóm máy bình thường.

Bài học

• CPU Busy tính từ idle là phép suy luận, không phải phép đo. Khi máy ảo bị hypervisor dừng, "không có idle" không có nghĩa là "đang bận".
• Kiểm tra lại cả lệnh dùng để loại trừ giả thuyết. Một glob sai cho ra con số sai, dù đôi khi kết luận vẫn tình cờ đúng.
• Đối chứng là bằng chứng mạnh nhất khi cần chứng minh lỗi nằm ở hypervisor của nhà cung cấp: hai nhóm máy cùng dải mạng, một nhóm hỏng, một nhóm không.
• Phân biệt với CPU 100% thật. Ở bài CPU 100% trên MySQL: lock chờ nhau và index còn thiếu, CPU bận thật vì truy vấn quét nhiều dòng và chờ lock. Ở đây không có tải web, còn cả nhóm máy cùng "bận" trong đúng một khoảng thời gian.

Cách đi từng tầng khi điều tra có trong bài điều tra sự cố nhiều tầng. Ý nghĩa của từng mode CPU trong /proc/stat, kể cả steal, được mô tả trong tài liệu /proc của Linux kernel. Metric node_exporter có trong hướng dẫn node exporter của Prometheus.

Bài tiếp theo

WAF chặn nhầm và trùng rule ID làm sập balancer. Một ngoại lệ Coraza cho một site, một rule ID bị dùng lại, và mọi site trên balancer cùng ngừng phục vụ.