继续每天的知心姐姐时间,这次客户邮件说,CPU 使用率飙升,同时 GET/LLEN 等命令,都要执行几十毫秒。看了一下慢日志,我去:

Id:900909 When:(1/1/2019 6:16:15 PM) Duration:41564us Command:(Llen PRIVATE ARG)
Id:900908 When:(1/1/2019 6:16:14 PM) Duration:17041us Command:(get PRIVATE ARG)
Id:900907 When:(1/1/2019 6:16:14 PM) Duration:51032us Command:(get PRIVATE ARG)
Id:900906 When:(1/1/2019 6:16:12 PM) Duration:49292us Command:(get PRIVATE ARG)
Id:900905 When:(1/1/2019 6:16:11 PM) Duration:56329us Command:(Llen PRIVATE ARG)
Id:900904 When:(1/1/2019 6:16:10 PM) Duration:10562us Command:(get PRIVATE ARG)
Id:900903 When:(1/1/2019 6:16:10 PM) Duration:35680us Command:(get PRIVATE ARG)
Id:900902 When:(1/1/2019 6:16:10 PM) Duration:16367us Command:(get PRIVATE ARG)
Id:900901 When:(1/1/2019 6:16:10 PM) Duration:29851us Command:(Llen PRIVATE ARG)
Id:900900 When:(1/1/2019 6:16:08 PM) Duration:29050us Command:(get PRIVATE ARG)

甘总教育我们,出了问题,不要惊慌。先看下 QPS, 20k 左右,不算低了。

比较奇怪的时命中率,非常之低,仅有10%左右。

赶紧跟客户反映了一下,估计是使用姿势的问题。Cache 这么用,是极大的浪费。

另外一个异常情况就是响应大小,20KB。Redis 对于大文件的支持很有限,具体可以参见:What is the ideal value size range for redis? Is 100KB too large?

这命中率和响应体的问题都说服不了客户,他们还在追问为什么 CPU 这么嗨。继续调查,看到页错误的时候,心里暗喜:

来看 Redis 官方关于 Lantency 的解释:

If a Redis page is moved by the kernel from the memory to the swap file, when the data stored in this memory page is used by Redis (for example accessing a key stored into this memory page) the kernel will stop the Redis process in order to move the page back into the main memory. This is a slow operation involving random I/Os (compared to accessing a page that is already in memory) and will result into anomalous latency experienced by Redis clients.

正是用户的访问方式,导致页面被频繁置换,引发了此次的延迟问题。

扩展一下,导致页错误的可能原因还有:

  1. 分配的内存不够用了。
  2. Redis 里的大部分数据闲置着,没有访问,本文遇到的就是这种情况。
  3. 大量的 I/O 也可能是罪魁祸首。文件被 cache 住,需要用到系统缓存,导致了 swap。RDB 和 AOF 都可能产生大文件。

收工。