15天玩轉redis —— 第七篇同事的一次緩存操做引發對慢查詢的認識

時間 2019-11-13

標籤 15天 redis 第七同事一次緩存引發查詢認識欄目 Redis 简体版

原文原文鏈接

上個星期同事作一個業務模塊，須要將一個80M的數據存入到redis緩存中，想法老是好的，真操做的時候遇到了HSet超時，咱們使用的是C#的redis

StackExchange.Redis驅動。express

  <redisCacheClient allowAdmin="true" ssl="false" connectTimeout="5000" abortConnect="false" database="0">
    <hosts>
      <add host="192.168.202.129" cachePort="6379"/>
    </hosts>
  </redisCacheClient>

因爲封裝代碼啥的都是網上下載的，第一反應就是把上面的「connectTimeout」設爲5000 * 60 =3min，可是絲毫沒有用處，也就是3min沒有起緩存

到做用，碼蛋的，這可怎麼辦？？？只能硬着頭皮去看StackExchange的源碼，終於在1個小時的地毯式搜索中找到了兩處兇殺現場，以下所示：測試

接着我發現其中的 timeoutMilliseconds 和 this.multiplexer.RawConfig.ResponseTimeout的取值決定着是否會拋異常，感謝感謝，接下來我繼續大數據

順藤摸瓜，找到了兩個屬性的賦值處。優化

當我看到了上面的syncTimeout.GetValueOrDefault(1000)的時候一顆懸着的心也就放下了，也懶得改了，直接將這裏的1000改爲1000*60*5ui

就好啦，commit代碼後讓同事再運行下看看效果。。。終於撥開迷霧見青天，數據出來啦，遺憾的是，讀寫操做須要耗時3s，雖然問題表面上看似this

解決了，可是問題來了，3s延時真的不是什麼好事情，咱們都知道redis是單線程的，那就意味着什麼？？？意味着這3s的時間內其餘redis客戶端spa

是阻塞的。。。雖然內心是這麼想的，可是仍是存有一點僥倖心理以爲不是這樣的，不過仍是決定作一個實驗看一看。線程

一：阻塞演示

　　我決定開一個線程將一個txt中140M的數據插入到redis的hashset中，同時我開另外一個線程1秒鐘一次的從string中獲取數據,同時記錄下獲

取時間，若是獲取string的時間間隔太大，說明阻塞產生了，想法就是這樣，說幹就幹。。。

 1  System.Threading.Tasks.Task.Factory.StartNew(() =>
 2                     {
 3                         try
 4                         {
 5                             var content = File.ReadAllText(@"D:\20151120-13\20151120-13.log", Encoding.Default);
 6 
 7                             Console.WriteLine("主線程 讀取txt內容完畢，準備插入redis {0}", DateTime.Now);
 8                             var result = CacheUtil.CacheClient.HashSet("myredis", "mykey", content);
 9 
10                             Console.WriteLine("主線程 插入Redis 成功:{0} , {1}", result, DateTime.Now);
11 
12                             var r = CacheUtil.CacheClient.HashGet<string>("myredis", "mykey");
13 
14                             Console.WriteLine("主線程,讀取Redis成功，總長度{0}, {1}", r.Length, DateTime.Now);
15                         }
16                         catch (Exception ex)
17                         {
18                             Console.WriteLine(ex.Message);
19                         }
20                     });
21 
22                     System.Threading.Tasks.Task.Factory.StartNew(() =>
23                     {
24                         try
25                         {
26                             var result = CacheUtil.CacheClient.Add<string>("myfruits", "asdfasdfasdfasdfasd");
27 
28                             for (int i = 0; i < 10; i++)
29                             {
30                                 var content = CacheUtil.CacheClient.Get<string>("myfruits");
31 
32                                 Console.WriteLine("第 {0} 次讀取 {1} ,{2}", i, content, DateTime.Now);
33 
34                                 Thread.Sleep(1000);
35                             }
36                         }
37                         catch (Exception ex)
38                         {
39                             Console.WriteLine(ex.Message);
40                         }
41                     });

讀取string的線程被Hashset阻塞了6s之多，很恐怖，這個就屬於典型的慢查詢，它的慢果真阻塞了其餘client，接下來就拿着問題找同事，第一個想

法就是問同事爲何要存這麼大的數據，得知爲了不海量運算必需要存這麼大數據以後，沒撤只能從假定80M的數據量作優化，第二個想法就是拆，

既然是80M的數據，我能夠拆成8份10M的數據，這樣有兩個好處，第一個不會太拖長Hset的時間，第二個盡最大努力不阻塞其餘client，可是呢，同

事不想改動代碼，還要問我還有其餘解決方案不？？？而後我就提了一個下下策，隔離你的緩存業務，既然你都是存儲大數據，那我專門給你開一個

redis去存儲緩存，幾秒鐘就幾秒鐘吧，估計對他業務還可以承受，我可不能讓個人主redis由於這個吊毛業務掛了。。。

二：慢查詢日誌

　　自從發生這個事情以後，我就有一個想法了，我是否是也須要記錄一下主redis中那些「慢操做」的命令，而後找到相關的業務方，否則的話，阻塞

就很差玩了。而後就直接在redis手冊中就找到了相關的命令。

SLOWLOG subcommand [argument]

什麼是 SLOWLOG

Slow log 是 Redis 用來記錄查詢執行時間的日誌系統。

查詢執行時間指的是不包括像客戶端響應(talking)、發送回覆等 IO 操做，而單單是執行一個查詢命令所耗費的時間。

另外，slow log 保存在內存裏面，讀寫速度很是快，所以你能夠放心地使用它，沒必要擔憂由於開啓 slow log 而損害 Redis 的速度。

設置 SLOWLOG

Slow log 的行爲由兩個配置參數(configuration parameter)指定，能夠經過改寫 redis.conf 文件或者用 CONFIG GET 和 CONFIG SET 命令對它們動態地進行修改。

第一個選項是 slowlog-log-slower-than ，它決定要對執行時間大於多少微秒(microsecond，1秒 = 1,000,000 微秒)的查詢進行記錄。

好比執行如下命令將讓 slow log 記錄全部查詢時間大於等於 100 微秒的查詢：

CONFIG SET slowlog-log-slower-than 100

而如下命令記錄全部查詢時間大於 1000 微秒的查詢：

CONFIG SET slowlog-log-slower-than 1000

另外一個選項是 slowlog-max-len ，它決定 slow log 最多能保存多少條日誌， slow log 自己是一個 FIFO 隊列，當隊列大小超過 slowlog-max-len 時，最舊的一條日誌將被刪除，而最新的一條日誌加入到 slow log ，以此類推。

如下命令讓 slow log 最多保存 1000 條日誌：

CONFIG SET slowlog-max-len 1000

從上面這段話中，大概看出了兩個屬性： slowlog-log-slower-than 和 slowlog-max-len，爲了測試方便，我就不config set了，直接改掉

redis.conf文件便可。。。

# The following time is expressed in microseconds, so 1000000 is equivalent
# to one second. Note that a negative number disables the slow log, while
# a value of zero forces the logging of every command.
slowlog-log-slower-than 0

# There is no limit to this length. Just be aware that it will consume memory.
# You can reclaim memory used by the slow log with SLOWLOG RESET.
slowlog-max-len 10