场景:

线上一个功能打开日志显示如下,ClientAbortException客户端中止异常,此功能在公司测试环境正常,另外线上的服务都是docker部署的,使用的是动态数据源,微服务库用的mysql库,业务库用的postgreSql库

Finished to call API:/process/getTaskAndFileBag/cf192870-e1a1-11ed-891a-5a5fd865df76/zb
Elapsed time : 68596 ms

org.apache.catalina.connector.ClientAbortException: java.io.IOException: Broken pipe
at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:341)

排查工具:

arthas

现象分析:

发现日志接口响应时间约69s了,而网关gateway中设置的响应时间为60s,超时所以客户端断开了,按理讲此时只要修改gateway客户端响应时间就可了,但是一个简单的接口怎么如此耗时呢?

用arthas追踪了一下接口,发现两个问题。

第一:

用arthas的trace命令显示如下,在对象实例化的时候非常耗时。

第二:

在接口从请求发出到arthas的追踪请求方法的过程中,非常慢!!!大概要1~2分钟才触发arthas

分析:

按理讲一个简单的构造函数怎么会如此耗时呢,根据arthas使用过程中发现的第二个问题,初步定位在网关转发有问题,因为第一个问题在追踪的过程中,内部调用了其它服务的接口,因为网关转发很慢,所以追踪到的接口就非常耗时,那么网关为什么转发的如此慢呢?代码在测试环境是没问题的(网关已经很多地方都在用了,而且还用的很久),所以排除是代码的问题。

配置排查。

cpu排查

top命令发现cpu正常

(注:131785这个进程cpu占比100%,但是网上查阅资料由于占用内存是0,所以对系统的性能是没有影响,项目经理讲这样做是提供cpu利用率)

负载排查:

uptime查看负载,负载最大的是5.39

线上cpu是16核,正常

内存,网络、磁盘IO排查

free -h

iftop

iotop

项目经理图未截取,告诉我正常的。

数据库:

索引,慢查询sql排查

SETGLOBALslow_query_log=’ON’;
SETGLOBALlong_query_time=5;
FLUSHLOGS;

索引和本地测试环境建立的索引一样,且没有生成超过5秒的慢sql.因此结果正常

表死锁排查

SHOWOPENTABLESWHEREIn_use>0;

结论:mysql是表级锁,未查到任何,因此没有锁问题。

SELECTpid,relname,modeFROMpg_locksJOINpg_classONpg_locks.relation=pg_class.oid;

结论:postgresql是行级锁,虽然查到了存在但是与我的业务表没有任何关系,因此没有问题。

数据库的连接数排查

HOWSTATUSWHERE`variable_name`=’Threads_connected’;

注:配置文件中数据库设置的最大连接数200,而线上排查是60,因此正常。

docker stats命令

docker stats这个命令之前排查问题的时候很少使用,因此使用docker部署的服务有时候性能问题可以尝试使用这个命令。

问题原因终于找到了,问了运维在部署gateway和oauth服务内存大小限制在1G,线上内存占用都超过50%那不鸡鸡了!!!!,修改后正常了