来源:彭伟
cnblogs.com/qhca/p/9347604.html
大家经常出现同步调用Redis超时的问题,但改成异步之后发现错误非常少了,但却可能通过前后记日志之类的发现Redis命令非常慢。
PS: 以后代码都在Windows bash中运行,StackExchange.Redis版本为1.2.6
先快速重现问题和解决问题,大家先运行下面的代码
public static async Task Main(string[] args)
{
ThreadPool.SetMinThreads(8, 8);
using (var connection = await ConnectionMultiplexer.ConnectAsync("localhost"))
{
connection.PreserveAsyncOrder = false;
var db = connection.GetDatabase(0);
var sw = Stopwatch.StartNew();
await Task.WhenAll(Enumerable.Range(0, 10)
.Select(_ => Task.Run(() =>
{
db.StringGet("aaa");
Thread.Sleep(1000);
})));
Console.WriteLine(sw.ElapsedMilliseconds);
}
}
运行发现抛出StackExchange.Redis.RedisTimeoutException,为什么呢?是因为当前工作线程根本不够用,同步等待时已经超时。
具体请看源代码(https://github.com/StackExchange/StackExchange.Redis/blob/fb4a630843045164df856a923c46d1c4cb256977/StackExchange.Redis/StackExchange/Redis/ConnectionMultiplexer.cs#L2015)
如果将上面的ThreadPool.SetMinThreads(8, 8)改成ThreadPool.SetMinThreads(100, 100)呢?是不是不抛异常了呢。
再说异步接口变慢的问题,大家先运行下面的代码:
public static async Task Main(string[] args)
{
var tcs = new TaskCompletionSource();
var sw = Stopwatch.StartNew();
Console.WriteLine($"Main1: , ThreadId: ");
var task = Task.Run(() =>
{
Thread.Sleep(10);
Console.WriteLine($"Run1: , ThreadId: ");
tcs.TrySetResult(true);
Console.WriteLine($"Run2: , ThreadId: ");
Thread.Sleep(10000);
});
var a = tcs.Task.ContinueWith(_ => { Console.WriteLine($"a: , ThreadId: "); });
var b = tcs.Task.ContinueWith(_ => { Console.WriteLine($"b: , ThreadId: "); });
var c = tcs.Task.ContinueWith(_ => { Console.WriteLine($"c: , ThreadId: "); });
await tcs.Task;
Console.WriteLine($"Main2: , ThreadId: ");
Thread.Sleep(100);
await Task.Delay(10);
Console.WriteLine($"Main3: , ThreadId: ");
}
最终输出结果发现Run1和Main2是使用相同的线程吧,而Run2的ElapsedMilliseconds基本上就是在Run1的基础上加100。
然后再回到调用Redis代码上
static async Task Main(string[] args)
{
ThreadPool.SetMinThreads(100, 100);
using (var connection = await ConnectionMultiplexer.ConnectAsync("localhost"))
{
var db = connection.GetDatabase(0);
var sw = Stopwatch.StartNew();
await Task.WhenAll(Enumerable.Range(0, 10)
.Select(_ => Task.Run(async () =>
{
await db.StringGetAsync("aaa");
Thread.Sleep(100);
})));
Console.WriteLine(sw.ElapsedMilliseconds);
}
}
你们发现输出是100多还是1000多?为什么?原来是因为sdk中有一个特殊的设置,要保护异步代码执行的顺序,然后我们在GetDatabase行之前加一个代码connection.PreserveAsyncOrder = false;
然后再运行一次看看结果是多少呢?通过上面再做代码基本上可以确定异步慢是和TaskCompletionSource和关系的,具体请看sdk的源代码(https://github.com/StackExchange/StackExchange.Redis/blob/fb4a630843045164df856a923c46d1c4cb256977/StackExchange.Redis/StackExchange/Redis/CompletionManager.cs#L37)。
总结上面两点,简单得通过SetMinThreads和connection.PreserveAsyncOrder = false可以解决绝大部分问题,但更多其他深层次的问题怎么发现呢?
下面就要介绍StackExchange.Redis两个神器ConnectionCounters和IProfiler
1、通过connection.GetCounters().Interactive获得的对象之后其中有三个属性非常有用
public class ConnectionCounters
{
///
/// Operations that have been requested, but which have not yet been sent to the server
///
public int PendingUnsentItems { get; }
///
/// Operations that have been sent to the server, but which are awaiting a response
///
public int SentItemsAwaitingResponse { get; }
///
/// Operations for which the response has been processed, but which are awaiting asynchronous completion
///
public int ResponsesAwaitingAsyncCompletion { get; }
}
每个属性表示当前redis连接的待完成的命令当前所处的状态。通过字面意思就可以知道PendingUnsentItems表示已经进行待发送队列还未发送出去的命令;SentItemsAwaitingResponse表示已经发送出去但还没有收到响应结果的命令;ResponsesAwaitingAsyncCompletion则表示已经收到响应的命令,但还没有调用TaskCompletionSource().TrySetResult()的命令。
其中PendingUnsentItems和SentItemsAwaitingResponse过大的原因基本上是因为网络阻塞了,你需要检查一下网络带宽或者redis的value是否很大。
ResponsesAwaitingAsyncCompletion则是因为await之后的代码,如上面示例中的代码,线程占用了很长的同步时间,需要优化代码和将PreserveAsyncOrder设置为false。
2、ConnectionCounters分析的是一个线程的瞬时状态,而IProfiler则可以跟踪一个请求总共执行了多少的redis命令以及他们分别使用了多长时间,具体细节请大家写代码体验。
参考文档(https://stackexchange.github.io/StackExchange.Redis/Profiling)
发现问题就需要解决问题,也就需要深层次得去学习才能解决问题。我不喜欢写文章,但发现最近有好几篇说redis超时的问题,最终我还是想把自己的踩坑的心得分享给大家。
这在里说一个好消息,那就是StackExchange.Redis 2.0已经从重构了异步队列,使用管道方式解决异步慢的问题。
看完本文有收获?请转发分享给更多人
关注「DotNet」,提升.Net技能
领取专属 10元无门槛券
私享最新 技术干货