不改一行代码定位线上性能问题
背景
最近时运不佳,几乎天天被线上问题骚扰。前几天刚解决了一个 HashSet 的并发问题,周六又来了一个性能问题。
大致的现象是:
我们提供出去的一个 OpenAPI 反应时快时慢,快的时候几十毫秒,慢的时候几秒钟才响应。
尝试解决
由于这种也不是业务问题,不能直接定位。所以尝试在测试环境复现,但遗憾的测试环境贼快。
没办法只能硬着头皮上了。
中途有抱着侥幸心里让运维查看了 Nginx
里 OpenAPI
的响应时间,想把锅扔给网络。结果果然打脸了;Nginx
里的日志也表明确实响应时间确实有问题。
为了清晰的了解这个问题,我简单梳理了这个调用过程。
整个的流程算是比较常见的分层架构:
- 客户端请求到
Nginx
。 Nginx
负载了后端的web
服务。web
服务通过RPC
调用后端的Service
服务。
日志大法
我们首先想到的是打日志,在可能会慢的方法或接口处记录处理时间来判断哪里有问题。
但通过刚才的调用链来说,这个请求流程不短。加日志涉及的改动较多而且万一加漏了还有可能定位不到问题。
再一个是改动代码之后还会涉及到发版上线。
工具分析
所以最好的方式就是不改动一行代码把这个问题分析出来。
这时就需要一个 agent
工具了。我们选用了阿里以前开源的 Tprofile 来使用。
只需要在启动参数中加入 -javaagent:/xx/tprofiler.jar
即可监控你想要监控的方法耗时,并且可以给你输出报告,非常方便。对代码没有任何侵入性同时性能影响也较小。
工具使用
下面来简单展示下如何使用这个工具。
首先第一步自然是 clone
源码然后打包,可以克隆我修改过的源码。
因为这个项目阿里多年没有维护了,还残留一些
bug
,我在它原有的基础上修复了个影响使用的bug
,同时做了一些优化。
执行以下脚本即可。
git clone https://github.com/crossoverJie/TProfilermvn assembly:assembly
到这里之后会在项目的 TProfiler/pkg/TProfiler/lib/tprofiler-1.0.1.jar
中生成好我们要使用的 jar 包。
接下来只需要将这个 jar 包配置到启动参数中,同时再配置一个配置文件路径即可。
这个配置文件我 copy 官方的解释。
#log file name
logFileName = tprofiler.log
methodFileName = tmethod.log
samplerFileName = tsampler.log#basic configuration items
# 开始取样时间
startProfTime = 1:00:00# 结束取样时间
endProfTime = 23:00:00# 取样的时间长度
eachProfUseTime = 10# 每次取样的时间间隔
eachProfIntervalTime = 1samplerIntervalTime = 20# 端口,主要不要冲突了
port = 50000
debugMode = false
needNanoTime = 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 items
excludeClassLoader = 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.jar com.taobao.profile.client.TProfilerClient 127.0.0.1 50000 flushmethodflushmethod success
其实就是访问了 Tprofile
暴露出的一个服务,他会读取、解析 tprofile.log
同时写入 tmethod.log
.
其中的端口就是配置文件中的 port。
再打开 tmethod.log
:
其中会记录方法的信息。
- 第一行数字为方法的编号。可以通过这个编号去
tprofile.log
(明细)中查询每次的耗时情况。 - 行末的数字则是这个方法在源码中最后一行的行号。
其实大部分的性能分析都是统计某个方法的平均耗时。
所以还需要执行下面的命令,通过 tmethod.log tprofile.log
来生成每个方法的平均耗时。
java -cp /TProfiler/tprofiler.jar com.taobao.profile.analysis.ProfilerLogAnalysis tprofiler.log tmethod.log topmethod.log topobject.log
print result success
打开 topmethod.log
就是所有方法的平均耗时。
- 4 为请求次数。
- 205 为平均耗时。
- 818 则为总耗时。
和实际情况是相符的。
方法的明细耗时
这是可能还会有其他需求;比如说我想查询某个方法所有的明细耗时怎么办呢?
官方没有提供,但也是可以的,只是要麻烦一点。
比如我想查看 selectDB()
的耗时明细:
首先得知道这个方法的编号,在 tmethod.log
中可以看查到。
2 top/crossoverjie/cicada/example/action/DemoAction:selectDB:84
编号为 2.
之前我们就知道 tprofile.log
记录的是明细,所以通过下面的命令即可查看。
grep 2 tprofiler.log
通过第三列方法编号为 2 的来查看每次执行的明细。
但这样的方式显然不够友好,需要人为来过滤干扰,步骤也多;所以我也准备加上这样一个功能。
只需要传入一个方法名称即可查询采集到的所有方法耗时明细。
总结
回到之前的问题;线上通过这个工具分析我们得到了如下结果。
- 有些方法确实执行时快时慢,但都是和数据库相关的。由于目前数据库压力较大,准备在接下来进行冷热数据分离,以及分库分表。
- 在第一步操作还没实施之前将部分写数据库的操作改为异步,减小响应时间。
- 考虑接入
pinpoint
这样的APM工具
。
类似于 Tprofile 的工具确实挺多的,找到适合自己的就好。
在还没有使用类似于 pinpoint
这样的分布式跟踪工具之前应该会大量依赖于这个工具,所以后续说不定也会做一些定制,比如增加一些可视化界面等,可以提高排查效率。
你的点赞与分享是对我最大的支持
不改一行代码定位线上性能问题相关推荐
- 不改一行代码定位线上性能问题 1
作者:crossoverJie 来源:crossoverJie 背景 最近时运不佳,几乎天天被线上问题骚扰.前几天刚解决了一个 HashSet 的并发问题,周六又来了一个性能问题. 大致的现象是: 我 ...
- 不改一行代码!快速迁移 Flask 应用上云
目前大部分应用都以 Web 形式提供,因此 Web 框架开发已经成了不少开发者必不可少的技能.而 Flask 是一种非常容易上手的 Python Web 开发框架,开发者只需要具备基本的 python ...
- 不改一行代码,将微信小程序转成商业App?
Web2.0前期的"眼球经济",即以吸引用户长时间观看内容.使用工具为导向,占有用户的"屏幕时间"(Screen time),从中寻求各种"变现&qu ...
- 有了这款工具,定位线上问题事半功倍|云效工程师指北
大家好,我叫刘玄,负责云效流水线的开发.程序员在日常工作中经常会遇到一些线上问题需要排查,本文的主人公程序员小张也不例外.但排查的过程却时常令他困扰不已.让我们一起看看他遇到了哪些问题,又是怎么解决的 ...
- 前端录屏+定位源码,帮你快速定位线上bug
前言 如何快速定位线上bug,是多数开发者都会遇到的难题 web-see 前端监控方案,提供了 前端录屏+定位源码 方式,让bug无处藏身 这是前端监控的第二篇,该篇讲解如何实现错误还原功能,第一篇 ...
- 抓包神器 Wireshark,帮你快速定位线上网络故障(3)
1 复习:TCP 三次握手&四次挥手 正式分享之前,先简单复习一下 TCP 的三次握手.四次挥手. TCP 通过三次握手建立连接(一图解千愁): TCP 协议通过四次挥手断开连接(一图知所 ...
- 不改一行代码!快速迁移 Express 应用上云
作为目前最流行的 Node 框架之一,Express 框架提供了一系列强大特性,帮助用户创建各种 Web 应用和丰富的 HTTP 工具,同时它也是是许多其它流行 Node 框架的底层库. Server ...
- 不改一行代码!快速迁移 Koa 应用上云
Koa 是现在最流行的基于 Node.js 平台的 Web 开发框架之一,由 Express 原班人马打造,利用 async 函数,Koa 丢弃了回调函数,并有力地增强错误处理,受到开发者普遍欢迎. ...
- 如何不改一行代码,让Hippy启动速度提升50%?
导读|Hippy使用JS引擎进行异步渲染,在用户从点击到打开首屏可交互过程中会有一定的耗时,影响用户体验.如何优化这段耗时?腾讯客户端开发工程师李鹏,将介绍QQ浏览器通过切换JS引擎来优化耗时的探索过 ...
最新文章
- 《Java程序员,上班那点事儿》序——刘博
- 排序算法的实现(C/C++实现)
- P6880-[JOI 2020 Final]オリンピックバス【最短路】
- 五个 SQL 查询性能测试题,只有 40% 及格率,你敢来挑战吗?
- SVG.js 颜色渐变使用
- 好用的文本编辑器推荐
- bbsmax mysql_MySQL中自己不太常用的命令
- 十大免费PHP编辑器-开发工具
- python布尔值使用_如何在Python中使用布尔值?
- python爬12306余票_Python 爬取12306火车票
- 笨功夫与巧心思,Milvus开源社区的成长
- 求矩阵主对角线元素及副对角线元素之和
- 视神经萎缩学计算机专业好吗,治视神经萎缩的维生素 视神经萎缩有哪些症状...
- word公式和图片显示不完全
- 《JavaScript》JavaScript教程
- Windows10安装开源Mujoco
- 网课答案公众号小白教程——手把手教你创建自己的大学查题公众号
- 计算机窗口的跳转列表,win7[开始]菜单和任务栏最近打开的项目(跳转列表)
- python 之 print用法
- [kubernetes]-k8s通过设置yaml中env的值动态调整nginx端口
热门文章
- ACL,NAACL,EMNLP,IJCNLP以及ACL、EMNLP2021论文模板
- 关于自动驾驶, Mobileye 的 14 个最新观点
- 重磅!2019年诺贝尔生理学或医学奖揭晓,“细胞感知氧气通路”摘得桂冠
- CCAI2018演讲实录 | 蒲慕明:脑科学与类脑机器学习
- DARPA盘点2017年最受关注的十大科技新闻
- 近 100 场专题演讲、14 大沉浸式应用场景…别不信!这是真·烧脑技术盛会
- 9 岁自学编程、24 岁身价涨至数百万美元,与微软一较高低的大佬多厉害?
- 平均 14926 元!2021 年 5 月程序员工资统计出炉
- 开源吞噬世界,得开发者得天下
- ​他被称为印度“ IT 大王”,富可敌国,却精打细算如守财奴