redis读数据超时问题查询

一、Redis超时问题排查

客户端设置了超时时间为200ms, 应用端反馈超时情况，并提供的超时日志。

逐个排查：
1. Redis慢查询：并没有发现慢查询
2. Redis日志：没有什么异常，也没什么RDB和AOF重写
3. 机器：观察cpu，内存，网络，负载，本地IO都正常
4. 唯一以前怀疑的是网络，按理说这个流量也不是很大，进行简单分析。

redis-cli
redis-cli是个比较好的方法来测redis的延迟，为此我们用下面的api来测试，发现会出现200ms的情况。

具体原因猜测：机房之间的带宽有限，据说只有50M，这台机器本身流量就有点大而且是台虚机。
./redis-cli --latency-history -h 192.168.9.39 -p 6379
min: 0, max: 1, avg: 0.07 (1480 samples) -- 15.00 seconds range
min: 0, max: 1, avg: 0.06 (1481 samples) -- 15.00 seconds range
min: 0, max: 1, avg: 0.07 (1479 samples) -- 15.00 seconds range
min: 0, max: 1, avg: 0.07 (1480 samples) -- 15.00 seconds range
min: 0, max: 1, avg: 0.07 (1480 samples) -- 15.00 seconds range
min: 0, max: 2, avg: 0.09 (1480 samples) -- 15.00 seconds range
min: 0, max: 1, avg: 0.07 (1481 samples) -- 15.01 seconds range
min: 0, max: 5, avg: 0.07 (1480 samples) -- 15.00 seconds range
min: 0, max: 1, avg: 0.07 (1479 samples) -- 15.00 seconds range
min: 0, max: 10, avg: 0.07 (1480 samples) -- 15.01 seconds range
min: 0, max: 7, avg: 0.07 (1480 samples) -- 15.00 seconds range
min: 0, max: 10, avg: 0.08 (1479 samples) -- 15.01 seconds range
min: 0, max: 2, avg: 0.07 (1481 samples) -- 15.01 seconds range
min: 0, max: 1, avg: 0.07 (1480 samples) -- 15.01 seconds range
min: 0, max: 1, avg: 0.07 (1480 samples) -- 15.00 seconds range
min: 0, max: 1, avg: 0.07 (1480 samples) -- 15.01 seconds range
min: 0, max: 1, avg: 0.06 (1481 samples) -- 15.00 seconds range
min: 0, max: 1, avg: 0.06 (1480 samples) -- 15.01 seconds range
min: 0, max: 1, avg: 0.06 (1480 samples) -- 15.01 seconds range
min: 0, max: 1, avg: 0.08 (1480 samples) -- 15.01 seconds range
min: 0, max: 10, avg: 0.08 (1479 samples) -- 15.00 seconds range
min: 0, max: 202, avg: 0.68 (1277 samples) -- 15.01 seconds range  
min: 0, max: 7, avg: 0.07 (1480 samples) -- 15.01 seconds range
min: 0, max: 9, avg: 0.08 (1480 samples) -- 15.00 seconds range
min: 0, max: 1, avg: 0.06 (1481 samples) -- 15.01 seconds range

总结：
以上就是查询超时的基本思路，分配机器要考虑流量的合理性，注意网络通信稳定性。


二、慢日志说明

Slowlog

命令用于读取和重新设置redis慢查询日志.
概述

redis 慢查询日志, 是系统记录那些超过指定查询时间的日志. 执行的时间不包括和客户端的IO操作，和响应时间等, 而只是实际redis执行命令的时间(只是线程执行命令时，阻塞不能在接受处理其他请求花费的时间)

慢查询日志有两个参数：

1.     slowlog-log-slower-than: 单位微妙，指定redis执行命令的最大时间，超过将记录到慢查询日志中,不接受负值，如果设置为0，每条命令都要记录到慢查询日志中.
2.     slowlog-max-len: 设置慢查询日志长度，如果慢查询日志已经到最大值，如果有新命令需要记录，就将最老那条记录删除.

读取慢查询日志

慢查询日志是会存储在内存中, 没有文件存储慢查询日志内容. 所以在获取慢查询日志时候，会响应非常快. 对性能影响很小.

获取慢查询日志可以使用 slowlog get 命令, 将会所有的慢查询记录. 获取指定数量的慢查询使用：

slowlog get N
实例
redis 127.0.0.1:6379> slowlog get 2
1) 1) (integer) 439
   2) (integer) 1472526432
   3) (integer) 258198
   4) 1) "KEYS"
      2) "uploadFile_*"
2) 1) (integer) 438
   2) (integer) 1472526385
   3) (integer) 259900
   4) 1) "KEYS"
      2) "uploadFile_*"

slowlog get 返回值说明

返回的每个慢查询实体，都由四个字段组成

•     第一个字段是每个慢查询唯一标识。
•     处理完命令后的，Unix 时间戳
•     执行改名了所需要的时间，单位微妙
•     命令的参数列表，是个数组类型

每个慢查询实体的ID都是唯一的，而且不会被重新设置，只会在redis重启后才会重置它.
查看当前慢查询日志长度

Slowlog len
清空慢查询日志内容

SLOWLOG RESET


参考文档：
Redis 响应延迟问题排查
http://www.oschina.net/translate/redis-latency-problems-troubleshooting
记一次Redis超时排查
http://carlosfu.iteye.com/blog/2275659
美团在Redis上踩过的一些坑-1.客户端周期性出现connect timeout
http://carlosfu.iteye.com/blog/2254566