性能优化：线程资源回收

一时失言乱红尘 2023-09-29 16:10 19阅读 0赞

### 一、问题 ###

模型服务平台的排序请求出现较多超时情况，且不定时伴随空指针异常。

### 二、问题发生前后的改动 ###

召回引擎扩大了召回量，导致排序请求的item数量增加了。

### 三、出问题的模型 ###

基于XGBoost预测的全排序模型。

### 四、项目介绍 ###

web-rec-model：模型服务平台。用于管理排序模型：XGBoost、TensorFlow、pmml…召回模型：item2item，key2item，vec2item…等模型的上下线、测试模型一致性、模型服务等。

### 五、一次排序请求流程 ###

1、如下图所示，一次排序请求流程包含：特征获取、向量获取、数据处理及预测。以上提到的三个步骤均采用多线程并行处理，均以子任务形式执行。每个阶段中间夹杂这数据处理的流程，由主线程进行处理，且每个阶段的执行任务均为超时返回，主线程等待子线程任务时，也采用超时等待的策略。（同事实现的一个树形任务执行，超时等待的线程框架）

2、特征数据闭环：该步骤为异步执行，将排序计算使用到的特征及分数，模型版本等信息记录。后续作为模型的训练样本，达到特征闭环。

![bf3f1e5b50774c2fb1b48a3e7fc5f7f7.png][]

3、一次排序请求中，***特征获取及向量获取***为网络IO（IO密集型任务），超时可直接响应中断，线程可快速返回。***数据处理及模型***为计算步骤（CPU密集型任务）。

4、当前请求耗时情况：特征与向量的获取阶段耗时均为5-8ms，数据处理及模型预测阶段耗时平均在10ms左右。

### 六、问题发生现象 ###

1、首先是调用方：推荐策略平台，监控报警排序请求的超时数量变多（调用方超时时间为300ms），且从监控上看发现排序服务的耗时明显变长：50ms+。正常高峰期的期望值为50ms以下。

2、其次排序服务告警出现大量超时错误。

![8304f99d380f2cfae82c94022b725676.png][]

3、第三根据错误信息定位到该错误信息来自于**数据处理及模型预测**阶段。

4、除了超时变多以外，服务中会出现偶发性的空指针异常。

### 七、问题排查 ###

1、首先解决空指针这类低级错误。

![3a5ae57607e5e3eabed07f0d867793ff.png][]

2、根据错误提示找到对应的代码，此处就不粘贴代码了，做一个简单的代码解释。代码逻辑为：从Map<String,Object>中根据特征key获取特征值进行计算。

3、疑惑点出现，首先该Map<String,Object>用于存放特征及向量键值对，且key均做了空值计算兼容。特征或者向量在查询到空值时，会在Map<String,Object>中放入一个对应的默认值。经过反复的代码确认，报错信息对应的代码不可能出现漏放默认值的情况。

4、借助Arthas的watch命令，监控空指针异常的入参。方便后面做模拟请求还原现场。

5、根据报错时的信息进行模拟请求。尝试N次，且使用不同的报错数据进行尝试，均未重现事故。

6、此时怀疑是多线程并发进行**数据处理及预测**时，发生对Map<String,Object>进行修改的动作，导致部分键值对丢失。

7、反复检查代码，确定**数据处理及预测**均为只读动作，不会对Map<String,Object>进行任何键值对的删改。

8、线索中断，排查一度搁置。

### 八、豁然开朗 ###

1、借用Arthas进行报错观察：使用watch命令，依靠-e参数（指定报错触发打印）以及-x n 参数（打印方法入参及返回值数据层数）

2、根据观察，发现Map<String,Object>中丢失的均为**向量**键值对。

3、找到问题：在排序请求流程图中，在主线程进行**分数归一化**时，会fork子线程异步做特征数据进行压缩写入kafka。由于Map<String,Object>中存在大量的向量数据，导致保存数据过冗余的情况。此处的做法是先去除所有的**向量**数据，再进行保存。

4、但是该动作是发生在**数据处理及模型预测**后的，为何还会因为Map<String,Object>中删除键值对导致空指针异常呢。

5、此时怀疑是**数据处理及模型预测**阶段，多线程任务还没完成时，主线程已经等候超时返回了。

### 九、验证想法 ###

1、还是观察超时日志。

![35e01af04580f93fddf92144a6319cbd.png][]

