Cái đồng hồ báo xăng trên xe rất giỏi một việc và rất tệ một việc khác. Nó cho bạn biết bình đầy hay vơi — tuyệt vời khi kim còn ở giữa. Nhưng lúc kim chạm vạch đỏ, nó chỉ nói được đúng một chữ: "hết". Nó không nói bạn đang tiêu xăng nhanh hay chậm, còn đi được bao xa, hay bình có đang rò. Vạch đỏ là vạch đỏ, dù bạn đang bò trong thành phố hay đạp ga trên cao tốc. Rất nhiều cảnh báo giám sát Redis mắc đúng cái tật ấy: chúng đặt trên một đại lượng có trần, và đúng vào lúc mọi thứ tệ nhất thì con số ghim ở trần và không nói thêm được gì. Bài này đo để chỉ ra dòng INFO nào báo sớm, dòng nào báo muộn, và dòng nào không báo gì cả.

INFO trả về hơn hai trăm dòng. Ta đo xem dòng nào đáng tin.

used_memory dừng ở 100% và ở đó mãi

Tôi nạp dữ liệu đều tay vào một Redis giới hạn 64 MB với chính sách allkeys-lru:

Giây used_memory % maxmemory Khoá bị đuổi mỗi giây
2 10.787.720 16,1% 0
8 37.418.432 55,8% 0
14 65.074.352 97,0% 0
16 67.142.720 100,1% 12.339
18 67.122.448 100,0% 15.102
24 67.122.240 100,0% 15.870

Từ giây 16 trở đi, tỉ lệ phần trăm không còn nói gì nữa. Nó ghim ở 100% dù tình hình tệ đến đâu — đúng như cái kim xăng ở vạch đỏ.

Cảnh báo đặt trên used_memory / maxmemory > 90% cho bạn đúng 2 giây báo trước — từ 97% ở giây 14 lên 100% ở giây 16. Với tốc độ nạp thật của một hệ thống production, cửa sổ đó có thể rộng hơn, nhưng bản chất không đổi: đó là chỉ số bão hoà, không phải chỉ số cảnh báo.

Cái nói lên mức độ nghiêm trọng là tốc độ đuổi khoá: 0 → 12.339 → 15.870 mỗi giây. Con số đó tiếp tục tăng khi tình hình xấu đi, còn phần trăm thì không. Nên cảnh báo đúng là:

rate(redis_evicted_keys_total[5m]) > 0

Bất kỳ giá trị nào lớn hơn 0 đều đáng nhìn, vì nó nghĩa là bộ đệm đang vứt đi thứ nó vừa nhận.

Bốn nguồn cho cùng một lệnh chậm

Redis có bốn cách nhìn vào hiệu năng lệnh, và chúng trả lời bốn câu hỏi khác nhau.

INFO commandstats — lệnh nào tốn nhất

cmdstat_keys: calls=2   usec_per_call=11576.50
cmdstat_get : calls=200 usec_per_call=0.06

get 0,06 µs so với keys 11.576 µs — chênh gần 200.000 lần. Độ trễ trung bình toàn cục không bao giờ thấy điều này; commandstats thấy ngay. Đây là nơi bắt đầu mọi cuộc điều tra hiệu năng: sắp xếp theo usec_per_call × calls để biết loại lệnh nào đang ăn hết luồng duy nhất.

INFO latencystats — phân bố, không phải trung bình

keys: p50=11206.655  p99=13762.559

Redis 7 thêm mục này, và nó là thứ commandstats thiếu: trung bình che mất đuôi. Một lệnh có p50 0,1 ms và p99 50 ms là vấn đề mà usec_per_call không hiện.

LATENCY LATEST — thời điểm có sự cố

command  1788208869  13 ms  max 13 ms

Ghi lại sự kiện vượt ngưỡng latency-monitor-threshold, kèm dấu thời gian. Dùng để trả lời "lúc 3 giờ sáng có gì bất thường không".

SLOWLOG GET — chính xác lệnh nào

