技术问题分析-报文截断03(11.22)

今天继续分析下Oracle OSB总线代理后发布的Web Service服务，在客户端消费的时候出现ESB系统级的异常，具体的异常错误信息为：

OSB-382030:Failure while un-marshalling message: Failed to parse XML text

经过前面两篇文章的分析，我们再做下总结，具体如下：

1. 经过多个错误和失败日志的查看，发现客户端发送报文的时间为01分，而实际上服务实例抛出异常被记录的时间为03分，即相差2分钟，120秒。和我们Weblogic上面设置的Post Timeout时间为120秒是一致的。

即Weblogic在2分钟的时间内没有得到完整的信息报文，而只得到了报文片段，导致了Post Timeout，同时不全的报文片段触发Proxy代理服务调用后，出现了Failed to parse XML text的解析错误。

2. 对于运行成功的实例，不管报文量是多大，可以看到，对于客户端发送报文的时间和实际上OSB 服务实例产生的时间是一致的，中间最多相差几秒。

3.出现错误的异常实例和OSB集群节点没有关系，在多个OSB集群节点都发现过同样的问题。

4. 客户端Http Post报文记录下的Http Keep Alive是true，现在Weblogic Http Keep Alive状态是False，不清楚是否是这两个状态不一致也有影响。

5. 当前只有在发送大数据量报文的时候才会出现错误，小报文不会出现异常，一般都是在500k以上的大报文会出现上面的异常错误。客户端现象就是当单据行大于100行或150行的时候就会产生异常。

6. 出现异常的消费端的业务系统均采用的 Docker 容器化部署，不能判断和确定是否和Docker容器化部署有关系。是否会存在正在发送的WebService调用请求的时候，Docker的APP Server变动了IP或出现了卸载。--对于该假设对所有服务实例进行分析，发现出现异常的前后日志实例，均是同样的消费端IP，该可能性很小。

7. 根据Oracle Support网站，我们当时调整了Post TimeOut的超时值为120秒，但是没有调整Duration Time时间，即发现Http连接空闲的回收时间仍然是在30秒，不清楚两个值是否需要调整为一致。

8. 根据Http Post的Trace记录，该出现异常的调用没有启用Http协议中的Chunked编码，即没有启用分块传输，因此在Http Trace中有明确的Content-Length记录，在传输成功的实例中可以看到，该Content-Length记录和实际收到的报文长度是一致的。

9. Oracle Support网站根据关键字没有搜索到更多的有价值的信息。

基于以上的思考，觉得还是要用Weblogic Http Post Timeout为关键字进行搜索相关信息，因为毕竟明确的还是Post Timeout出现了超时，那就要找在哪些情况下会导致Post Timeout。

因此基于该关键字搜索到：https://community.oracle.com/thread/749221

Turns out Apache-WL plugin creates a /tmp/_wl_proxy directory as a buffer flush for POSTs,especially any post over 64k. Our dev environment consists of multiple developers with multiple instances on Solaris, so whoever logs in and triggers the plugin first will generate this directory with their permission, and subsequently all other developer's instance will not be allowed to write to this directory. Note this can also happen on staging or prod environment if different users are used to start the same server. Our solution is to change the permission of this directory to write-for-all, and the problem disappears。

即超大报文会写入缓冲区，但是由于缓冲区被独占，导致超大报文无法发送成功。同时还有一种方法就是将post-max-size值本身设置大一点，参考：

https://blog.csdn.net/bravekingzhang/article/details/38534099

这个时候回顾下，发现我们在检查的时候，只检查了Weblogic Server上的Http Max Post Size，而并没有去检查客户端Server本身的这个设置，而对于客户端发送报文，如果是发送出来就是被截断的报文，那么就一定和客户端Server本身的这个参数设置有关系。

基于这个思路，我们在想如果客户端服务器端是Tomcat App Server，是否也有类似的Max Post Size的设置。于是我们用tomcat max post size 截断 作为关键字进一步搜索。可以搜索到不少的文章说明。

里面提到了可以修改Tomcat Server.xml配置文件中的maxPostSize的值来控制最大可以Post的大小，默认值为2M，注意在tomcat7和以后的版本，需要设置maxPostSize="-1"时才是无限大。

参考这篇文章，也可以看到被截断的情况： http://ian.wang/316.htm

基于以上总计，再梳理下问题现象和逻辑，即为何2分钟才超时，为何重试会成功的问题。

即当发送消息报文的时候，由于受max size控制，报文只有写缓冲区，但是当前缓冲区被独占但是无法写入，即使超过了120秒也无法写入后续数据，导致最终超时。而在重试的时候缓冲区可用的话，能够正常写入。即基于分析最大可能仍然是发送过来的报文本身就是被截断的，而不是OSB收到完整的报文进行了截断。

如果要验证该想法，或者彻底了解清楚问题发送的边界，则必须进行Tcp Trace才能够很好的跟踪到具体的问题原因。而当前在生产环境每天调用并发量很大，而是涉及到诸多的集群节点，要进行Tcp Trace基本不太可能。即使要再进一步分析，也只能是在测试环境进行。