一、前言
我们的微服务响应生产环境出现一个功能响应时间过慢，对Prometheus监控 Http Request进行分析发下该功能调用的后端接口响应时间平均在30秒以上，分析源码接口有mysql查询、MongoDB查询操作，对慢sql进行分析首先排除了慢sql问题，但是MongoDB作为高性能数据库几乎不会查询缓慢问题，由于没有一个即时的分析工具，无法判断程序在那块耗时较长，只有采取笨办法，在程序各个关键节点输出时间戳日志，最终排查到是MongoDB问题，线上MongoDB因为某种原因导致查询商品的数据到达百万级，而程序开发者在设计时未考虑到大数据情况，因为未设置索引。
1.1 为什么选择Arthas
Arthas是Alibaba开源Java应用诊断工具，具有
- 活跃成熟的社区，文档齐全
- arthas的定位是诊断问题排查，不会长时间attach在进程上，也不会作用在集群，不需要太多考虑对性能的开销
- 支持Docker镜像
- Dashboard实时查看系统的运行状况
- 查看入参/返回值/异常
- 性能热点
- 类冲突
- WebConsole
等特点和特性。更多细节参考 中文官网
二、使用Arthas
Arthas支持单独部署安装arthas-boot.jar和将Arthas安装到基础镜像里两种方式，我们的微服务是基于Dokcer镜像进行发布，因此我们选择将把Arthas安装到基础镜像里：
2.1 使用docker-maven-plugin + Dockerfile构建镜像
# 在pom.xml增加docker-maven-plugin配置
<plugin>
<groupId>com.spotify</groupId>
<artifactId>docker-maven-plugin</artifactId>
<version>1.1.0</version>
<executions>
<execution>
<id>build-image</id>
<phase>package</phase>
<goals>
<goal>build</goal>
</goals>
</execution>
</executions>
<configuration>
<imageName>${project.artifactId}:${project.version}</imageName>
# dockerDirectory 参数表示使用Dockerfile构建镜像，${basedir}表示Dockerfile与pom.xml同级目录
<dockerDirectory>${basedir}</dockerDirectory>
<dockerHost>http://192.168.128.xxxx:2375</dockerHost>
<imageTags>
<imageTag>latest</imageTag>
</imageTags>
<forceTags>true</forceTags>
<resources>
<resource>
<targetPath>/</targetPath>
<directory>${project.build.directory}</directory>
<include>${project.build.finalName}.jar</include>
</resource>
</resources>
</configuration>
</plugin>
</plugins>
</build>
2.2 修改Dockerfile 添加安装arthas代码
FROM java:8
ADD /app.jar //
# copy arthas
COPY --from=hengyunabc/arthas:latest /opt/arthas /opt/arthas
ENTRYPOINT ["java", "-jar", "-Dspring.profiles.active=dev","/app.jar"]
注意Docker构建应该使用完整的JDK基础包，否则会出现Docker应用中arthas无法正常运行的问题，因为Arthas依赖JAVA的命令行工具和类库
2.3 使用公开的JDK基础镜像
FROM openjdk:8-jdk
FROM openjdk:8-jdk-alpine
FROM java:8
三 诊断工具使用案例
3.1 在线实时分析接口响应缓慢问题
生产环境出现接口响应缓慢，常想到分析手段是通过日志埋点来分析接口在那块处理耗费时间长，而通过集成arthas，使用trace命令可以渲染和统计整个调用链路上的所有性能开销和追踪调用链路。
3.1.1 启动Docker 镜像进程中arthas
docker exec -it c86629fdc6cb /bin/bash -c "wget https://arthas.aliyun.com/arthas-boot.jar && java -jar arthas-boot.jar"
启动结果：
[root@localhost ~]# docker exec -it c86629fdc6cb /bin/bash -c "wget https://arthas.aliyun.com/arthas-boot.jar && java -jar arthas-boot.jar"
--2020-11-25 15:17:33-- https://arthas.aliyun.com/arthas-boot.jar
Resolving arthas.aliyun.com (arthas.aliyun.com)... 203.119.214.116
Connecting to arthas.aliyun.com (arthas.aliyun.com)|203.119.214.116|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 138711 (135K) [application/java-archive]
Saving to: ‘arthas-boot.jar’
arthas-boot.jar 100%[========================================================================================>] 135.46K 245KB/s in 0.6s
2020-11-25 15:17:34 (245 KB/s) - ‘arthas-boot.jar’ saved [138711/138711]
[INFO] arthas-boot version: 3.4.4
[INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER.
* [1]: 1 /app.jar
3.1.2 使用trace命令 侦听方法
trace com.myyshop.saas.dsuserserver.controller.TdDsShopController createShop
访问接口，查看侦听结果
`---ts=2020-11-25 07:32:47;thread_name=http-nio-7004-exec-5;id=4c;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@4ba534b0
`---[650.100619ms] com.myyshop.saas.dsuserserver.service.impl.TdDsShopServiceImpl$$EnhancerBySpringCGLIB$$3e545494:createShop()
`---[650.007439ms] org.springframework.cglib.proxy.MethodInterceptor:intercept()
`---[646.06381ms] com.myyshop.saas.dsuserserver.service.impl.TdDsShopServiceImpl:createShop()
+---[0.018917ms] com.myyshop.saas.dsuserserver.utils.LoginUtils:chkLogin() #110
+---[0.006053ms] com.dhgate.saas.common.core.model.LoginAppUser:getUserId() #111
+---[0.015575ms] com.baomidou.mybatisplus.core.conditions.query.QueryWrapper:<init>() #114
+---[0.027124ms] com.baomidou.mybatisplus.core.conditions.query.QueryWrapper:eq() #114
+---[5.757169ms] com.myyshop.saas.dsuserserver.mapper.TdDsShopMapper:selectCount() #114
+---[0.019784ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getDomain() #121
+---[0.016377ms] com.dhgate.saas.common.core.utils.StringUtils:lowerCase() #121
+---[0.008651ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:setDomain() #121
+---[0.005473ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getDomain() #124
+---[1.166932ms] com.myyshop.saas.dsuserserver.utils.DomainUtils:chkIsSensitiveWord() #124
+---[0.008751ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getDomain() #131
+---[3.751548ms] com.myyshop.saas.dsuserserver.utils.DomainUtils:isRegisterDomains() #131
+---[0.008372ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getDomain() #138
+---[0.012716ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getShopName() #138
+---[3.482077ms] com.myyshop.saas.dsuserserver.mapper.TdDsShopMapper:getcount() #138
+---[0.064746ms] com.myyshop.saas.dsuserserver.model.TdDsShop:<init>() #145
+---[0.007541ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getDomain() #146
+---[0.012804ms] com.myyshop.saas.dsuserserver.model.TdDsShop:setDomain() #146
+---[0.009306ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getShopName() #148
+---[0.00715ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getDomain() #148
+---[0.009197ms] com.myyshop.saas.dsuserserver.model.TdDsShop:setShopName() #148
+---[0.007298ms] com.myyshop.saas.dsuserserver.model.TdDsShop:setUserId() #149
+---[0.011004ms] com.myyshop.saas.dsuserserver.model.TdDsShop:setTemplateId() #150
+---[0.007945ms] com.myyshop.saas.dsuserserver.model.TdDsShop:setCreatedAt() #151
+---[0.007562ms] com.myyshop.saas.dsuserserver.model.TdDsShop:setUpdatedAt() #152
+---[4.256693ms] com.myyshop.saas.dsuserserver.mapper.TdDsShopMapper:insert() #153
+---[0.01248ms] com.myyshop.saas.dsuserserver.model.TdDsShop:getShopId() #155
+---[0.018589ms] com.myyshop.saas.dsuserserver.model.TdDsShopSetting$Builder:<init>() #160
+---[0.009691ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getCurrency() #162
+---[0.009491ms] com.myyshop.saas.dsuserserver.model.TdDsShopSetting$Builder:currency() #162
+---[0.007937ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getLanguage() #163
+---[0.008896ms] com.myyshop.saas.dsuserserver.model.TdDsShopSetting$Builder:language() #163
+---[0.007881ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getRefundPolicyUrl() #164
+---[0.009011ms] com.myyshop.saas.dsuserserver.model.TdDsShopSetting$Builder:refundPolicyUrl() #164
+---[0.008243ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getPrivacyPolicyUrl() #165
+---[0.008377ms] com.myyshop.saas.dsuserserver.model.TdDsShopSetting$Builder:privacyPolicyUrl() #165
+---[0.007477ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getShippingTermsUrl() #166
+---[0.013257ms] com.myyshop.saas.dsuserserver.model.TdDsShopSetting$Builder:shippingTermsUrl() #166
+---[0.025617ms] com.myyshop.saas.dsuserserver.model.TdDsShopSetting$Builder:build() #167
+---[10.906103ms] com.myyshop.saas.dsuserserver.service.TdDsShopSettingService:save() #169
+---[609.588604ms] com.myyshop.saas.dsuserserver.feign.MyyshopOrderClient:fistTimeCreateShop() #173
+---[0.024436ms] com.myyshop.saas.dsuserserver.model.dto.TdDsShopParam:getDomain() #179
+---[5.150318ms] com.myyshop.saas.dsuserserver.utils.DomainUtils:setRegisterDomains() #179
+---[0.154152ms] com.dhgate.saas.common.core.utils.CopyUtils:copyObject() #181
+---[0.013183ms] com.myyshop.saas.dsuserserver.model.vo.DsShopVo:setShopId() #182
`---[0.02153ms] com.dhgate.saas.common.core.model.Result:succeed() #184
通过调用链分析，可以看出接口处理大量时间花费到一个feign调用上，可以考虑对该接口进行优化。
网友评论