ZMonster's Blog 巧者劳而智者忧，无能者无所求，饱食而遨游，泛若不系之舟

Redis 性能分析与优化

2015-12-16

Redis 简介

Redis 是一个 key-value 内存存储系统，并且支持丰富的数据结构，包括:

  1. string
  2. list
  3. hash table
  4. set(集合)
  5. zset(有序集合)

其体量很小，但却支持丰富的数据结构和相应的操作方式，是一个非常好的工具。

然而像很多工具一样，Redis 也有一些坑，我也是被坑过一段时间的……

当然，这里就不对 Redis 的数据结构及操作做过多说明了，可能的话单独再写一篇文章，不过考虑网上类似的文章实在不少，估计是不会去写了。

从遇到的问题说起

目前我负责的一个项目使用着 Redis ，在 10 月中下旬的时候发现往 Redis 写数据的定时任务频繁 timeout ，同时从同一个 Redis 读数据的线上项目的 log 也显示经常一些读操作耗时增长了十倍甚至更多。

发现问题的时候，首先怀疑是不是自己代码里的逻辑写得有问题，花了两天时间把相关的代码翻来覆去看了好几遍，虽然是有一些地方有待优化，但这些地方的问题是不足以引发前面说的问题的。而在我为代码中每个 Redis 操作都加上了超时检测后，发现甚至连 get 这样的操作都会发生超时(所取的 key 的 value 并不大)后，就已经大致明白应该和我的代码没有关系。

找 SA 要来 Redis server 所在服务器上的帐号后开始跑脚本往 Redis 写数据，同时监控 Redis server 的 log ，最后发现了这么一条 log: 

[25206] 04 Nov 17:34:41.090 * Asynchronous AOF fsync is taking too long (disk is busy?). Writing the AOF buffer without waiting     for fsync to complete, this may slow down Redis.

this may slow down Redis !

原来，这个 Redis server 的持久化方式是 RDB+AOF，而上述警告信息是因为 AOF 操作造成的。有了这个明确的警告信息后，再去网上搜索就找到了不少类似的案例:

  1. how redis took us offline and what we did about it
  2. logs of timeout in someone second #248

各种迹象都说明我遇到的问题是和这条警告信息密切相关的，于是回过头重新启动脚本，并且监控 Redis server 日志中包含 "Asynchronous AOF fsync is taking too long" 的内容。经过一个下午的观察，确定超时错误与这条日志是同时出现的。

redisdebugger.png

最后的解决办法是在 Redis master 上关闭了 AOF。

用于分析 Redis 性能的一些命令(参数)

都是在解决上面提到的问题的过程中，所了解到的 tricks。

redis-cli 参数

  • –bigkeys 

    redis-cli -h <host> -p <port> -n <db> --bigkeys

    这条命令会从指定的 Redis DB 中持续采样，实时输出当时得到的 value 占用空间最大的 key 值，并在最后给出各种数据结构的 biggest key 的总结报告: 

    user $ redis-cli -h myhost -p 12345 --bigkeys

# Scanning the entire keyspace to find biggest keys as well as
# average sizes per key type.  You can use -i 0.1 to sleep 0.1 sec
# per 100 SCAN commands (not usually needed).

[00.00%] Biggest hash   found so far 'idx:同类项' with 1 fields
[00.00%] Biggest hash   found so far 'idx:格点' with 3 fields
[00.00%] Biggest hash   found so far 'idx:任意' with 14 fields
[02.29%] Biggest hash   found so far 'idx:设' with 16 fields
[02.29%] Biggest hash   found so far 'idx:4' with 69 fields
[04.45%] Biggest set    found so far 'indexed_word_set' with 1482 members
[05.93%] Biggest hash   found so far 'idx:c' with 159 fields
[11.79%] Biggest hash   found so far 'idx:的' with 196 fields

-------- summary -------

Sampled 1484 keys in the keyspace!
Total key length in bytes is 13488 (avg len 9.09)

