JVM那点事—show-busy-java-threads排查CPU性能问题

show-busy-java-thread用于快速排查Java的CPU性能问题(top us值过高),自动查出运行的JAVA进程中消耗CPU多的线程,并打印出其线程栈,从而确定导致性能问题的方法调用。

1. 以往方法

  1. top命令找出消耗CPU高的Java进程及其线程id:
    i. 开启线程的显示模式(top -H,或者打开top后按H)。
    ii. 按cpu使用率排序(top缺省就是按CPU的使用率降序)。
    iii. 记下Java进程id及其CPU高的线程id。
  2. 查看消耗CPU高的线程栈:
    i. 用进程id作为参数,jstack出有问题的Java进程。
    ii. 手动转换线程id成16进制(可以使用printf %x pid)。
    iii. 在jstack输出中查找16进制的线程id(jstack -l pid > test.txt | grep16进制的值)
  3. 查看对应的线程栈,分析问题。

查问题时,会要多次上面的操作以分析确定问题,这个过程太繁琐太慢了。

2. show-busy-java-threads命令

注意:show-busy-java-threads只支持Linux服务器

2.1 安装

推荐使用直接在网络上下载安装包,并解压的方式。

## 下载安装包
source-shell
wget --no-check-certificate https://github.com/oldratlee/useful-scripts/archive/release.zip
## 解压
unzip release.zip

其他方式可参考:GitHub上show-busy-java-threads安装方式

2.2 常用命令

使用方式:sh show-busy-java-threads.sh

2.2.1 基本命令

# 从所有运行的Java进程中找出最消耗CPU的线程(缺省5个),打印出其线程栈
show-busy-java-threads

# 缺省会自动从所有的Java进程中找出最消耗CPU的线程,这样用更方便
# 当然你可以手动指定要分析的Java进程Id,以保证只会显示你关心的那个Java进程的信息
show-busy-java-threads -p <指定的Java进程Id>

show-busy-java-threads -c <要显示的线程栈数>

# 多次执行
show-busy-java-threads <重复执行的间隔秒数> [<重复执行的次数>]

# 记录到文件以方便回溯查看
show-busy-java-threads -a <运行输出的记录到的文件>

# 指定jstack输出文件的存储目录,方便记录以后续分析
show-busy-java-threads -S <存储jstack输出文件的目录>

2.2.2 注意事项

# 如果Java进程的用户 与 执行脚本的当前用户 不同,则jstack不了这个Java进程
# 为了能切换到Java进程的用户,需要加sudo来执行,即可以解决:
sudo show-busy-java-threads

# 对于sudo方式的运行,JAVA_HOME环境变量不能传递给root,
# 而root用户往往没有配置JAVA_HOME且不方便配置,
# 显式指定jstack命令的路径就反而显得更方便了
show-busy-java-threads -s <指定jstack命令的全路径>

2.2.3 其他命令

# -m选项:执行jstack命令时加上-m选项,显示上Native的栈帧,一般应用排查不需要使用
show-busy-java-threads -m
# -F选项:执行jstack命令时加上 -F 选项(如果直接jstack无响应时,用于强制jstack),一般情况不需要使用
show-busy-java-threads -F
# -l选项:执行jstack命令时加上 -l 选项,显示上更多相关锁的信息,一般情况不需要使用
# 注意:和 -m -F 选项一起使用时,可能会大大增加jstack操作的耗时
show-busy-java-threads -l

2.3 示例

$ show-busy-java-threads
[1] Busy(57.0%) thread(23355/0x5b3b) stack of java process(23269) under user(admin):
"pool-1-thread-1" prio=10 tid=0x000000005b5c5000 nid=0x5b3b runnable [0x000000004062c000]
   java.lang.Thread.State: RUNNABLE
    at java.text.DateFormat.format(DateFormat.java:316)
    at com.xxx.foo.services.common.DateFormatUtil.format(DateFormatUtil.java:41)
    at com.xxx.foo.shared.monitor.schedule.AppMonitorDataAvgScheduler.run(AppMonitorDataAvgScheduler.java:127)
    at com.xxx.foo.services.common.utils.AliTimer$2.run(AliTimer.java:128)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:662)

[2] Busy(26.1%) thread(24018/0x5dd2) stack of java process(23269) under user(admin):
"pool-1-thread-2" prio=10 tid=0x000000005a968800 nid=0x5dd2 runnable [0x00000000420e9000]
   java.lang.Thread.State: RUNNABLE
    at java.util.Arrays.copyOf(Arrays.java:2882)
    at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:100)
    at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:572)
    at java.lang.StringBuffer.append(StringBuffer.java:320)
    - locked <0x00000007908d0030> (a java.lang.StringBuffer)
    at java.text.SimpleDateFormat.format(SimpleDateFormat.java:890)
    at java.text.SimpleDateFormat.format(SimpleDateFormat.java:869)
    at java.text.DateFormat.format(DateFormat.java:316)
    at com.xxx.foo.services.common.DateFormatUtil.format(DateFormatUtil.java:41)
    at com.xxx.foo.shared.monitor.schedule.AppMonitorDataAvgScheduler.run(AppMonitorDataAvgScheduler.java:126)
    at com.xxx.foo.services.common.utils.AliTimer$2.run(AliTimer.java:128)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:662)

......

上面的线程栈可以看出,CPU消耗最高的2个线程都在执行java.text.DateFormat.format,业务代码对应的方法是shared.monitor.schedule.AppMonitorDataAvgScheduler.run。可以基本确定:

AppMonitorDataAvgScheduler.run调用DateFormat.format次数比较频繁。
DateFormat.format比较慢。(这个可以由DateFormat.format的实现确定。)
多执行几次show-busy-java-threads,如果上面情况高概率出现,则可以确定上面的判定。
因为调用越少代码执行越快,则出现在线程栈的概率就越低。
脚本有自动多次执行的功能,指定 重复执行的间隔秒数/重复执行的次数 参数。

分析shared.monitor.schedule.AppMonitorDataAvgScheduler.run实现逻辑和调用方式,以优化实现解决问题。

推荐阅读

show-busy-java-threads的github地址

相关文章

Arthas——java调试工具的使用

JVM那点事—show-busy-java-threads排查CPU性能问题

JVM那点事—火焰图(flame graph)性能分析

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 205,033评论 6 478
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 87,725评论 2 381
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 151,473评论 0 338
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,846评论 1 277
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,848评论 5 368
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,691评论 1 282
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 38,053评论 3 399
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,700评论 0 258
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 42,856评论 1 300
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,676评论 2 323
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,787评论 1 333
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,430评论 4 321
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 39,034评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,990评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,218评论 1 260
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 45,174评论 2 352
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,526评论 2 343

推荐阅读更多精彩内容