问题描述
StackExchange.Redis在使用线程池后,偶尔会出现Timeout awaiting response 或者 No connection is available to service this operation的异常消息,完整的错误异常如:
StackExchange.Redis.RedisTimeoutException: Timeout awaiting response (outbound=0KiB, inbound=0KiB, 20016ms elapsed, timeout is 20000ms), command=GET, next: GET VMD:LVSHFXXXXXXXX, inst: 0, qu: 10, qs: 1167, aw: True, bw: Inactive, rs: ReadAsync, ws: Writing, in: 0, serverEndpoint: Unspecified/xxxxredis.redis.cache.chinacloudapi.cn:6380, mgr: 9 of 10 available, clientName: RD00xxxxxxxx, IOCP: (Busy=3,Free=997,Min=200,Max=1000), WORKER: (Busy=367,Free=1680,Min=300,Max=2047), v: 2.0.601.3402 (Please take a look at this article for some common client-side issues that can cause timeouts: |
StackExchange.Redis.RedisConnectionException: No connection is available to service this operation: SET VMD:LVSHFXXXXXXXX; IOCP: (Busy=4,Free=996,Min=200,Max=1000), WORKER: (Busy=344,Free=1703,Min=300,Max=2047), Local-CPU: n/a |
Timeout performing GET orderfortjw, inst: 5, mgr: Inactive, err: never, queue: 10, qu: 0, qs: 15, qc: 0, wr: 0, wq: 0, in: 1826, ar: 0, clientName: RD00155D45335D, serverEndpoint: Unspecified/order-api.redis.cache.chinacloudapi.cn:6380, keyHashSlot: 545, IOCP: (Busy=0,Free=1000,Min=100,Max=1000), WORKER: (Busy=35,Free=23764,Min=100,Max=23764) |
StackExchange.Redis.RedisTimeoutException: Timeout performing GET orderforvb1dm6g0m, inst: 6, mgr: Inactive, err: never, queue: 913, qu: 0, qs: 913, qc: 0, wr: 0, wq: 0, in: 65536, ar: 0, clientName: RD00155D45352D, serverEndpoint: Unspecified/order-api.redis.cache.chinacloudapi.cn:6380, keyHashSlot: 1255, IOCP: (Busy=0,Free=1000,Min=2,Max=1000), WORKER: (Busy=3,Free=23764,Min=2,Max=23764) |
问题原因
在异常消息中,最重要的信息为IOCP, WORKER两部分, 这是因为CLR(Common Language Runtime,公共语言运行库)有两种类型的线程, Worker" 和 "I/O Completion Port" (IOCP) 线程。
- WORKER: 对于诸如处理
Task.Run(…)
或ThreadPool.QueueUserWorkItem(…)
方法这类事务,请使用WORKER线程。 需要在后台线程上进行工作时,CLR 中的各种组件也会使用这些线程。 - IOCP: 进行异步 IO(例如从网络进行读取)时,使用 IOCP 线程
一旦Busy线程数达到Min线程数,ThreadPool 便会将插入新线程的速率限制为每 500 毫秒一个线程。如果Busy的工作多于配置的Min设置,则在处理某些工作时会出现一定的延迟,因为 ThreadPool 会等待发生以下两种情况之一。
- 一个现有线程释放,以便处理工作。
- 在 500 毫秒内没有任何现有线程释放,因此会创建一个新线程。
基本上,这意味着Busy线程数大于Min线程数,在应用程序处理网络流量之前可能需要付出 500 毫秒延迟。 如果 IOCP 或WORKER线程受到限制,则 StackExchange.Redis 可能会超时等异常。
- StackExchange.Redis.RedisTimeoutException: Timeout awaiting response ... IOCP: (Busy=3,Free=997,Min=200,Max=1000), WORKER: (Busy=367,Free=1680,Min=300,Max=2047)
- StackExchange.Redis.RedisConnectionException ... IOCP: (Busy=4,Free=996,Min=200,Max=1000), WORKER: (Busy=344,Free=1703,Min=300,Max=2047)
如以上的错误消息中,IOCP的线程数工作正常,没有超过Min值。但是Worker的线程数Busy状态分别为367,344都大于最小值(Min)300,所以出现RedisTimeoutException或RedisConnectionException异常。
解决办法
建议将 IOCP 和Worker 线程的最小配置值设置为大于默认值。此设置会影响复杂应用程序其他部分的性能,因此每个应用需要按照其特定需求来微调此设置。开始时设置为 200 或 300 会比较好,随后可进行测试并根据需要进行调整。
在.NET中的设置示例如下:
private readonly int minThreads = 200; void Application_Start(object sender, EventArgs e) { // Code that runs on application startup AreaRegistration.RegisterAllAreas(); RouteConfig.RegisterRoutes(RouteTable.Routes); BundleConfig.RegisterBundles(BundleTable.Bundles); ThreadPool.SetMinThreads(minThreads, minThreads); }
参考资料
Redis 有关线程池增长的重要详细信息: https://docs.microsoft.com/zh-cn/azure/azure-cache-for-redis/cache-management-faq#important-details-about-threadpool-growth