13732 us  keys *  127.0.0.1:49110

Đây là nguồn duy nhất cho bạn tham số thật và địa chỉ khách. Ba nguồn kia nói loại lệnh; cái này nói ai gọi và gọi gì.

Mười chỉ số đáng đưa lên bảng điều khiển

Chỉ số Vì sao
evicted_keys (tốc độ) Bộ nhớ đầy, đo được ở trên
keyspace_misses / (hits+misses) Tỉ lệ trượt bộ đệm
instantaneous_ops_per_sec Tải hiện tại
connected_clients so với maxclients Trần kết nối (phần 31)
blocked_clients Worker đang chờ, và có đang tăng bất thường không
mem_fragmentation_ratio kèm used_memory Chỉ có nghĩa khi dữ liệu đủ lớn (phần 10)
rdb_changes_since_last_save Lượng sẽ mất nếu chết ngay (phần 18)
master_repl_offset trừ offset bản sao Lượng sẽ mất khi chuyển đổi (phần 21)
rejected_connections Đã chạm maxclients
latency_percentiles_usec_* Đuôi độ trễ theo lệnh

Ba chỉ số gây hiểu nhầm

used_memory_rss và tỉ lệ phân mảnh. Như đo ở phần 10: một instance gần rỗng có tỉ lệ 16,59 và hoàn toàn khoẻ. Chỉ đọc nó khi used_memory đã đủ lớn, và ưu tiên allocator_frag_bytes.

Độ trễ trung bình. Phần 11 đo được: một lệnh KEYS đẩy max lên 263 ms trong khi p50 gần như không đổi. Trung bình che mất đúng thứ người dùng cảm nhận.

connected_clients một mình. Con số này ổn định không có nghĩa mọi thứ ổn — có thể là các kết nối rò rỉ đang giữ chỗ, như phần 31. Đọc kèm idle trong CLIENT LIST.

Ba cảnh báo tối thiểu

Nếu chỉ đặt được ba, đây là ba:

1. rate(evicted_keys) > 0                    bo nho da day
2. rdb_changes_since_last_save > <nguong>    dang khong duoc luu
3. rejected_connections tang                 da cham maxclients

Cả ba đều là sự kiện rời rạc chứ không phải ngưỡng trên một đại lượng liên tục — và đó chính là điểm mạnh của chúng: chúng không có vấn đề "ghim ở 100%" như phần trăm bộ nhớ.

Cách lấy chỉ số

INFO là một lệnh rẻ nhưng không miễn phí: nó duyệt vài cấu trúc và sinh ra một chuỗi vài KB. Gọi mỗi giây từ mười bộ thu thập là một khoản tải thật trên luồng duy nhất. Gọi INFO mỗi 10–15 giây là đủ cho gần như mọi mục đích. Với INFO all (gồm commandstats và latencystats) thì chi phí cao hơn nữa — chúng duyệt toàn bộ bảng lệnh.

Và CONFIG RESETSTAT xoá commandstats, latencystats và các bộ đếm. Hữu ích để đo một cửa sổ sạch, nhưng nó cũng làm mọi bộ thu thập khác thấy con số nhảy về 0 — đừng gõ nó trên production khi có ai đang theo dõi.

Mẫu số chung: cảnh báo trên cái có trần, hay trên cái không có trần

Cái bẫy "phần trăm bộ nhớ ghim ở 100%" không riêng gì Redis — nó là hệ quả của việc chọn nhầm loại đại lượng để cảnh báo. Một chỉ số bão hoà (utilization) bị chặn trong khoảng 0–100%: nó mô tả tốt lúc hệ còn khoẻ, nhưng chạm trần là hết thông tin, và trần lại đúng là vùng bạn cần thông tin nhất. Một chỉ số tốc độ hay hàng đợi (rate, counter, queue length) không có trần trên: nó cứ thế leo khi mọi thứ xấu đi, nên vẫn còn nói được điều gì đó ngay giữa cơn cháy.