Biggest    set found 'indexed_word_set' has 1482 members
Biggest   hash found 'idx:的' has 196 fields

0 strings with 0 bytes (00.00% of keys, avg size 0.00)
0 lists with 0 items (00.00% of keys, avg size 0.00)
2 sets with 1710 members (00.13% of keys, avg size 855.00)
1482 hashs with 6731 fields (99.87% of keys, avg size 4.54)
0 zsets with 0 members (00.00% of keys, avg size 0.00)

    这条命令给出的 "big key" ，是值得去分析一下的。

  • –latency, –latency-history

    这两条命令用来测试 Redis 服务端的响应延迟，–latency 的输出是这样的 

    min: 7, max: 1230, avg: 66.22 (89 samples)

    –latency-history 的输出是这样的: 

    min: 7, max: 3332, avg: 157.41 (91 samples) -- 15.23 seconds range
min: 6, max: 774, avg: 75.69 (176 samples) -- 15.10 seconds range
min: 7, max: 1631, avg: 93.49 (147 samples) -- 15.23 seconds range
min: 7, max: 714, avg: 67.90 (194 samples) -- 15.14 seconds range
min: 7, max: 809, avg: 95.09 (143 samples) -- 15.04 seconds range

    两者的区别在于前者显示的是持续的采样结果，而后者则只输出一段时间内的采样结果。

    用这两个参数可以判断客户端与服务端之间的网络通信造成的延迟对整体延迟的影响，方法是在 Redis Server 所在的服务器上使用 –latency/–latency-history 得到大致的延迟结果，然后在客户端所在机器上同样得到延迟情况进行对比。

redis-cli 子命令

  • slowlog 命令

    默认的 Redis server 配置中有这么两条: 

    slowlog-log-slower-than 10000
slowlog-max-len 128

    这两条配置会产生这样的效果: 如果一条命令的响应时间超过了 10000us (即 10ms) ，那么将会作为 "slow command" 被记录，并且将只保留最新的 128 条 记录。

    需要说明的是，这里所说的 响应时间 不包括客户端与服务端之间的通信开销，仅仅指命令在 Redis server 中的执行时间消耗。

    使用 slowlog 这个子命令可以获取当前的这些记录: 

    127.0.0.1:6379> slowlog get 3
1) 1) (integer) 26
   2) (integer) 1450253133
   3) (integer) 43097
   4) 1) "flushdb"
2) 1) (integer) 25
   2) (integer) 1450252804
   3) (integer) 33115
   4) 1) "flushdb"
3) 1) (integer) 24
   2) (integer) 1450248951
   3) (integer) 3328650
   4) 1) "flushdb"

    在不指定记录数量的情况下(slowlog get)，默认返回 10 条记录，每条记录包含四个字段，以下面这个为例来说明 

    1) (integer) 26
2) (integer) 1450253133
3) (integer) 43097
4) 1) "flushdb"

    第一个字段表示该条记录在所有慢日志中的序号，最新的记录被展示在最前面；

    第二个字段是这条记录被记录时的系统时间，可以用 date 命令来将其转换为友好的格式: 

    linusp $ date -d @1450253133
2015年 12月 16日 星期三 16:05:33 CST

    第三个字段表示这条命令的响应时间，单位为 us (微秒)；

    第四个字段为对应的 Redis 操作。

    因此上面这个例子的含义就是: 在 2015 年 12 月 16 日 16 时 5 分 33 秒执行的 flushdb 操作耗时 43ms ，因为超过了设定的值被记录到慢日志中。

  • info

    顾名思义，这个子命令用来获取 Redis server 的一些信息，这些信息按照内容被分成了很多部分，可以用额外的参数来单独获取，如下:

    参数名 说明
    server 获取 server 信息，包括 version, OS, port 等信息
    clients 获取 clients 信息，如客户端连接数等
    memory 获取 server 的内存信息，包括当前内存消耗、内存使用峰值
    persistence 获取 server 的持久化配置信息
    stats 获取 server 的一些基本统计信息，如处理过的连接数量等
    replication 获取 server 的主从配置信息
    cpu 获取 server 的 CPU 使用信息
    keyspace 获取 server 中各个 DB 的 key 的数量
    cluster 获取集群节点信息，仅在开启集群后可见
    commandstas 获取每种命令的统计信息，非常有用

    挑几个个人觉得有用的部分再详细说明一下.

    • info memory

      输出如下: 

      # Memory
