专栏首页Java架构师进阶不改一行代码定位线上性能问题

不改一行代码定位线上性能问题

背景

最近时运不佳,几乎天天被线上问题骚扰。前几天刚解决了一个 HashSet 的并发问题,周六又来了一个性能问题。

大致的现象是:

我们提供出去的一个 OpenAPI 反应时快时慢,快的时候几十毫秒,慢的时候几秒钟才响应。

尝试解决

如果想学习Java工程化、高性能及分布式、深入浅出。微服务、Spring,MyBatis,Netty源码分析的朋友可以加我的Java高级交流:854630135,群里有阿里大牛直播讲解技术,以及Java大型互联网技术的视频免费分享给大家。

由于这种也不是业务问题,不能直接定位。所以尝试在测试环境复现,但遗憾的测试环境贼快。

没办法只能硬着头皮上了。

中途有抱着侥幸心里让运维查看了 Nginx 里 OpenAPI 的响应时间,想把锅扔给网络。结果果然打脸了;Nginx 里的日志也表明确实响应时间确实有问题。

为了清晰的了解这个问题,我简单梳理了这个调用过程。

整个的流程算是比较常见的分层架构:

客户端请求到 Nginx。

Nginx 负载了后端的 web 服务。

web 服务通过 RPC 调用后端的 Service 服务。

日志大法

我们首先想到的是打日志,在可能会慢的方法或接口处记录处理时间来判断哪里有问题。

但通过刚才的调用链来说,这个请求流程不短。加日志涉及的改动较多而且万一加漏了还有可能定位不到问题。

再一个是改动代码之后还会涉及到发版上线。

工具分析

所以最好的方式就是不改动一行代码把这个问题分析出来。

这时就需要一个 agent 工具了。我们选用了阿里以前开源的 Tprofile 来使用。

只需要在启动参数中加入 -javaagent:/xx/tprofiler.jar 即可监控你想要监控的方法耗时,并且可以给你输出报告,非常方便。对代码没有任何侵入性同时性能影响也较小。

工具使用

如果想学习Java工程化、高性能及分布式、深入浅出。微服务、Spring,MyBatis,Netty源码分析的朋友可以加我的Java高级交流:854630135,群里有阿里大牛直播讲解技术,以及Java大型互联网技术的视频免费分享给大家。

下面来简单展示下如何使用这个工具。

首先第一步自然是 clone 源码然后打包,可以克隆我修改过的源码。

因为这个项目阿里多年没有维护了,还残留一些 bug,我在它原有的基础上修复了个影响使用的 bug,同时做了一些优化。

执行以下脚本即可。

git clone https://github.com/crossoverJie/TProfilermvnassembly:assembly

到这里之后会在项目的 TProfiler/pkg/TProfiler/lib/tprofiler-1.0.1.jar 中生成好我们要使用的 jar 包。

接下来只需要将这个 jar 包配置到启动参数中,同时再配置一个配置文件路径即可。

这个配置文件我 copy 官方的解释。

#log file namelogFileName= tprofiler.logmethodFileName= tmethod.logsamplerFileName= tsampler.log#basic configuration items# 开始取样时间startProfTime=1:00:00# 结束取样时间endProfTime=23:00:00# 取样的时间长度eachProfUseTime=10# 每次取样的时间间隔eachProfIntervalTime=1samplerIntervalTime=20# 端口,主要不要冲突了port=50000debugMode=falseneedNanoTime=false# 是否忽略 get set 方法ignoreGetSetMethod=true#file paths 日志路径logFilePath= /data/work/logs/tprofile/${logFileName}methodFilePath=/data/work/logs/tprofile/${methodFileName}samplerFilePath=/data/work/logs/tprofile/${samplerFileName}#include & excludes itemsexcludeClassLoader= org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader# 需要监控的包includePackageStartsWith= top.crossoverjie.cicada.example.action# 不需要监控的包excludePackageStartsWith= com.taobao.sketch;org.apache.velocity;com.alibaba;com.taobao.forest.domain.dataobject

最终的启动参数如下:

-javaagent:/TProfiler/lib/tprofiler-1.0.1.jar-Dprofile.properties=/TProfiler/profile.properties

为了模拟排查接口响应慢的问题,我用 cicada 实现了一个 HTTP 接口。其中调用了两个耗时方法:

这样当我启动应用时,Tprofile 就会在我配置的目录记录它所收集的方法信息。

我访问接口 http://127.0.0.1:5688/cicada-example/demoAction?name=test&id=10 几次后它就会把每个方法的明细响应写入 tprofile.log。

由左到右每列分别代表为:

线程ID、方法栈深度、方法编号、耗时(毫秒)。

但 tmethod.log 还是空的;

这时我们只需要执行这个命令即可把最新的方法采样信息刷到 tmethod.log 文件中。

java -cp /TProfiler/tprofiler.jarcom.taobao.profile.client.TProfilerClient127.0.0.150000flushmethodflushmethod success

其实就是访问了 Tprofile 暴露出的一个服务,他会读取、解析 tprofile.log 同时写入 tmethod.log.