![08d6b9854e0389b279cc09fa60f0e5bd.png][]

2、发现请求已经返回后，才出现空指针异常。那基本就可以验证以上的想法了。

### 十、问题解决 ###

1、翻看使用的多线程框架（同事实现），主线程超时等待子线程任务。主线程超时返回后，没有通知子线程任务取消。所以才发生请求已返回，特征数据异步落地后，偶发性出现晚到的空指针异常的情况。如下图，主线程超时返回后，只取消主线程任务。

![9a70768deebe295b8140aacdd189d7fb.png][]

2、解决思路：主线程超时返回后，中断子任务（取消子任务）。由于java的中断机制为软中断，一般是通过中断标志位进行线程中断协作的。当然IO或者sleep的中断由系统帮我们做了中断可以快速返回。对于CPU密集型的任务，是需要使用者在**合适**的计算点上做标志位判断，确定是否已中断结束任务。以这种协作的方式达到中断。（此处可能有部分理解不当）

3、修改多线程框架，在主线程超时返回后，修改子线程中断标志位。

![22827da65ae7f26f6c3af99d8acd85ca.png][]

4、在计算流程中加入线程中断检查，如果被中断则提前结束计算。

![ed1843ba78378f45a7fafa5c678cfa22.png][]

### 十一、效果检查 ###

1、修改发版后，空指针没再出现。（其实该空指针是不影响排序结果，因为结果已经是错的，该异常只是附带的虫子而已）  
2、超时请求减少，高峰期的超时数据减少三分之一，50ms+的排序请求有明显减少。

### 十二、复盘 ###

1、主线程等待子任务的场景下，如果主线程超时返回了。需通知子线程结束执行的任务。首先，主线程返回了，表示子任务已被丢弃。继续执行都是在做无用的计算，占用计算机资源。也不是说占着茅坑不拉屎，而是拉了没人要。应该尽量减少服务器资源用在没必要的消耗上。

2、该服务在**数据处理及预测**阶段使用的线程池队列为SynchronousQueue，如果不了解SynchronousQueue的话可以简单理解为一个0长度的队列。任务进池子时必须要有线程进行对接。与常规的BlockingQueue不同的是，任务在池子中不会堆积，对于任务的快速响应比较友好。但是也因为如果没有空闲的线程，则会不停创建线程直到**最高线程数**限制而触发丢弃策略。在该项目问题中，由于部分子任务在主线程返回后仍然在执行。新的请求进来后，会出现没有空闲线程的情况，导致池子创建新线程接任务。对于CPU密集型任务来说，过多的线程数对服务来说是另一种负担，毕竟线程切换的代价还是比较大的。这就套入死循环了。（个人理解，如表述有误，还望指正）

![70f251ba075544519a68f940d848b1e9.png][]

[bf3f1e5b50774c2fb1b48a3e7fc5f7f7.png]: https://img-blog.csdnimg.cn/bf3f1e5b50774c2fb1b48a3e7fc5f7f7.png
[8304f99d380f2cfae82c94022b725676.png]: https://img-blog.csdnimg.cn/img_convert/8304f99d380f2cfae82c94022b725676.png
[3a5ae57607e5e3eabed07f0d867793ff.png]: https://img-blog.csdnimg.cn/img_convert/3a5ae57607e5e3eabed07f0d867793ff.png
[35e01af04580f93fddf92144a6319cbd.png]: https://img-blog.csdnimg.cn/img_convert/35e01af04580f93fddf92144a6319cbd.png
[08d6b9854e0389b279cc09fa60f0e5bd.png]: https://img-blog.csdnimg.cn/img_convert/08d6b9854e0389b279cc09fa60f0e5bd.png
[9a70768deebe295b8140aacdd189d7fb.png]: https://img-blog.csdnimg.cn/img_convert/9a70768deebe295b8140aacdd189d7fb.png
[22827da65ae7f26f6c3af99d8acd85ca.png]: https://img-blog.csdnimg.cn/img_convert/22827da65ae7f26f6c3af99d8acd85ca.png
[ed1843ba78378f45a7fafa5c678cfa22.png]: https://img-blog.csdnimg.cn/img_convert/ed1843ba78378f45a7fafa5c678cfa22.png
[70f251ba075544519a68f940d848b1e9.png]: https://img-blog.csdnimg.cn/70f251ba075544519a68f940d848b1e9.png