cpu分析利器 — async-profiler

捉虫大师
• 阅读 2232

本文已收录 https://github.com/lkxiaolou/lkxiaolou 欢迎star。

简介

async-profiler是一款采集分析java性能的工具,翻译一下github上的项目介绍:

async-profiler是一款没有Safepoint bias problem的低开销java采集分析器,它利用HotSpot特殊的api来收集栈信息以及内存分配信息,可以在OpenJDK,Oracle JDK以及一些其他的基于HotSpot的java虚拟机。async-profiler可以追踪以下几种事件:

  • cpu周期
  • 硬件和软件性能计数器,例如高速缓存未命中,分支未命中,页面错误,上下文切换等
  • Java堆中内存的分配
  • 锁尝试,包括Java对象监视器和ReentrantLock

使用方法

首先下载async-profiler,github主页(https://github.com/jvm-profiling-tools/async-profiler) 上有已经编译好的文件,找到对应的平台下载即可

cpu分析利器 — async-profiler

基本用法

下载好的文件解压后,有一个profiler.sh脚本,运行脚本即可对java进程进行cpu分析,例如java进程id为1232

./profiler.sh start 1232
./profiler.sh stop 1232

或者可以用-d指定剖析的时间(秒)

./profiler.sh -d 30 1232 

执行完成后会输出采集的信息:

cpu分析利器 — async-profiler

通常我们会用更加直观的火焰图来绘制输出的信息,使用参数-f {$file_name}.svg

./profiler.sh -d 30 -f ./nacos.svg 1232

命令执行完成后会生成一个svg格式的文件,用浏览器打开

cpu分析利器 — async-profiler

火焰图怎么看?可以参考阮一峰的文章

《如何读懂火焰图》 http://www.ruanyifeng.com/blog/2017/09/flame-graph.html

简单来说:x轴是抽样数,x轴越长说明被这个方法被抽样的次数越多,消耗cpu时间也越长 y轴是栈的深度,通常越往上越细,如果发现往上有一个平顶,且平顶很宽,则说明它可能有问题,消耗cpu时间较多。

其他参数介绍

  • -e event

event 可选参数用这个命令来查看

./profiler.sh list list 1232

输出样例:

cpu分析利器 — async-profiler

event 默认为cpu,也可以用alloc来查看内存分配

./profiler.sh -e alloc -d 30 -f ./nacos-alloc.svg 1232

cpu分析利器 — async-profiler

lock查看锁情况:

cpu分析利器 — async-profiler

其他的模式这里就不一一尝试,用的最多的还是cpu模式。

  • -i N 设置采样频率,默认是10ms,可使用ms,us,s作为单位,无单位默认为纳秒,如
./profiler.sh -i 500us -d 30
  • -j N 设置栈采样深度

  • -o fmt 设置输出格式:可选的有 summary、traces、flat、jfr、collapsed、svg、tree,最常用的是svg

更多命令可参考async-profiler github主页

一次网关性能压测实例

笔者有一次在压测全链路异步网关时,RPS在2000左右,始终上不去,cpu消耗比较高,于是使用async-profiler进行cpu剖析,生成的火焰图如下

cpu分析利器 — async-profiler

可以看到这里有个宽又深的栈,它消耗了很多cpu,限于图像大小,再往上拉,看下这块到底是什么

cpu分析利器 — async-profiler

从类名就能看出是log4j,猜测是代码某处打日志过于频繁导致,找到打日志的地方后先去掉日志,压测了一下,果然RPS提升到了5000,一处小小的日志竟有如此大的影响。

原理介绍

看到这里相信你应该会用async-profiler来进行cpu剖析了,如果感兴趣可以了解下async-profiler实现的原理,这块有一篇文章介绍的很详细,可以参考

《JVM CPU Profiler技术原理及源码深度解析》 https://mp.weixin.qq.com/s/RKqmy8dw7B7WtQc6Xy2CLA

简单总结一下:

  • cpu profiler实现一般有两种方案:(1)Sampling,采样(2)Instrumentation,埋点;采样对性能损耗较小但没那么准确,埋点(类似AOP)精准但性能影响大
  • Sampling采样只能在Safe Point处采样,会导致统计结果偏差,也就是开头说的Safepoint bias problem,例如某些方法执行时间短,但执行频率高,正真占用了cpu,这部分如果Sampling的采样频率不能足够小,可能就采样不到,但采样频率过高又会影响性能,这就是一般的基于采样的cpu profiler的缺点
  • async-profiler是基于采样实现的,但它又没有Safepoint bias problem,它是通过一种叫做AsyncGetCallTrace的方式来采样,这种采样不需要在安全点处采样,但这个函数不是那么容易就调用到的,需要使用一些技巧(黑科技)的方式来获取

正是第三点原因我才写了这篇文章来推荐这款cpu分析利器,比如我用了一款其他的分析器(uber-common/jvm-profiler)来分析上面网关的cpu,得出了如下的火焰图

cpu分析利器 — async-profiler

如果是这样,完全没法找到问题。而且阿里开源的Arthas中的cpu分析也是使用的async-profiler。所以你不试试吗?


搜索关注微信公众号"捉虫大师",后端技术分享,架构设计、性能优化、源码阅读、问题排查、踩坑实践。

cpu分析利器 — async-profiler

点赞
收藏
评论区
推荐文章
blmius blmius
3年前
MySQL:[Err] 1292 - Incorrect datetime value: ‘0000-00-00 00:00:00‘ for column ‘CREATE_TIME‘ at row 1
文章目录问题用navicat导入数据时,报错:原因这是因为当前的MySQL不支持datetime为0的情况。解决修改sql\mode:sql\mode:SQLMode定义了MySQL应支持的SQL语法、数据校验等,这样可以更容易地在不同的环境中使用MySQL。全局s
皕杰报表之UUID
​在我们用皕杰报表工具设计填报报表时,如何在新增行里自动增加id呢?能新增整数排序id吗?目前可以在新增行里自动增加id,但只能用uuid函数增加UUID编码,不能新增整数排序id。uuid函数说明:获取一个UUID,可以在填报表中用来创建数据ID语法:uuid()或uuid(sep)参数说明:sep布尔值,生成的uuid中是否包含分隔符'',缺省为
待兔 待兔
3个月前
手写Java HashMap源码
HashMap的使用教程HashMap的使用教程HashMap的使用教程HashMap的使用教程HashMap的使用教程22
Jacquelyn38 Jacquelyn38
3年前
2020年前端实用代码段,为你的工作保驾护航
有空的时候,自己总结了几个代码段,在开发中也经常使用,谢谢。1、使用解构获取json数据let jsonData  id: 1,status: "OK",data: 'a', 'b';let  id, status, data: number   jsonData;console.log(id, status, number )
捉虫大师 捉虫大师
3年前
盘点golang中的开发神器
本文已收录https://github.com/lkxiaolou/lkxiaolou欢迎star。在Java中,我们用Junit做单元测试,用JMH做性能基准测试(benchmark),用asyncprofiler剖析cpu性能,用jstack、jmap、arthas等来排查问题。作为一名比较新的编程语言,golang的这些工具是否更加好用呢?单元测
Wesley13 Wesley13
3年前
00:Java简单了解
浅谈Java之概述Java是SUN(StanfordUniversityNetwork),斯坦福大学网络公司)1995年推出的一门高级编程语言。Java是一种面向Internet的编程语言。随着Java技术在web方面的不断成熟,已经成为Web应用程序的首选开发语言。Java是简单易学,完全面向对象,安全可靠,与平台无关的编程语言。
Stella981 Stella981
3年前
Django中Admin中的一些参数配置
设置在列表中显示的字段,id为django模型默认的主键list_display('id','name','sex','profession','email','qq','phone','status','create_time')设置在列表可编辑字段list_editable
Stella981 Stella981
3年前
Linux日志安全分析技巧
0x00前言我正在整理一个项目,收集和汇总了一些应急响应案例(不断更新中)。GitHub地址:https://github.com/Bypass007/EmergencyResponseNotes本文主要介绍Linux日志分析的技巧,更多详细信息请访问Github地址,欢迎Star。0x01日志简介Lin
Wesley13 Wesley13
3年前
MySQL部分从库上面因为大量的临时表tmp_table造成慢查询
背景描述Time:20190124T00:08:14.70572408:00User@Host:@Id:Schema:sentrymetaLast_errno:0Killed:0Query_time:0.315758Lock_
Python进阶者 Python进阶者
9个月前
Excel中这日期老是出来00:00:00,怎么用Pandas把这个去除
大家好,我是皮皮。一、前言前几天在Python白银交流群【上海新年人】问了一个Pandas数据筛选的问题。问题如下:这日期老是出来00:00:00,怎么把这个去除。二、实现过程后来【论草莓如何成为冻干莓】给了一个思路和代码如下:pd.toexcel之前把这