记5.28大促压测的性能优化—线程池相关问题
目录：
创新互联主营肇东网站建设的网络公司,主营网站建设方案,app软件开发公司,肇东h5微信小程序开发搭建,肇东网站营销推广欢迎肇东等地区企业咨询
1.环境介绍
2.症状
3.诊断
4.结论
5.解决
6.对比java实现
废话就不多说了，本文分享下博主在5.28大促压测期间解决的一个性能问题，觉得这个还是比较有意思的，值得总结拿出来分享下。
博主所服务的部门是作为公共业务平台，公共业务平台支持上层所有业务系统（2C、UGC、直播等）。平台中核心之一的就是订单域相关服务，下单服务、查单服务、支付回调服务，当然结算页暂时还是我们负责，结算页负责承上启下进行下单、结算、跳支付中心。每次业务方进行大促期间平台都要进行一次常规压测，做到心里有底。
在压测的上半场，陆续的解决一些不是太奇怪的问题，定位到问题时间都在计划内。下单服务、查单服务、结算页都顺利压测通过。但是到了支付回调服务压测的时候，有个奇怪的问题出现了。
1.环境介绍
我们每年基本两次大促，5.28、双12。两次大促期间相隔时间也就只有半年左右，所以每次大促压测都会心里有点低，基本就是摸底检查下。因为之前的压测性能在这半年期间一般不会出现太大的性能问题。这前提是因为我们每次发布重大的项目的时候都会进行性能压测，所以压测慢慢变得常规化、自动化，遗漏的性能问题应该不会太多。性能指标其实在平时就关注了，而不是大促才来临时抱佛脚，那样其实为时已晚，只能拆东墙补西墙。
应用服务器配置，物理机、32core 、168g、千兆网卡、压测网络带宽千兆、IIS 7.5、.NET 4.0，这台压测服务器还是很强的。
我们本地会用JMeter进行问题排查。由于这篇文章不是讲怎么做性能压测的，所以其他跟本篇文章关系的不大的情况就不介绍了。包括压测网络隔离、压测机器的配置和节点数等。
我们的要求，顶层服务在200并发下，平均响应时间不能超过50毫秒，TPS要到3000左右。一级服务，也就是最底层服务的要求更高，商品系统、促销系统、卡券系统平均响应时间基本保持在20毫秒以内才能接受。因为一级服务的响应速度直接决定了上层服务的响应速度，这里还要去掉一些其他的调用开销。
2.症状
这个性能问题的症状还是比较奇怪的，情况是这样的：200并发、2000loop，40w的调用量。一开始前几秒速度是比较快的，基本上TPS到了2500左右。服务器的CPU也到了60左右，还是比较正常的，但是几秒过后处理速度陡降，TPS慢慢在往下掉。从服务器的监控中发现，服务器的CPU是0%消耗。这很吓人，怎么突然不处理了。TPS掉到100多了，显然会一直掉下去。等了大概不到4分钟，一下子CPU又上来了。TPS可以到2000左右。
我们仔细分析查看，首先JMeter的吞吐量的问题，吞吐量是按照你的请求平均响应时间计算的，所以这里看起来TPS是慢慢在减慢其实已经基本停止了。如果你的平均响应时间为20毫秒，那么在单位时间内你的吞吐量是基本可以计算出来的。
症状主要就是这样的，我们接下来对它进行诊断。
3.诊断
开始通过走查代码，看能不能发现点什么。
这是支付回调服务，代码的前后没有太多的业务处理，鉴权检查、订单支付状态修改、触发支付完成事件、调用配送、周边业务通知（这里有一部分需要兼容老代码、老接口）。我们首先主要是查看对外依赖的部分，发现有redis读写的代码，就将redis的部分代码注释掉在进行压测试试看。结果一下子就正常了，这就比较奇怪了，redis是我们其他压测服务共用的，之前压测怎么没有问题。没管那么多了，可能是代码的执行序列不同，在并发领域里面，这也说得通。
我们再通过打印redis执行的时间，看处理需要多久。结果显示，处理速度不均匀，前面的很快，后面的时间都在5-6秒，虽然不均匀但是很有规律。
所以我们都认为是redis的相关问题，就开始一头扎进去检查redis的问题了。开始对redis进行检查，首先是开启Wireshark TCP连接监控，检查链路、redis服务器的Slowlog查看处理时间。redis客户端库的源代码查看（redis客户端排除原生的StackExhange.Redis的有两层封装，一共三层），重点关注有锁的地方和thread wait的地方。同时排查网络问题，再进行压测的时候ping redis服务器看是否有延迟。（此时是晚上21点左右，这个时候的大脑情况大家都懂的。）
就是这样地毯式的搜查，以为是肯定能定位到问题。但是我们却忽视了代码的层次结构，一下子专到了太细节的地方，忽视了整体的架构（指开发架构，因为代码不是我们写的，对代码周边情况不是太了解）。
先看redis服务器的建立情况，tcp抓包查看，连接建立正常，没有丢包，速度也很快。redis的处理速度也没问题，slowlog查看基本get key也就1毫秒不到。（这里需要注意，redis的处理时间还包括队列里等待的时间。slowlog只能看到redis处理的时间，看不到blocking的时间，这里面还包括redis的command在客户端队列的时间。）
所以打印出来的redis处理时间很慢，不纯粹是redis服务器的处理时间，中间有几个环节需要排查的。
经过一番折腾，排查，问题没定位到，已是深夜，精力严重不足了，也要到地铁最后一班车发车时间了，再不走赶不上了，下班回家，上到最后一班地铁没耽误三分钟~~。
重整思路，第二天继续排查。
我们定位到redis客户端的连接是可以先预热的，在global application_begin启动的时候先预热好，然后性能一下子也正常了。
范围进一步缩小，问题出在连接上，这里我们又反思了（一夜觉睡过了，脑子清醒了），那为什么我们之前的压测没出现过这个问题。对技术狂热爱好的我们，哪能善罢甘休。此时问题算是解决了，但是背后所涉及到的相关线索穿不起来，总是不太舒服。（中场休息片刻，已是第二天的下午快傍晚了~~。）技术人员要有这种征服欲，必须搞清楚。
我们开始还原现场，然后开始出大招，开始dump进程文件，分不同的时间段，抓取了几份dump文件down到本地进行分析。
首先查看了线程情况，!runaway，发现大多数线程执行时间都有点长。接着切换到某个线程中~xxs，查看线程调用堆栈。发现在等一把monitor锁。同时切换到其他几个线程中查看下是不是都在等待这把锁。结果确实都在等这把锁。
结论，发现一半的线程都在等待moniter监视器锁，随着时间增加，是不是都在等待这把锁。这比较奇怪。
这把锁是redis库的第三层封装的时候用来lock获取redis connectioin时候用的。我们直接注释掉这把锁，继续压测继续dump，然后又发现一把monitor，这把锁是StackExchange.Redis中的，代码一时半会无法消化，只查了主体代码和周边代码情况，没有时间查看全局情况。（因为时间紧迫）。暂且完全信任第三方库，然后查看redis connection string 的各个参数，是不是可以调整超时时间、连接池大小等。但是还是未能解决。
回过头继续查看dump，查看了下CLR连接池，！ThreadPool，一下子看到问题了。
继续查看其他几个dump文件，Idle都是0，也就是说CLR线程池没有线程来处理请求了，至少CLR线程池的创建速率和并发速率不匹配了。
CLR线程池的创建速率一般是1秒2个线程，线程池的创建速率是否存在滑动时间不太清楚。线程池的大小可以通过 C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Config\machine.config 配置来设置，默认是自动配置的。最小的线程数一般是当前机器的CPU 核数。当然你也可以通过ThreadPool相关方法来设置，ThreadPool.SetMaxThreads(), ThreadPool.SetMinThreads()。
然后我们继续排查代码，发现代码中有用Action的委托的地方，而这个Action是处理异步代码的，上面说的redis的读写都在这个Action里面的。一下我们明白了，所有的线索都连起来了。
4.结论
.NET CLR线程池是共享线程池，也就是说ASP.NET、委托、Task背后都是一个线程池在处理。线程池分为两种，Request线程池、IOCP线程池（完成端口线程池）。
我们现在理下线索：
1.从最开始的JMeter压测吞吐量慢慢变低是个假象，而此时处理已经全面停止，服务器的CPU处理为0%。肉眼看起来变慢是因为请求延迟时间增加了。
2.redis的TCP链路没问题，Wireshark查看没有任何异常、Slowlog没有问题、redis的key comnand慢是因为blocking住了。
3.其他服务压测之所有没问题是因为我们是同步调用redis，当首次TCP连接建立之后速度会上来。
4.Action看起来速度是上去了，但是所有的Action都是CLR线程池中的线程，看起来快是因为还没有到CLR线程池的瓶颈。
Action asyncAction = () =>
{
//读写redis
//发送邮件
//...
};
asyncAction();5.JMeter压测的时候没有延迟，在压测的时候程序没有预热，导致所有的东西需要初始化，IIS、.NET等。这些都会让第一次看起来很快，然后慢慢下降的错觉。
总结：首次建立TCP连接是需要时间的，此时并发过大，所有的线程在wait，wait之后CPU会将这些线程交换出去，此时是明显的所线程上下文切换过程，是一部分开销。当CLR线程池的线程全部耗光吞吐量开始陡降。每次调用其实是开启力了两个线程，一个处理请求的Request，还有一个是Action委托线程。当你以为线程还够的时候，其实线程池已经满了。
5.解决
针对这个问题我们进行了队列化处理。相当于在CLR线程池基础上抽象一个工作队列出来，然后队列的消费线程控制在一定数量之内，初始化的时候默认一个线程，会提供接口创建顶多6个线程。这样当队列的处理速度跟不上的时候可以调用。大致代码如下（已进行适当的修改，非源码模样，仅供参考）：
Service 部分：
private static readonly ConcurrentQueueAsyncNotifyPayQueue = new ConcurrentQueue (); private static int _workThread; static ChangeOrderService() { StartWorkThread(); } public static int GetPayNoticQueueCount() { return AsyncNotifyPayQueue.Count; } public static int StartWorkThread() { if (_workThread > 5) return _workThread; ThreadPool.QueueUserWorkItem(WaitCallbackImpl); _workThread += 1; return _workThread;; } public static void WaitCallbackImpl(object state) { while (true) { try { PayNoticeParamEntity payParam; AsyncNotifyPayQueue.TryDequeue(out payParam); if (payParam == null) { Thread.Sleep(5000); continue; } //获取订单详情 //结转分摊 //发短信 //发送消息 //配送 } catch (Exception exception) { //log } } }
原来调用的地方直接改成入队列：
private void AsyncNotifyPayCompleted(NoticeParamEntity payNoticeParam)
{
AsyncNotifyPayQueue.Enqueue(payNoticeParam);
}Controller 代码：
public class WorkQueueController : ApiController
{
[Route("worker/server_work_queue")]
[HttpGet]
public HttpResponseMessage GetServerWorkQueue()
{
var payNoticCount = ChangeOrderService.GetPayNoticQueueCount();
var result = new HttpResponseMessage()
{
Content = new StringContent(payNoticCount.ToString(), Encoding.UTF8, "application/json")
};
return result;
}
[Route("worker/start-work-thread")]
[HttpGet]
public HttpResponseMessage StartWorkThread()
{
var count = ChangeOrderService.StartWorkThread();
var result = new HttpResponseMessage()
{
Content = new StringContent(count.ToString(), Encoding.UTF8, "application/json")
};
return result;
}
}上述代码是未经过抽象封装的，仅供参考。思路是不变的，将线程利用率最大化，延迟任务无需占用过多线程，将CPU密集型和IO密集型分开。让速度不匹配的动作分开。
优化后的TPS可以到7000，比原来快近三倍。
6.对比JAVA实现
这个问题其实如果在JAVA里也许不太容易出现，JAVA的线程池功能是比较强大的，并发库比较丰富。在JAVA里两行代码就可以搞定了。
ExecutorService fiexdExecutorService = Executors.newFixedThreadPool(Thread_count);
直接构造一个指定数量的线程池，当然我们也可以设置线程池的队列类型、大小、包括队列满了之后、线程池满了之后的拒绝策略。这些用起来还是比较方便的。
本文题目：记5.28大促压测的性能优化—线程池相关问题
分享地址：http://azwzsj.com/article/ihdeeh.html
