业务慢故障分析-查询错误导致

一、故障描述

某二级政府单位网络，网络管理人员经常接到用户反映业务系统访问比较慢，而此时网络运行良好，并不存在网络问题。基于这种情况，我们对网络进行了数据流分析。网络及部署情况大致如下：





如上图，该网络为省级单位的应用服务器区，通过各下级单位通过广域网访问应用服务器，科来回溯分析系统部署在核心交换的镜像端口。

二、故障分析

2.1 分析方法简介

通过流量、数据包、利用率、TCP Flags关键参数的图形化显示，快速了解网络运行状况；并通过网络协议，物理端点、IP端点、物理会话、IP会话、TCP会话、UDP会话等多角度、深层次的对数据进行关联挖掘，直观地展现各网络对象间的关联关系和数据统计结果，从而全面展现网络的工作状态，是否存在风险和隐患等问题。
最后通过提取数据包(Packets)，通过解码、会话分析等验证结论过解码验证分析结果。数据包分析将按照以下两种方法进行：

1. 数据包分析法

对捕获下来的数据包进行统计分析，解码分析（关键字段），专家分析。

2. 同步对比分析法

在不同的位置同时捕包，并采用数据包分析方法对数据进行对比分析的方法。

整个测试分析过程严格遵循以上流程，即“全局—>节点（会话）—>数据包”的分析方法。

2.2 详细分析

本次分析仍然使用诊断-->定位地址-->定位数据包---〉分析这个传统的分析思路。

1.下载数据包

根据用户反馈的时间，定位到相关时间段，如下图：





选中相关数据包，调用专家分析进行诊断





科来回溯分析系统提供了专家分析功能，可以智能的对网络中的一些安全、性能、故障问题进行快速的定位。

2、诊断分析

专家分析系统提供了快捷的分析体系，可通过诊断三步曲，来实现对异常现象的快速定位、识别分析。





第一步，先找出网络中存在的异常现象，本次发现了TCP慢应答报错，关于TCP慢应答的相关解释信息，可在诊断条目中双击该条目获取，如下图：





第二步，定位诊断发生的地址，如上图中详细的提供了发生TCP慢应答的主机，并提供了各主机出现慢应答的次数，并支持对次数排名，如下图：





其中服务器16.205出现的次数最多，达到了402个，接下来需要对该主机的TCP会话信息进行深入分析。
第三步，选中该主机，定位到诊断事件，快速调去相关数据包，如下图：





通过如上三步曲，我们选中了25.157:1304<--->16.205:1521这个会话进行详细分析，通过对TCP会话交互信息，确定应用慢具体慢在什么地方。





如上图，在TCP会话中显示该会话条目，双击进入TCP流分析界面，如下图：





选中的该会话持续了29.45s，传输了139.714K字节，共522个数据包。
打开TCP交易列表，对TCP会话包括的所有交易情况进行分析，如下图：





选取请求3与响应3的的时间差值来简单评估服务器的响应时间，我们可以看到在该服务器响应中，只用了0.815ms，可以说服务器性能良好。





而在后续的交易中，服务器响应时间也相对较快，其中下图中的红色标示部分为服务器响应时间：





在上图中，我们可以清晰的看到响应时间一般在0.3ms左右，最高也不过0.5ms。

继续分析该会话的交易信息，发现在序列号193、194、195这三个数据包之间出现了比较大地超时，如下图：





而在序列号为193的数据包解码中，看到ORA-01403: no data found字样。





结合上下文，该no data found响应，是由于客户端进行如下操作时造成：

select count ( *) from xxx*ba where xx* =:1 and xxbz ='Y' and q_q <= :2 and ( xxx) ，（一条select语句）如下图所示：





由于这样一个操作导致了将近2.5s的时间停顿，如下图：





继续分析该会话，又在序列号230、231、232这三个数据包之间出现了一个长达8.9s的传输停顿，如下图：





同样这个停顿也是由于客户端收到了一个no data found的报错，如下图：





而本次客户端上一个操作为：Select Max （xx） From xx Where x =:1 and xx_xx =:2 and

接下来在序列号为244、245、246这三个数据包之间又出现了10.4s的时间停顿，如下图：





同样这个停顿了也伴随了no data found，而这次客户端的操作为：Select MBFS from xx where xx =:1，

综合本次会话中的3次no data found停顿，共造成了2.5+8.9+10.4=21.8s的延时，而整个会话总共为29.4s。也就是在这个29.4s的会话中只有7.6s的时间用于传输有效数据，其中21.8s的时间用于时间停顿，也就造成了该应用的用户体验较差。

三、结论

业务访问慢问题，主要由于客户端的查询错误导致长时间停顿造成。其中在截取的29.4s会话中，只有不足三分之一的时间用于有效的请求、响应及数据传输，大量时间用于停顿。

关于造成该停顿的原因可能跟该应用的客户端程序设计有关，需进一步跟相关应用开发人员协商，准确定位问题原因。

此次分析的入手点是诊断信息定位到的TCP慢反应，需注明此信息与最终的诊断原因并无明显的必然联系，希望大家不要误解。而之所以从此特征能成功找到故障根源，跟网络中该业务数据流较大，且更多会话中都存在该查询等错误有关。

附件：http://down.51cto.com/data/2359792