赞
踩
生产环境偶发400请求错误,发生概率万分之一,异常信息如下:
1) 从异常信息可以看到,skywalking的sw8 header解析失效导致异常信息。
2) 0x0d0x0a 作为回车换行符号,没有被正确处理,导致header的截断错误。
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的信息。
由于问题需要发生在tcp包刚好截断在CRLF之间,因此比较难以复现,本地用socket程序模拟CRLF 截断。分别发送两个数据包,第一个包发送数据到CR,第二个包发送剩下的数据。
成功复现了生产环境的错误。
Tomcat 9.0.46 版本对类似问题进行了修复,https://bz.apache.org/bugzilla/show_bug.cgi?id=65272。因此升级tomcat到9.0.46以后的版本就可以解决这个问题。
Copyright © 2003-2013 www.wpsshop.cn 版权所有,并保留所有权利。