标签：问题 22 履约 网络流量 OMS sql 日志 超时 尖刺
1.现象: OMS订单履约系统调用供应链基础服务接口超时(图1)
图1
2.调用链查看: 供应链基础服务这段时间内存在一定的接口超时(图2)
图2
-
根据以往经验首先想到是服务有频繁FULLGC,查看服务是否频繁fullgc
进入jdk bin目录下执行 ./jstat -gccause <进程id> <时间(单位毫秒)> (图3)图3
发现虽然有fullgc,但是7月4号启动的进程到7月9号, 总共fullgc次数为14次. 每天平均不到3次 (图4)
图4
4.此时可以断定代码有问题,但是不足以致命,继续跟踪应用服务器性能监控
cpu: 发现9:22分左右有明显尖刺, 但是整体cpu负载在40%以下(图5)
图5
网络: 网络流量在9:22分左右有明显尖刺,说明有大量的数据流量占据网络IO(图6)
图6
5.根据上述性能指标分析, 数据包数据来源估计是从DB读取的数据写入到内存,接下来我们看DB的性能指标
cpu: 9:22分左右cpu使用率在12%左右, 整体负载不高(图7)
图7
iops: iops数据在9:22左右有尖刺, 说明此事有一波较大的瞬时流量打入到DB(图8)
图8
网络流量: 根据9:22分左右网络流量的尖刺, 平均每秒钟输出流量峰值为:46178.8kb, 说明此段时间内存在有问题的查询语句, 并且查询返回的数据量较大,也可能是瞬时并发较大,导致整体的网络流量出现尖刺(图9)
图9
6.根据上述问题,继续往下跟,既然知道了可能是存在大数据量查询的sql语句, 那我们就正好利用sql统计中的审计日志来进行分析
首先,选择时间段,生成审计日志(图10)
图10
然后对审计日志进行分析,因为我想查找到底是哪个sql返回的行数较大, 所以分析维度选择返回行数
发现第一个sql执行了2次居然返回了6587993行数据, 第二个sql执行了218次,返回了1274864行数据,
sql1:
sql2:
- 由此,问题的根本原因基本找到, 这两个sql语句对应的接口在设计上存在问题,第一个是操作日志表(因为历史原因,这个表是整个供应链记录操作记录的日志表), type为5的数据有10108830条记录(表中总共数据为18037716条), 第二个sql是每次查全部生效的类目数据, 但是查询次数较多,并且没有缓存, 穿透到DB, 这两个问题综合引起了整个网络流量的尖刺.
8.后续解决方案
A.操作记录日志表及服务按照业务线拆分并做数据迁移.
B.梳理调用量较大并且数据变更频率不高的接口,完善相应的缓存机制.
C.一般问题出现时如果初步断定是网络问题的话, 都很有可能是系统问题引起的.需要进一步跟进具体产生此类问题的根源.
附:
第2步中细节部分
1.详细调用链路
上图中的调用行为分以下四种：
cs - Client Send : 客户端已经提出了请求。这就设置了跨度的开始。
sr - Server Receive: 服务器已收到请求并将开始处理它。这与CS之间的差异将是网络延迟和时钟抖动的组合。
ss - Server Send: 服务器已完成处理，并将请求发送回客户端。这与SR之间的差异将是服务器处理请求所花费的时间
cr - Client Receive : 客户端已经收到来自服务器的响应。这就设置了跨度的终点。当记录注释时，RPC被认为是完整的。
2.总上所述.基础服务整个的接口内部处理时间为ss-sr = 2019-07-09 09:23:21 199 - 2019-07-09 09:23:21 190 = 9ms, 但是返回给客户端的RPC耗时为cs-cr = 6s . 很大程度上断定这就是网路问题引起的, 但是一般问题出现时如果初步断定是网络问题的话,
都很有可能是系统问题引起的.需要进一步跟进具体产生此类问题的根源.
标签：问题,22,履约,网络流量,OMS,sql,日志,超时,尖刺 来源： https://blog.csdn.net/guofeng5201314/article/details/113580454
本站声明： 1. iCode9 技术分享网（下文简称本站）提供的所有内容，仅供技术学习、探讨和分享； 2. 关于本站的所有留言、评论、转载及引用，纯属内容发起人的个人观点，与本站观点和立场无关； 3. 关于本站的所有言论和文字，纯属内容发起人的个人观点，与本站观点和立场无关； 4. 本站文章均是网友提供，不完全保证技术分享内容的完整性、准确性、时效性、风险性和版权归属；如您发现该文章侵犯了您的权益，可联系我们第一时间进行删除； 5. 本站为非盈利性的个人网站，所有内容不会用来进行牟利，也不会利用任何形式的广告来间接获益，纯粹是为了广大技术爱好者提供技术内容和技术思想的分享性交流网站。