一次现网问题定位-线程池设置不当，导致流量上去后接口变慢
背景
公司大促活动流量上升，突然一线用户反馈发消息特别慢，运维已经初步通过监控发现B服务接口大量超时，调用链如下图。
发消息接口以前只经过A服务，后面为了防止客服骂人（我们是客服系统），接入了风控。因为产品下面好几个模块都要对接风控（外部门的），因此搞了一个公共服务（B服务）去对接风控，B服务本身没有业务逻辑，基本上是纯透传。
当时业务明确，风控的逻辑耗时不能超过500ms，如果超过500ms则放通，当时这个DFX特性做在了B服务，代码如下
@RequestMapping(xx)
public ServiceResponse<CheckRspVO> checkTextMsg(request) {
Future<Result> aicFuture = hossTaskExecutor.submit(new Callable<Result>() {
@Override
public Result call() throws Exception {
return getAICResult(request);
}
});
return aicFuture.get(500, TimeUnit.MILLISECONDS);
}
private Result getAICResult(request) {
log.info("rcService: taskId:[{}]",);
HttpEntity<String> formEntity = buildHttpEntity<String>(request);
try {
ResponseEntity<AICRspVO> response = restTemplate.exchange(aicUrl, HttpMethod.POST, formEntity);
log.info("rcService: From AIC [{}]");
return response.getBody();
} catch (RestClientException rtException) {
log.error("rcService: Call RiskControl Center Failed: []");
}
}
如上所述，B服务接口没有业务逻辑，就是纯透传请求到风控。只不过为了保证接口500ms能够返回，使用了异步线程池，并通过Future.get的方法实现500ms超时返回。
上述代码去掉了一些参数转换的代码，整体架子就这些。
定位过程
首先通过监控能明确是风控逻辑导致的接口变慢，只不过不确定是我们自己（B服务），还是风控系统本身导致的。不过自己本能的还是认为是风控系统导致，因为我们本身服务器监控指标没什么异常，而且B服务也只是透传，自己没啥计算量，不至于过载，另外正好出问题的当天有大促活动，业务量增多，很可能是风控系统本身过载了。
为了能把锅甩出去，还是得找到实质证据。
从日志入手，确认风控有没有报错
从日志确实发现调用风控有报错:“rcService: Call RiskControl Center Failed”
但是由于异常没有打印出来，并不确认到底是什么问题。因此在仔细查阅一段时间的日志，确认报错到底是少量报错，还是大量报错，试图从其中找到一些有用信息。（这里要批评一下开发者，异常没打印出来，导致问题不能快速的确认）。
分析日志的过程中，敏锐的发现一个异常点：getAICResult函数中第一行日志和异常日志，中间隔了5秒钟，并且所有报错2者都是隔了5秒钟。5秒基本就是接口请求的耗时，因为从上面代码可以看到，并无其他操作（参数组装转换的代码没贴在上面，但是这个基本不耗时时间）。
接口请求固定花费5秒，这个很像是设置请求超时时间导致的，因为寻找配置，确认到底是什么超时。
public class SpringRestTemplateConfig {
// tcp三次握手完成时间
@Value("${xx:5000}")
private int connectTimeout;
// 数据传输过程中数据包之间间隔的最大时间
@Value("${xx:60000}")
private int socketTimeout;
从配置项确认是连接超时，很可能是网络不通，通过登录使用telnet命令得以确认。
至此问题得以初步定位（后面找平台确认是N天前，对网络做了变更，部分区域恢复了防火墙）。
疑问
通过翻阅日志，发现报错一致存在， 因此该问题一直有，为什么今天才爆发。
通过回顾代码，发现已经通过Future.get保证了SLA，就算风控超时，也不会影响B服务及时返回，难道线程池设置的有问题？
解惑
查阅线程池配置如下
corePoolSize为4，workqueue大小4*corePoolSize，即线程池的核心线程，最大线程数量为4，任务队列大小为16，线程拒绝策略为CallerRunsPolicy。
@Bean(name = xx)
public ThreadPoolExecutor xx(TaskConfig taskConfig, ThreadFactory namedThreadFactory) {
return new ThreadPoolExecutor(corePoolSize, corePoolSize, 0, TimeUnit.SECONDS, taskConfig.getWorkQueue(),
namedThreadFactory, new ThreadPoolExecutor.CallerRunsPolicy());
}
从配置上来看，线程数设置的过小，大概率是线程池过载，然后拒绝策略又是在本线程执行（CallerRunsPolicy），导致过载的请求响应时间由0.5m变成了5秒（请求5秒超时）。
证明：
从上述代码可以看到，只要能够提交到异步线程处理的都能保证SLA（0.5s）
系统能够保证SLA的QPS为 12个实例*0.8=9.6 一分钟就是576
对于0.8的解释：
因为异步线程的最大线程数为4，因此并发量最大为4，单个请求5秒才完成，因此每5秒能完成4个请求，那单个实例的QPS为4/5=0.8，单个实例的请求频率一旦超过这个数，那么线程池就无法及时处理完，并放入任务队列，最终任务队列满了后，在本线程执行，导致SLA无法得到满足。
平时调用量统计
出问题当天调用量统计
当天超时接口统计
从上述可以看到，平时QPS也就400到500间，没有超过576，线程池不会过载，0.5S的SLA能够保证
出问题时(下午15:50分后)QPS逐渐超过576，线程池过载，问题开始出现。
因为请求的分布并不是绝对的平均（单个容器的QPS超过0.8了），所以15:50分开始，虽然中QPS没有超过576，但是有少量请求还是变慢了。
总结
线程池的几个参数意义我这里就不详细介绍了，网上一大堆。
将请求第三方的逻辑，放到异步线程里面处理，还是比较常见的做法，比如某个接口要调用好几个第三方，而且各自没有依赖，会使用异步线程，同时提交对第三方系统的请求，以减小本接口的响应时间。请求第三方属于IO密集型，本身并不会怎么消耗CPU，因此线程池的线程数可以设置大一点（比如200）。另外一个比较重要的参数就是线程池拒绝策略，一定要想好极端场景的兜底措施，对于本系统，风控逻辑并不重要，线程池超载后可以丢弃，因此可以自定义一个处理策略，丢弃配置打印日志就可以了。