千万不要把Request传递到异步线程里面！有坑
前几天在网上冲浪的时候看到一篇技术文章，讲的是他把一个 request 请求传递到了线程池里面，然后遇到了一个匪夷所思的情况。
他写了这篇文章，把自己针对这个问题的探索过程分享了出来：
《springboot 中如何正确的在异步线程中使用request》
https://www.cnblogs.com/mysgk/p/16470336.html
文章还是挺不错的，把发现问题和解决问题都写的很明白了。
但是，我觉得把探索问题的部分写的太省略了，导致我看完之后都不知道这个问题的根本原因是什么。
而为什么我会对这篇文章特别感兴趣呢？
因为这个“坑”我记得我刚刚入行没两年的也遇到过，我已经不记得自己当时是怎么解决的了，但是我肯定也没有深入的去研究。
因为那个时候遇到问题，就去网上费尽心思的查，粘一个方案过来看能不能用。
如果不能用的话，心里暗骂一句：小可(S)爱(B)，然后接着找。
直到找到一个可以用的。
至于为什么能用？
管它呢，研究这玩意干啥。
image.png
主要是当时觉得探索这个玩意到进入到源码里面去，一涉及到源码心里就犯怵，所以就敬而远之。
现在不一样了，现在我看到源码我就觉得兴奋，心里想着：多好的素材啊。
既然这次又让我遇到了，所以我决定把几年前的坑填上，盘一盘它。
image.png
搞个 Demo
由于这个现象太过匪夷所思，所以写文章的那个老哥认为这个是一个 BUG，还在 Spring 的 github 上提了一个 issues：
https://github.com/spring-projects/spring-framework/issues/28741
这里面他附上了一个可以复现的 Demo，所以我就直接拿来用了。
确实是可以复现，但是其实他提供的这个 Demo 还是有点臃肿，具有一点点的迷惑性，直接给我迷晕了，让我在这上面稍微花了时间。
先给你看一下他的 Demo 是怎么样的。
主要是两个 Controller 接口。
第一个接口是 get 请求类型的 getParams，代码很简单，先放在这里，等下用：
image.png
第二个接口是 post 请求类型的 postTest，就这么几行代码：
@PostMapping("/postTest")
public String postTest(HttpServletRequest request) {
String age1 = request.getParameter("age");
String name1 = request.getParameter("name");
System.out.println("age1=" + age1 + ",name1=" + name1);
new Thread(new Runnable() {
@Override
public void run() {
String age2 = request.getParameter("age");
String name2 = request.getParameter("name");
System.out.println("age2=" + age2 + ",name2=" + name2);
//模拟业务请求
try {
Thread.sleep(200);
} catch (InterruptedException e) {
throw new RuntimeException(e);
}
age2 = request.getParameter("age");
name2 = request.getParameter("name");
}
}).start();
return "post success";
}
主要是里面启动了一个线程，在线程里面有从 request 里面获取参数的动作。
这个方法访问起来是这样的一个情况：
image.png
从 age2、name2 输出上看，虽然 request 传入到异步线程里面了，但是还是能从里面获取到对应的参数，没有看出来有什么毛病。
但是接下来，匪夷所思的事情就要出现了。
还记得我们前面的 getParams 接口吗？
我再把它拿过来给你看一眼：
image.png
你说，就这个接口，我用下面这个链接去访问，在我的认知里面是完全不可能有任何问题的，对吧？
但是，这玩意还真的就打破了我的认知：
image.png
在访问 postTest 方法之后，再次访问 getParams 方法，getParams 方法居然抛出异常了？
抛出的异常是说我调用的时候没有传递 b 这个参数。
但是我的链接里面明明就是有 b=2 的啊？
这玩意上哪里说理去？
image.png
上面就是那位老哥提供的可复现的 Demo 的主要部分。
但是我前面说了，这个 Demo 有点臃肿，具有一点点迷惑性。
首先如果我再加一个输出语句，那么在一个短暂的 sleep 之后， age2 和 name2 就没了：
image.png
虽然还是感觉有点神奇吧，但是也没有刚刚那个操作让我感到震惊。
因为从输出 null 这个结果，我至少可以知道程序在这个地方就出现问题了，把问题的范围限定在了一次请求中。
刚刚那个操作，好家伙，表现出来到情况是这样的：
- 先发起一个 post 请求，看起来是正常的。
- 然后再发起一个 get 请求，这个 get 请求挂了。
- 但是这个 get 请求从发起的角度来看找不到任何毛病。
你要基于上面这个情况去分析问题的话，就不好找问题了，毕竟要发起两个毫不相干的请求才能触发问题。
image.png
加入一行输出日志，相当于把问题简化了一点。
但是你看到的是我就加了一行输出日志，实际上等我加这行日志的时候，我拿到这个 Demo 已经过去了好几个小时了。
在这期间我也一直以为必须要按照这个流程来操作，才能复现问题。
所以我才说具有一点点迷惑性。
好，现在不管怎么说吧。
我先把 Demo 简化一点，便于继续分析。我的 Demo 可以简化到这个程度：
@GetMapping("/getTest")
public String getTest(HttpServletRequest request) {
String age = request.getParameter("age");
System.out.println("age=" + age);
new Thread(() -> {
try {
Thread.sleep(200);
} catch (InterruptedException e) {
throw new RuntimeException(e);
}
String age1 = request.getParameter("age");
System.out.println("age1=" + age1);
}).start();
return "success";
}
get 和 post 请求都可以，只是我为了方便选择发起 get 请求。
然后只需要传递一个参数就行，核心步骤是要把 request 传递到异步线程里面去，调用 getParameter 再次获取对应入参。
你可以把上面的代码粘到你本地，把项目跑起来，然后调一次下面这个链接：
从控制台你可以看到这样的输出：
image.png
到这里就复现了前面说的问题。
但是你別着急，你再次发起调用，你会看到控制台的输出是这样的：
image.png
怎么样，是不是很神奇，很懵逼？
为了让你更加直观的懵逼，我给你上个动图，发起两次调用，主要关注控制台的输出：
image.png
好，现在，你就去泡杯茶，点根烟，慢慢去琢磨，这玩意是不是属于超自然现象。
image.png
探索
其实我看到这个现象的时候并不是特别的震惊，毕竟写文章这几年，什么稀奇古怪的现象都遇到过。
所以我只是轻蔑一笑，看向了我排查问题的武器库，很快就看到了一个比较趁手的东西：开启 Debug 日志。
如果是以前，对于这种没有抛出异常的问题跟着，由于没有异常堆栈，我肯定是迫不及待的正向的 Debug 跟了一下源码，扎到源码里面去一顿狂翻，左看右看。
但是结果常常是一头扎进去之后，很快就迷失了，搞了好几个小时才从源码里面爬出来，出来的时候基本上一无所获。
但是我现在不会这么猴急了，现在就成熟了很多。遇到这类问题不会先急着去卷源码会先多从日志里面挖掘一点东西出来。
所以我遇到这个问题的第一反应就是调整日志级别到 Debug：
logging.level.root=debug
观察日志这个小技巧我在之前的文章里面也分享过。
当日志调整到 Debug 级别之后，再次发起两次调用，问题复现，同时把日志拿出来做对比。
两次请求的 Debug 日志整体情况是这样的，左边是第一次请求，右边是第二次请求：
image.png
可以看到第一次请求比第二次请求的日志多。
多说明什么问题？
是不是说明第一次请求调用的方法更多一点？
为什么多一点，到底是哪些方法只调用了一次？
我也不知道，但是我能从 Debug 日志里面梳理出来。
比如下面这个图就是梳理出来的第一次请求多打印的日志：
image.png
很快我就从 Debug 日志里面看到了一个我觉得很可疑的地方：
image.png
Start processing with input [age=18]
这一行日志，只有第一次请求的时候打印了，从日志表达的意思来看，是处理请求里面的 age=18。
为什么第二次不打印呢？
我也不知道，但是我知道了第一个关键断点打在什么位置了。
全局搜索关键字 “Start processing with input” 可以找到配置文件里面的 “parameters.bytes”。
然后全局搜索 “parameters.bytes”，就能找到是在 Parameters.java 文件里面输出的：
image.png
也就是这个地方：
org.apache.tomcat.util.http.Parameters#processParameters(byte[], int, int, java.nio.charset.Charset)
image.png
找到第一个断点，就找到了突破口，只要好好的拿捏住，之后的事情就基本上就顺风顺水了。
image.png
首先，重启项目，发起调用，在断点处看调用堆栈：
image.png
接下来的思路是什么？
就是我要从堆栈里面找到一个东西。
你想啊，第一次请求走这个地方，第二次请求就不走这个地方了，所以一定有个类似于这样的逻辑：
if(满足某个条件){
走processParameters方法
}
所以，只需要往回找五个调用栈，我就找到了这一个方法：
org.apache.catalina.connector.Request#getParameter
image.png
这个时候你看旁边的 parametersParsed 参数是 true，按理来说 true 不应该走进 if 分支呀？
因为这个地方我们是从断点处的堆栈信息往回找，在从 parseParameters 方法到 processParameters 方法之间，肯定有地方修改了 parametersParsed 参数的值为 true。
image.png
这一点，从 parametersParsed 的初始值是 false 也能看出来：
image.png
因此，我决定把第二个断点打在 getParameter 方法中：
image.png
再次重启服务，发起调用，parametersParsed 为 false，开始执行 parseParameters() 方法解析参数：
image.png
而解析参数的目的之一就是把我的 age=18 放到 paramHashValues 这个 Map 容器里面：
org.apache.tomcat.util.http.Parameters#addParameter
image.png
parseParameters() 方法执行完成之后，接着从前面的 paramHashValues 容器里面把 age 对应的 18 返回回去：
image.png
但是，朋友们，注意上面的图片中有个标号为 ① 的地方：
image.png
这个方法，在 parseParameters 方法里面也会被调用：
org.apache.tomcat.util.http.Parameters#handleQueryParameters
image.png
好，现在打起精神来听我说。
handleQueryParameters 方法才是真正解析参数的方法，为了防止重复解析它加入了这样的逻辑：
image.png
image.png
didQueryParameters 初始为 false，随后被设置为 true。
这个很好理解，入参解析一次就行了，解析的产物一个 Map，后续要拿参数对应的值，从 Map 里面获取即可。
比如我把入参修改为这样：
那么经过解析之后，这个 Map 就变成了这样：
image.png
经过了前面的这一顿折腾之后，现在找到了解析入参的方法。
那么全文的关键点就在 didQueryParameters 这个参数的变化了。
只有是 false 的时候才会去解析入参。
那么我接下来的排查思路就是观察 didQueryParameters 参数的变化，所以在字段上打上断点，重启项目，继续调试：
image.png
第一次进入这个方法的时候 didQueryParameters 为 false，入参是 age=18：
image.png
而第一次进入这个方法的原因我前面也说了，是因为触发了 parseParameters 的逻辑：
image.png
第二次进入这个方法 didQueryParameters 变为 true 了，不用再次解析：
image.png
那么第二次进入这个方法的原因是什么？
前面也说了，getParameter 方法的第一行就是触发解析的逻辑：
image.png
接下来，断点停在了这个地方：
org.apache.tomcat.util.http.Parameters#recycle
image.png
方法叫做 recycle，表明是循环再利用，在这里面会把存放参数的 Map 清空，把 didQueryParameters 再次设置为了 false。
而当你用同样的手段去观察 parametersParsed 参数，也就是这个参数的时候：
image.png
会发现它也有一个 recycle 方法：
org.apache.catalina.connector.Request#recycle
image.png
这个方法上的注释，也有一个特别扎眼的词：reuse。
注释过来是这样的：释放所有的对象引用，并初始化实例变量，为重新使用这个对象做准备。
种种迹象表明 request 在 tomcat 里面是循环使用的。
虽然在这之前我也知道是循环使用的，但是百闻不如一见嘛。这次是我 Debug 的时候亲眼看到了。
又拿捏一个小细节。
image.png
由于我们在异步线程里面还触发了一次 getParameter 方法：
image.png
但是 getTest 方法已经完成了响应，这个时候 Request 可能已经完成了回收。
注意我说的是“可能”，因为这个时候 Request 的回收动作和异步线程谁先谁后还不一定。
这也解释了这个现象：
image.png
虽然 request 传入到异步线程里面了，但是还是能从里面获取到对应的参数。
因为此时 request 的回收动作还没做完，还可以继续获取参数。
为了避免这个“可能”，我把 sleep 的时间调整为 5s，保证 request 完成回收。
然后这异步线程里面继续 Debug，接下来神奇的事情就要开始了。
image.png
再次触发 handleQueryParameters 的时候，didQueryParameters 由于被 recycle 了，所以变成了 false。
然后执行解析的逻辑，把 didQueryParameters 设置为 true。
但是，我们可以看到，此时查询的内容却没有了，是个 null：
image.png
这个也好理解，肯定是随着调用结束，被 recycle 了嘛：
image.png
所以，到这里我能解答为什么异步线程里面的输出是 null 了。
queryMB 就是我调用的时候传入的 age=18。
通过 Debug 发现异步线程里面调用 getParameter 的时候没有 queryMB ，所以就不会解析出 Map。
没有 Map ，异步线程里面的输出肯定是 null。
为什么没有 queryMB 呢？
因为当前这个请求已经被返回了，执行了 recycle 相关操作，queryMB 就是在这个时候没有的。
那么为什么再次发起调用，会出现这个神奇的现象呢？
image.png
很简单，因为在异步线程里面调用 getParameter 的时候，把 didQueryParameters 设置为 true 了。
但是异步线程里面的调用，超出了 request 的生命周期，所以并不会再次触发 request 的 recycle 相关操作，因此这个 request 拿来复用的时候 didQueryParameters 还是 true。
所以，从 Debug 来看，虽然 queryMB 是有值的，但是没用啊，didQueryParameters 是 true，程序直接 return 了，不会去解析你的入参：
image.png
问题得到解答。
此时，我们再回到最开始的这个方法中：
image.png
你想想为什么这个方法调用的时候出现异常了？
还是一样的道理呀，由于 request 是复用的，虽然你传入了参数 b，但是由于前一个请求在异步线程里面调用了 getParameter 方法，将 didQueryParameters 设置为了 true，导致程序不会去解析我传入的 a=1&b=2。
从调用链接的角度来说，虽然我们调用的是这个链接：
但是对于程序来说，它等效于这个链接：
由于入参 b 是 int 类型的，那可不就是会抛出这个异常吗：
image.png
这个异常是说：哥们，你要么把 b 搞成 Integer 类型的，不传值我就给你赋为 null。要么给我传一个值。
你现在用 int 来接受，又不给我值，我这没法处理啊？
我能给你默认赋值一个 0 吗？
肯定不能啊，0 和 null 可不是一个含义，万一你程序出异常了，把锅甩给我怎么办？
算了，我还是抛异常吧，最稳妥了。
所以你看，要是你从这个抛异常的地方去找答案，也许能找到，但是路就走远了一点。
因为这个地方并不是问题的根因。
到这里，你应该清楚这个 BUG 到底是怎么回事了。
request 的生命周期
在探索这个问题的过程中，我也想到了另外一个问题：
一个 request 请求的生命周期是怎么样的？
这题我记得几年前我背过，现在我确实有点想不起来了，但是我知道去哪里找答案。
Java Servlet Specification，这是一份规范，答案就藏在这个规范里面：
https://javaee.github.io/servlet-spec/downloads/servlet-4.0/servlet-4_0_FINAL.pdf
在 3.13 小节里面，关于 request 这个 Object 的生命周期，规范是这样说的：
image.png
这寥寥数语，非常关键，所以我一句句的拆解给你看。
Each request object is valid only within the scope of a servlet’s service method, or within the scope of a filter’s doFilter method，unless the asynchronous processing is enabled for the component and the startAsync method is invoked on the request object.
一上来就是一个长句，但是根本不要慌。
你知道的，我英语八级半，水平一向是可以的。
image.png
先把长句拆短一点，我可以先只翻译 unless 之前的部分。
前面这部分说：每个 request 对象只在 servlet 的服务方法的范围内有效，或者在过滤器的 doFilter 方法的范围内有效。
接着它来了一个 unless，表示转折，和 but 差不多。
我们主要关注 unless 后面这句：
the asynchronous processing is enabled for the component and the startAsync method is invoked on the request object.
组件的异步处理功能被启用，并且在 request 上调用了 startAsync 方法。
也就是说，request 的生命周期在遇到异步的时候有点特殊，但是这个异步又不是我前面演示的那种异步。
关于异步，规范中提到了 request 里面有个方法：startAsync。
我去看了一眼，果然是有：
image.png
返回值是一个叫做 AsyncContext 的东西。
但是我先按下不表，接着往下翻译。
In the case where asynchronous processing occurs, the request object remains valid until complete is invoked on the AsyncContext.
在发生异步处理的情况下，request 对象的生命周期一直会延续到在 AsyncContext 上调用 complete 方法之前。
这里又提到了一个 complete 方法，这个 complete 方法 invoked on the AsyncContext。
AsyncContext 是什么玩意？
不就是 request.startAsync() 方法的返回值吗？
果然在 AsyncContext 里面有个 complete 方法：
image.png
不慌，继续按下不表，一会就回收，接着往下看。
Containers commonly recycle request objects in order to avoid the performance overhead of request object creation.
容器通常会 recycle 请求对象，以避免创建请求对象的性能开销。
看到这个 recycle 我们就很眼熟了，原来规范里面是建议了容器里面实现 request 的时候尽量复用，而不是回收，目的是节约性能。
这玩意，属于意外收获呀。
最后一句话是这样的：
The developer must be aware that maintaining references to request objects for which startAsync has not been called outside the scope described above is not recommended as it may have indeterminate results.
这句话是说：程序员朋友们必须要意识到，我不建议在上述范围之外维护 request 的引用，因为它可能会产生不确定的结果。
看到这个“不确定的结果”时我很开心，因为我前面已经演示过了，确实会产生莫名其妙的结果。
但是规范里面在“scope”之前还加了一个限定词：startAsync has not been called。
反过来说，意思就是如果你有一个调用了 startAsync 方法的 request，那么在上述范围之外，你还可以操作这个 request，也不会有问题。
这一整段话中，我们提炼到了两个关键的方法：
- request 的 startAsync 方法
- AsyncContext 的 complete 方法
根据规范来说，这两个方法才是 request 异步编程的正确打开方式。
正确打开方式
在这之前，假设你完全不知道 startAsync 和 complete 方法。
但是看了规范上的描述，猜也能猜出来代码应该这样写，然后发起多次调用，没有任何毛病：
image.png
这就是正确的打开方式。
从现象上来说，就是 getTest 请求返回之后，request 线程并没有被调用 recycle 方法进行回收。
为什么这样写就能实现 request 的异步化呢？
用脚指头想也能想到，一定有一个这样的判断逻辑存在：
if(调用过request的startAsync方法){
先不回收
}
所以，用之前的方法，在 recycle 方法上打断点，并往回找，很快就能找到这个方法：
image.png
然后，关于 AsyncContext 的 complete 方法我还注意到它有这样的一个描述：
image.png
也就是说在调用 complete 方法之后 response 流才会关闭，那么有意思的就来了：
image.png
我不仅在异步线程里面可以操作 request 还可以操作 response。
但是转念一想，既然都是异步编程了，操作 response 的意义肯定比操作 request 的意义更大。
关于 Tomcat 对于异步请求的支持还有很多可以探索的地方，自己慢慢去玩吧。
写到这里的时候我发现标题说的也不对，标题是：千万不要把 Request 传递到异步线程里面！有坑！
而正确的说法应该是：
千万不要随便把 Request 传递到异步线程里面！有坑！你拿捏不住，得用 startAsync 方法才行。
好了，就这样吧，本文写到这里就差不多了。
本文主要是分享了一下 request 放到异步线程之后的诡异现象和排查方法，最后也给出了正确的打开方式。
希望你能掌握到这样的一个问题排查方法，不要惧怕问题，要抽丝剥茧的干它。
然后，其实和 BUG 排查比起来，关于 request 的异步编程相关的知识更加重要，本文只是做了一个小小的引子，如果这块知识对你是空白的，希望你有兴趣的话自己去研究一下，很有价值。
最后，我想说的是，关于之前文章的一个留言：
image.png
从看到这个现象，到写完这篇文章，我不断的调试程序，至少重启了近百次服务，发起了上百次请求。在源码里面也走了一些弯路，最后才抽丝剥茧的看到本问题的根因。
所以，我排查问题的经验就一个字：
image.png