Trong thế giới Java, đây đúng là chuyện heap: % heap used áp sát 100% ngay trước khi OOM và dính ở đó trong khi ứng dụng vật vã full-GC liên tục — con số phần trăm không phân biệt "sắp căng" với "đã chết". Cái nói lên mức nghiêm trọng là những đại lượng không trần: tần suất Full GC, tổng thời gian dừng GC mỗi phút, tốc độ cấp phát (allocation rate) và promotion rate. Cảnh báo trên chúng thấy được đường dốc, chứ không chỉ thấy cái vách.

Trong Go, cùng hình dạng: % CPU hay lượng heap sống chạm trần rồi im, còn thứ tiếp tục leo là số goroutine đang chờ, độ dài gcPauseNs, và độ trễ scheduler — hàng đợi, không phải mức chiếm dụng.

Còn ở cơ sở dữ liệu, đây là khác biệt giữa "connection pool đang dùng 100%" (bão hoà, đứng im ngay khi bắt đầu có vấn đề) và "số request đang chờ một kết nối" hoặc "số kết nối bị từ chối mỗi giây" (hàng đợi, cứ leo mãi) — cũng đúng như disk % used so với iowait, hay CPU 100% so với load average (độ dài run-queue). Phương pháp USE gọi tên hai vế này: Utilization bão hoà, Saturation thì không.

Mẫu số chung: đại lượng có trần trên mô tả tốt trạng thái bình thường nhưng câm lặng đúng lúc chạm trần — mà chạm trần chính là lúc có sự cố; còn đại lượng dạng tốc độ hoặc hàng đợi không bị chặn nên vẫn phản ánh mức nghiêm trọng khi hệ đã quá tải. Vì thế câu hỏi đúng khi đặt một cảnh báo không phải "ngưỡng bao nhiêu phần trăm" mà là "con số này có bị chặn trên không — nếu có, khi nó chạm trần tôi còn biết được gì". Cảnh báo trên cái đang tràn ra ngoài (khoá bị đuổi, kết nối bị từ chối, request nằm chờ), đừng cảnh báo trên cái đang đầy dần — vì cái đầy dần sẽ ngừng kể chuyện đúng lúc câu chuyện trở nên đáng nghe nhất.

Muốn tự lấy bức tranh đầy đủ trong một lệnh:

redis-cli info | grep -E \
  'used_memory:|maxmemory:|evicted_keys|expired_keys|keyspace_hits|keyspace_misses|connected_clients|blocked_clients|rejected_connections|instantaneous_ops_per_sec|rdb_changes_since_last_save|master_repl_offset'

Rồi tìm lệnh đang ăn nhiều thời gian nhất:

redis-cli info commandstats | python3 -c '
import sys, re
rows = []
for line in sys.stdin:
    m = re.match(r"cmdstat_(\S+?):calls=(\d+),usec=(\d+),usec_per_call=([\d.]+)", line)
    if m: rows.append((int(m.group(3)), m.group(1), int(m.group(2)), float(m.group(4))))
rows.sort(reverse=True)
print("%10s  %10s  %12s  %s" % ("tong (s)", "so lan", "us moi lan", "lenh"))
for usec, name, calls, per in rows[:10]:
    print("%10.3f  %10d  %12.2f  %s" % (usec/1e6, calls, per, name))
'

Kết quả trên chính instance vừa đo:

  tong (s)      so lan    us moi lan  lenh
     0.046           4      11576.50  keys
     0.010           2       4786.00  eval
     0.000           5         70.00  info
     0.000         200          0.06  get

Cột đầu là tổng số giây CPU mà mỗi loại lệnh đã tiêu. Dòng đầu bảng là thứ đang chiếm luồng duy nhất của bạn — và nó thường không phải lệnh bạn đoán. Ở đây, 4 lệnh keys tốn nhiều CPU hơn 200 lệnh get gấp hàng nghìn lần.

Phần sau: nhật ký lệnh chậm — cách bắt và cách đọc.