Http 请求偶发400错误

时间:2024-04-19 09:43:33

1. 背景

  生产环境偶发400请求错误,发生概率万分之一,异常信息如下:

  1) 从异常信息可以看到,skywalking的sw8 header解析失效导致异常信息。

  2) 0x0d0x0a 作为回车换行符号,没有被正确处理,导致header的截断错误。

2. 排查过程

1) 怀疑skywalking的sw8 header头存在异常编码情况,导致header头格式错误,对sw8进行链路的反解,反解信息正常如下所示,因此排除skywalking的问题:

sw8:1-ZGM1YmQ1NzYzMTEwNGY1MDlmOGRhMGQ0MTcwZTU0ZGIuMTUzLjE3MTI4MTk1NjIyMjc0Mzgz-ZjlmZTAwMmJmZTNkNGE2MGFlNDQ5NWRhYTY1YzQ4NDQuMzI0Mi4xNzEyODE5NTYyMjYzMjgwNA==-1-ZW5kcG9pbnQtZ2F0ZXdheQ==-ZW5kcG9pbnQtZ2F0ZXdheUBuMTEwZWdrOHNhcDAwMDI=-SHlzdHJpeC9kcy9FeGVjdXRpb24=-MTAuMjEwLjkuMzU6MzAyOTI=

追踪ID:2f8b4d048cd345d2bce4fad6fb055fe0.150.17128195042681703

父追踪片段ID:2f8b4d048cd345d2bce4fad6fb055fe0.150.17128195042681703

-1-

父服务名称:endpoint-gateway

父服务实例标识,解码后为endpoint-gateway@n110egk8sap0002

父服务的端点:Hystrix/ds/Execution

本请求的目标地址: 10.210.9.35:30292

2) 通过异常堆栈,找到对应的异常代码逻辑org.apache.coyote.http11.Http11InputBuffer.parseHeader(), 可以发现tomcat是按数据包的字节流处理header的。正常情况下碰到CR LF会跳出循环处理header项,但是400异常情况下并没有。

3) 对请求进行抓包,发现400错误请求的TCP 包刚好截断在CR LF之间。

        由于第一个数据包截断在CR, 所以第一个数据包没办法处理sw8的header,会返回HeaderParseStatus.NEED_MORE_DATA等待第二个数据包的到来。

        当第二个数据包到达时,会对回车和换行符进行处理,但是由于tomact 9.0.31版本对LF处理有问题,当一个字符是LF时,被当作普通字符拼接到之前的数据流的末尾。

  此时,prevChr=0, 但是chr=LF,tomcat认为header格式异常,因此删除当前这个header进入异常打印逻辑。

   打印异常的时候,从当前位置往下读直到碰到回车换行符,也就是sw-correction:,因此异常打印到sw-correction header项。

   将控制符转化为16进制码进行打印,也就是异常里面0x0d0x0a的信息。

3. 问题复现

      由于问题需要发生在tcp包刚好截断在CRLF之间,因此比较难以复现,本地用socket程序模拟CRLF 截断。分别发送两个数据包,第一个包发送数据到CR,第二个包发送剩下的数据。

   成功复现了生产环境的错误。

4. 修复方案

   Tomcat 9.0.46 版本对类似问题进行了修复,https://bz.apache.org/bugzilla/show_bug.cgi?id=65272。因此升级tomcat到9.0.46以后的版本就可以解决这个问题。