受欢迎的博客标签

StackExchange.Redis性能调优(8)-解决Redis超时错误的问题

Published
Created: 2018年8月8日星期三 下午12:37:15 Latest updated:2019年2月4日星期一 下午9:22:06 views(2931)
  _logger.LogInformation($"{DateTime.Now.ToString()} 开始连接Redis数据库");
            var configurationOptions = ConfigurationOptions.Parse("127.0.0.1" + ":" + "6379");
            configurationOptions.SyncTimeout = int.MaxValue;
            configurationOptions.AllowAdmin = true;

            //解决redis超时问题  http://www.cnblogs.com/qhca/p/9347604.html
            ThreadPool.SetMinThreads(100, 100);

            ConnectionMultiplexer redis = ConnectionMultiplexer.Connect(configurationOptions);

            //解决redis超时问题
            redis.PreserveAsyncOrder = false;

            redis.GetServer("127.0.0.1", 6379).FlushDatabase(3);

   

 

大家经常出现同步调用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，为什么呢？是因为当前工作线程根本不够用，同步等待时已经超时。具体请看源代码

    如果将上面的ThreadPool.SetMinThreads(8, 8)改成ThreadPool.SetMinThreads(100, 100)呢？是不是不抛异常了呢。

 

    再说异步接口变慢的问题，大家先运行下面的代码：

复制代码
        public static async Task Main(string[] args)
        {
            var tcs = new TaskCompletionSource<bool>();
            var sw = Stopwatch.StartNew();

            Console.WriteLine($"Main1: {sw.ElapsedMilliseconds}, ThreadId: {Environment.CurrentManagedThreadId}");

            var task = Task.Run(() =>
            {
                Thread.Sleep(10);
                Console.WriteLine($"Run1: {sw.ElapsedMilliseconds}, ThreadId: {Environment.CurrentManagedThreadId}");
                tcs.TrySetResult(true);
                Console.WriteLine($"Run2: {sw.ElapsedMilliseconds}, ThreadId: {Environment.CurrentManagedThreadId}");
                Thread.Sleep(10000);
            });

            var a = tcs.Task.ContinueWith(_ => { Console.WriteLine($"a: {sw.ElapsedMilliseconds}, ThreadId: {Environment.CurrentManagedThreadId}"); });
            var b = tcs.Task.ContinueWith(_ => { Console.WriteLine($"b: {sw.ElapsedMilliseconds}, ThreadId: {Environment.CurrentManagedThreadId}"); });
            var c = tcs.Task.ContinueWith(_ => { Console.WriteLine($"c: {sw.ElapsedMilliseconds}, ThreadId: {Environment.CurrentManagedThreadId}"); });

            await tcs.Task;
            Console.WriteLine($"Main2: {sw.ElapsedMilliseconds}, ThreadId: {Environment.CurrentManagedThreadId}");
            Thread.Sleep(100);
            await Task.Delay(10);
            Console.WriteLine($"Main3: {sw.ElapsedMilliseconds}, ThreadId: {Environment.CurrentManagedThreadId}");
        }
复制代码

    最终输出结果发现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的源代码。

 

    总结上面两点，简单得通过SetMinThreads和connection.PreserveAsyncOrder = false可以解决绝大部分问题，但更多其他深层次的问题怎么发现呢？

 

    下面就要介绍StackExchange.Redis两个神器ConnectionCounters和IProfiler 

  1. 通过connection.GetCounters().Interactive获得的对象之后其中有三个属性非常有用
    复制代码
    public class ConnectionCounters
{
    /// <summary>
    /// Operations that have been requested, but which have not yet been sent to the server
    /// </summary>
    public int PendingUnsentItems { get; }

    /// <summary>
    /// Operations that have been sent to the server, but which are awaiting a response
    /// </summary>
    public int SentItemsAwaitingResponse { get; }

    /// <summary>
    /// Operations for which the response has been processed, but which are awaiting asynchronous completion
    /// </summary>
    public int ResponsesAwaitingAsyncCompletion { get; }
}
    复制代码

    每个属性表示当前redis连接的待完成的命令当前所处的状态。通过字面意思就可以知道PendingUnsentItems表示已经进行待发送队列还未发送出去的命令；SentItemsAwaitingResponse表示已经发送出去但还没有收到响应结果的命令；ResponsesAwaitingAsyncCompletion则表示已经收到响应的命令，但还没有调用TaskCompletionSource<T>().TrySetResult()的命令。
    其中PendingUnsentItems和SentItemsAwaitingResponse过大的原因基本上是因为网络阻塞了，你需要检查一下网络带宽或者redis的value是否很大。
    ResponsesAwaitingAsyncCompletion则是因为await之后的代码，如上面示例中的代码，线程占用了很长的同步时间，需要优化代码和将PreserveAsyncOrder设置为false。

  2. ConnectionCounters分析的是一个线程的瞬时状态，而IProfiler则可以跟踪一个请求总共执行了多少的redis命令以及他们分别使用了多长时间，具体细节请大家写代码体验。参考文档

 

    发现问题就需要解决问题，也就需要深层次得去学习才能解决问题。我不喜欢写文章，但发现最近有好几篇说redis超时的问题，最终我还是想把自己的踩坑的心得分享给大家。

    这在里说一个好消息，那就是StackExchange.Redis 2.0已经从重构了异步队列，使用管道方式解决异步慢的问题