其中的端口就是配置文件中的 port。

再打开 tmethod.log :

其中会记录方法的信息。

第一行数字为方法的编号。可以通过这个编号去 tprofile.log(明细)中查询每次的耗时情况。

行末的数字则是这个方法在源码中最后一行的行号。

其实大部分的性能分析都是统计某个方法的平均耗时。

所以还需要执行下面的命令,通过 tmethod.log tprofile.log来生成每个方法的平均耗时。

java -cp /TProfiler/tprofiler.jarcom.taobao.profile.analysis.ProfilerLogAnalysistprofiler.logtmethod.logtopmethod.logtopobject.logprint result success

打开 topmethod.log 就是所有方法的平均耗时。

4 为请求次数。

205 为平均耗时。

818 则为总耗时。

和实际情况是相符的。

方法的明细耗时

这是可能还会有其他需求;比如说我想查询某个方法所有的明细耗时怎么办呢?

官方没有提供,但也是可以的,只是要麻烦一点。

比如我想查看 selectDB() 的耗时明细:

首先得知道这个方法的编号,在 tmethod.log 中可以看查到。

2 top/crossoverjie/cicada/example/action/DemoAction:selectDB:84

编号为 2.

之前我们就知道 tprofile.log 记录的是明细,所以通过下面的命令即可查看。

grep2tprofiler.log

通过第三列方法编号为 2 的来查看每次执行的明细。

但这样的方式显然不够友好,需要人为来过滤干扰,步骤也多;所以我也准备加上这样一个功能。

只需要传入一个方法名称即可查询采集到的所有方法耗时明细。

总结

回到之前的问题;线上通过这个工具分析我们得到了如下结果。

有些方法确实执行时快时慢,但都是和数据库相关的。由于目前数据库压力较大,准备在接下来进行冷热数据分离,以及分库分表。

在第一步操作还没实施之前将部分写数据库的操作改为异步,减小响应时间。

考虑接入 pinpoint 这样的 APM工具。

类似于 Tprofile 的工具确实挺多的,找到适合自己的就好。

在还没有使用类似于 pinpoint 这样的分布式跟踪工具之前应该会大量依赖于这个工具,所以后续说不定也会做一些定制,比如增加一些可视化界面等,可以提高排查效率。

如果想学习Java工程化、高性能及分布式、深入浅出。微服务、Spring,MyBatis,Netty源码分析的朋友可以加我的Java高级交流:854630135,群里有阿里大牛直播讲解技术,以及Java大型互联网技术的视频免费分享给大家。

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

我来说两句

0 条评论
登录 后参与评论

相关文章

  • Java 常见的 30 个误区与细节!

    1、在Java中,没有goto语句。因为大量使用goto语句会降低程序的可读性和可维护性,所以Java语言取消了goto的使用。同时,为了避免程序员自行使用go...

    java架构师
  • Kafka Producer Consumer

    org.apache.kafka.clients.producer.KafkaProducer

    java架构师
  • 被标记为事务的方法互相调用的坑(上)

    相信大家一定用过Spring中的注解型事务,配合上Spring Boot,只需要在方法上打一个@Transactional 就可以完成,真香。

    java架构师
  • WordPress上传图片静态文件同步腾讯云COS对象云存储插件

    WordPress,作为全球用户量最大的免费CMS程序,小到个人博客、大到企业网站、电子商务网站都可以使用。WordPress虽然也有各种优势,但是也有不小的缺...

    Alexaer
  • matlab—进阶绘图

    这里我们要讲的是画一些与对数(log)有关的图像,这里的log,既可以是图像是log,又可以是坐标轴是log,我们接下来用一个例子来说明

    mathor
  • RoadStar创始人曝光真相:投资方忽然冻结账户,威逼利诱抢公章

    4月4日,深科技发出文章《“他不让我们活”:中国首例无人车公司猝死成罗生门?丨专访Roadstar员工、投资人代表》。

    量子位
  • 面试需要注意哪些问题?这里有程序员求职面试的66个细节整理

    要想面试成功,这不仅仅是关于情商、智商、逆商、专业能力等个人与个人的较量,更是个人与群体的博弈。这个时候掌握一些我多年积累下来的锦囊,无疑是事半功倍的。

    Android技术干货分享
  • 编程语言之间的差别真有那么大吗?

    软件开发是一种特殊的职业,特殊到有点匪夷所思,行业从业人员的工种分类非常的不稳定, 比如说古时候有C工程师、C++工程师、VB工程师,后来有了Java工程师、....

    用户1608022
  • 以太网的新时代

    以太网(Ethernet)无处不在,已经达到开创者最初想到达到的境界—ETHER,成为人类信息社会无处不在的媒介。以太网已经发展了40多年,以太网的发展历史大致...

    SDNLAB
  • 2020年4月程序员工资统计,人工智能工资大跌

    统计异常的城市,是为了找出数据中的异常。第一次做这张图的时候,有5个城市异常,经过删除异常数据,减少到了两个。

    IT苦逼一枚

扫码关注云+社区

领取腾讯云代金券