used_memory:17348250392
used_memory_human:16.16G
used_memory_rss:14339567616
used_memory_peak:17348362312
used_memory_peak_human:16.16G
used_memory_lua:33792
mem_fragmentation_ratio:0.83
mem_allocator:jemalloc-3.0.0

      了解 Redis server 的内存占用是很有必要的

    • info keyspace

      输出如下: 

      db0:keys=52021100,expires=0,avg_ttl=0
db1:keys=520062,expires=0,avg_ttl=0
db2:keys=559810,expires=0,avg_ttl=0
db4:keys=513887,expires=0,avg_ttl=0

      由于 Redis 要为每个 key 维护一些入口信息，因此 key 会比 value 中的对象额外消耗一些内存，当 key 的数量太多的时候会多消耗不少内存。一些优化 Redis 内存占用的方法基本都是基于减少 key 的数量以及减少 key 的平均长度这两个思路。

      key 的数量太多时可以使用 hash 结构将 key 进行分隔成两部分来减少数量，当然这个要看是否能满足具体的业务、功能需求了。

    • info commandstats

      其输出如下: 

      cmdstat_get:calls=774811168,usec=2567380170,usec_per_call=3.31
cmdstat_set:calls=4616783,usec=17308580,usec_per_call=3.75
cmdstat_append:calls=290375669,usec=2051415709,usec_per_call=7.06
cmdstat_exists:calls=41374218,usec=72561479,usec_per_call=1.75
cmdstat_sadd:calls=60640,usec=540252,usec_per_call=8.91
cmdstat_sismember:calls=3,usec=16,usec_per_call=5.33
cmdstat_smembers:calls=1863495,usec=253706917,usec_per_call=136.15
cmdstat_incrby:calls=114499073,usec=157843782,usec_per_call=1.38
cmdstat_keys:calls=1,usec=79743,usec_per_call=79743.00
cmdstat_multi:calls=4618103,usec=6087466,usec_per_call=1.32
cmdstat_exec:calls=4618103,usec=2597435761,usec_per_call=562.45
cmdstat_replconf:calls=335,usec=512,usec_per_call=1.53
cmdstat_flushdb:calls=5,usec=842393,usec_per_call=168478.59
cmdstat_info:calls=825297,usec=39131868,usec_per_call=47.42
cmdstat_slowlog:calls=23,usec=22646,usec_per_call=984.61
......

      输出中包含处理过的每一种命令的调用次数、消耗的总 CPU 时间(单位 ms)以及平均 CPU 耗时，这对了解自己的程序所使用的 Redis 操作情况非常有用。

Redis 使用的一点点经验

  1. 管理好自己的 key，比如用一个 set 来存放所有同类型的 key，这样可以避免使用 keys 来获取该类型所有 key，由于 Redis 是单线程的，在数据量大的情况下将会阻塞 Redis 中其他的操作
  2. 如果不能避免使用 keys 操作，那么使用 scan 来替代，将遍历 Redis DB 中所有 key 的操作放到客户端来做，这样就不会导致其他操作被阻塞了
  3. 在数据量大的情况下，key 或 value 的微小的压缩也能带来不小的内存使用提高
  4. hash 结构是个好东西，但是它只支持一级 hash，所以如果需要使用多级 hash，那就进行序列化吧
  5. 注意客户端和服务端之间的网络通信情况(–latency/–latency-history)
  6. Redis 的 python 接口返回的 key 的类型和 value 中的最小结构的类型都是 string，记得转换成自己需要的类型
Naringu is designed by Rizky Ariestiyansyah
Copyright © 2024