aix kill java_AIX环境Java进程cpu瓶颈分析(转)
http://blog.csdn.net/fjpqzm/article/details/24261773
1. 环境信息
机器
CPU(个)
内存
系统
DBA(数据库服务器A)
16(64 core)
256G
AIX 6100-08(AL770_048)
DBB(数据库服务器B)
16(64 core)
256G
AIX 6100-08(AL770_048)
APPA(应用服务器A)
16(64 core)
256G
AIX 6100-08(AL770_048)
APPB(应用服务器B)
16(64 core)
256G
AIX 6100-08(AL770_048)
APPC(应用服务器C)
16(64 core)
256G
AIX 6100-08(AL770_048)
本次测试使用3台Load Runner客户机100并发压测,启动3台应用服务器(APPA,APPB,APPC),每台服务器启动1个JVM进程,2台数据库服务器搭建Oracle RAC环境,只仅启动单节点。
数据流向如下:
3台LR客户机(100并发)
-> Tuxedo(100通道,消除Tuxedo排队因素)
-> Java应用(3台机器,每台个1个)
-> 数据库服务器(单节点)
2. 第一步:数据定位
现象:
在Load Runner对单交易做不同并发压力测试(目的:验证单交易并发情况下响应时间是否正常)时,发现单JVM并发越高时,响应时间越来越高,上升趋势非常明显,个别交易还出现CPU也很高的现象。
例如其中一个交易的TPS结果。
并发数(3台机器3个JVM)
TPS
响应时间(ms)
CPU(%)
20
430
25
14.4
40
651
32
25
100
146
349
72
从LR压测结果分析,100并发时响应时间很长,TPS却比40并发时还低,对本交易基本可排除数据库的因素,猜测Java应用存在锁竞争的现象。
3. 第二步:tprof分析
通过tprof命令分析java进程cpu瓶颈。
# 用root用户登录,采集60秒的数据
tprof -s -k -x sleep 60
采集的数据如下:
Process Freq Total Kernel User Shared Other
======= ==== ===== ====== ==== ====== =====
/usr/java5/jre/bin/java 177 52.77 5.69 0.00 44.83 2.24
可以看出java进程cpu主要消耗在“User Shared”(即jvm相关动态链接库)上面,继续分析究竟是哪些动态库消耗较多呢?
Shared Object %
============= ======
/lib/libpthread.a[shr_xpg5_64.o] 28.37
/usr/java6_64/jre/lib/ppc64/default/libj9jit24.so 10.33
/usr/java6_64/jre/lib/ppc64/default/libj9thr24.so 4.82
/usr/java6_64/jre/lib/ppc64/default/libj9gc24.so 0.66
/usr/java6_64/jre/lib/ppc64/default/libj9vm24.so 0.48
从此处可以确定pthread线程库占用时间很大,猜测问题与高并发使用多线程API引起的。
继续分析libpthread.a库中方法的cpu消耗情况。
Profile: /lib/libpthread.a[shr_xpg5_64.o]
Total % For All Processes (/lib/libpthread.a[shr_xpg5_64.o]) = 28.37
Subroutine % Source
========== ====== ======
.pthread_mutex_trylock 25.11 pthreads/pth_mutex.c
._global_trylock 1.79 reads/pth_spinlock.c
.global_unlock_ppc_mp 0.82 pth_locks_ppc_mp.s
._global_lock_common 0.32 reads/pth_spinlock.c
._local_trylock 0.12 reads/pth_spinlock.c
大量调用“pthread_mutex_trylock”(试图获取互斥锁),基本上可以确定交易在并发高的情况下同步阻塞的情况很严重,下面再通过jvisualvm进一步验证下是不是存在大量阻塞的情况。
4. 第三步:jvisualvm分析
jvisualvm监控线程运行情况,分析是否有锁的存在?
通过截取LR压测时间段内的线程时序图,可看出线程处于“监视”的时间很长,现在基本可断定问题应该在于Java代码中大量线程存在资源竞争,可能是阻塞等待持有同一个锁或同步块等竞争资源。那究竟是什么代码引起的问题呢,进一步分析不同时点的javacore文件对比可得出结果。
5. 第四步:javacore分析
通过jvisualvm工具“线程dump”功能可以产生javacore文件,或者在服务端通过“kill -3 pid”也可以生成javacore文件。
分析javacore文件,查看锁的情况。
NULL ------------------------------------------------------------------------
0SECTION LOCKS subcomponent dump routine
NULL ===============================
NULL
1LKPOOLINFO Monitor pool info:
2LKPOOLTOTAL Current total number of monitors: 1150
NULL
1LKMONPOOLDUMP Monitor Pool Dump (flat & inflated object-monitors):
2LKMONINUSE sys_mon_t:0x00000100178A8618 infl_mon_t: 0x00000100178A8658:
3LKMONOBJECT sun/misc/GC$LatencyLock@0x07000000060065A0/0x07000000060065B8:
3LKNOTIFYQ Waiting to be notified:
3LKWAITNOTIFY "GC Daemon" (0x00000100196E7900)
2LKMONINUSE sys_mon_t:0x00000100171969A8 infl_mon_t: 0x00000100171969E8:
3LKMONOBJECT java/lang/ref/ReferenceQueue@0x07000000043C99B8/0x07000000043C99D0:
3LKNOTIFYQ Waiting to be notified:
3LKWAITNOTIFY "RMI RenewClean-[192.168.101.49:65116]" (0x0000010019821000)
2LKMONINUSE sys_mon_t:0x0000010019273AD8 infl_mon_t: 0x0000010019273B18:
3LKMONOBJECT java/lang/ref/ReferenceQueue@0x07000000001C89F0/0x07000000001C8A08:
3LKNOTIFYQ Waiting to be notified:
3LKWAITNOTIFY "RMI Reaper" (0x00000100196D8100)
2LKMONINUSE sys_mon_t:0x0000010019273FA0 infl_mon_t: 0x0000010019273FE0:
3LKMONOBJECT [I@0x07000000043C9A40/0x07000000043C9A58:
3LKNOTIFYQ Waiting to be notified:
3LKWAITNOTIFY "JMX server connection timeout 95" (0x0000010019BE7D00)
2LKMONINUSE sys_mon_t:0x0000010019274798 infl_mon_t: 0x00000100192747D8:
3LKMONOBJECT com/sun/jmx/remote/internal/ArrayNotificationBuffer@0x0700000006037000/0x0700000006037018:
3LKNOTIFYQ Waiting to be notified:
3LKWAITNOTIFY "RMI TCP Connection(4)-192.168.101.49" (0x0000010015F56700)
2LKMONINUSE sys_mon_t:0x000001001CDC9750 infl_mon_t: 0x000001001CDC9790:
3LKMONOBJECT java/util/Collections$SynchronizedMap@0x07000000001C8F58/0x07000000001C8F70: owner "Pool-2-(BizServer)-thread-105" (0x000001001EA36200), entry count 1
3LKWAITERQ Waiting to enter:
3LKWAITER "Pool-2-(BizServer)-thread-25" (0x000001001D3A2700)
3LKWAITER "Pool-2-(BizServer)-thread-27" (0x000001001B61E900)
3LKWAITER "Pool-2-(BizServer)-thread-28" (0x00000100198AF300)
3LKWAITER "Pool-2-(BizServer)-thread-29" (0x0000010019767700)
3LKWAITER "Pool-2-(BizServer)-thread-30" (0x000001001A652300)
3LKWAITER "Pool-2-(BizServer)-thread-31" (0x000001001A589B00)
3LKWAITER "Pool-2-(BizServer)-thread-108" (0x000001001C37E900)
3LKWAITER "Pool-2-(BizServer)-thread-109" (0x000001001D7E5000)
3LKWAITER "Pool-2-(BizServer)-thread-110" (0x0000010015F41E00)
3LKWAITER "Pool-2-(BizServer)-thread-111" (0x000001001A4CC600)
3LKWAITER "Pool-2-(BizServer)-thread-113" (0x000001001B9E4E00)
3LKWAITER "Pool-2-(BizServer)-thread-114" (0x000001001BB98500)
3LKWAITER "Pool-2-(BizServer)-thread-116" (0x000001001EA0D300)
3LKWAITER "Pool-2-(BizServer)-thread-118" (0x000001001D692600)
3LKWAITER "Pool-2-(BizServer)-thread-119" (0x000001001C25B300)
3LKWAITER "Pool-2-(BizServer)-thread-120" (0x000001001D352E00)
3LKWAITER "Pool-2-(BizServer)-thread-121" (0x000001001C7E2A00)
3LKWAITER "Pool-2-(BizServer)-thread-122" (0x000001001C75A800)
3LKWAITER "Pool-2-(BizServer)-thread-123" (0x000001001A6D9F00)
3LKWAITER "Pool-2-(BizServer)-thread-127" (0x000001001CE55F00)
3LKWAITER "Pool-2-(BizServer)-thread-128" (0x000001001CEA8400)
3LKWAITER "Pool-2-(BizServer)-thread-130" (0x000001001C3D5600)
3LKWAITER "Pool-2-(BizServer)-thread-131" (0x000001001D78A500)
2LKMONINUSE sys_mon_t:0x000001001D3584E0 infl_mon_t: 0x000001001D358520:
3LKMONOBJECT java/util/Hashtable@0x0700000000C44020/0x0700000000C44038: owner "Pool-2-(BizServer)-thread-124" (0x00000100195A4200), entry count 1
2LKMONINUSE sys_mon_t:0x000001001B51D1C0 infl_mon_t: 0x000001001B51D200:
3LKMONOBJECT java/lang/ClassLoader$CacheTable@0x0700000006C03AF8/0x0700000006C03B10: Flat locked by "Pool-2-(BizServer)-thread-103" (0x000001001EA2A800), entry count 1
2LKMONINUSE sys_mon_t:0x000001001C72F740 infl_mon_t: 0x000001001C72F780:
3LKMONOBJECT [I@0x07000000085B0428/0x07000000085B0440:
3LKNOTIFYQ Waiting to be notified:
3LKWAITNOTIFY "JMX server connection timeout 294" (0x000001001C75D900)
NULL
该时点有23个线程“Pool-2-(BizServer)-thread-xxx”阻塞等待线程“Pool-2-(BizServer)-thread-105”释放锁,继续分析线程“Pool-2-(BizServer)-thread -105”当前调用堆栈。
3XMTHREADINFO "Pool-2-(BizServer)-thread-105" J9VMThread:0x000001001EA36200, j9thread_t:0x000001001AFF2BC0,
java/lang/Thread:0x07000000003C4F18, state:CW, prio=5
3XMJAVALTHREAD (java/lang/Thread getId:0x10A, isDaemon:false)
3XMTHREADINFO1 (native thread ID:0x1EF0215, native priority:0x5, native policy:UNKNOWN)
3XMTHREADINFO3 Java callstack:
4XESTACKTRACE at java/util/Collections$SynchronizedMap.containsKey(Collections.java:726(Compiled Code))
4XESTACKTRACE at java/lang/reflect/Proxy.isProxyClass(Proxy.java:752(Compiled Code))
4XESTACKTRACE at cn/xxx/util/PropertyUtil.createAccessor(PropertyUtil.java:141(Compiled Code))
在PropertyUtil.createAccessor方法里头调用Proxy.isProxyClass方法,该方法最终调用SynchronizedMap. containsKey()方法,分析SynchronizedMap的代码可以看出该类中大量方法都使用“synchronized”语义。
public boolean containsKey(Object key) {
synchronized(mutex){return m.containsKey(key);}
}
到了这里,可以确定在高并发情况下Proxy.isProxyClass方法方法会大量阻塞在“synchronized”同步块上,那解决办法也就是在这方面上做文章,对目前的应用来说此处可以不调用该方法,去除它。
6. 总结
6.1 单交易不同并发测试的案例,可以用于验证高并发时是否有Java锁的存在。
LoadRunner压测时,建议挑选大部分交易进行该类案例的测试。
6.2 压测结果分析过程中,多种方式有时可以得出一样的结论,相互验证结论更可靠。
如:本次分析过程中,通过tprof+jvisualvm+javacore多种方式的分析最终都指向同样的结果。
6.3 再小的同步块“synchronized”都有可能是问题所在,所以慎重对待它。
对交易系统而言,最好能增加“synchronized”关键字使用的代码评审。
另外,不要过于相信第三方jar包的可靠性,使用方式不对或使用场景的变化都有可能导致第三方jar包呈现出不同的效率问题。
aix kill java_AIX环境Java进程cpu瓶颈分析(转)相关推荐
- Java进程CPU使用率高排查
1.使用top 定位到占用CPU高的进程PID top 通过ps aux | grep PID命令 2.获取线程信息,并找到占用CPU高的线程 ps -mp pid -o THREAD,tid,tim ...
- java进程CPU占用高如何排查-案例二
近期项目新版本上线遇到cpu冲高现象,依据之前的经验,把这次排查过程记录下. 这次排查参考了之前记录的经验,还是很有用的:java进程cpu占用高如何排查_停5s的博客-CSDN博客_java进程cp ...
- java进程cpu占用高如何排查
问题: 公司参加HW期间,项目两台双活的jboss服务器频繁触发cpu利用率过高告警,cpu利用率长时间在90%以上. 排查思路: 第一步:在两台Linux服务器上,执行top命令,并按大写P以cpu ...
- linux查看java进程cpu占用过高
linux下查找java进程占用CPU过高原因 1. 查找进程 top查看进程占用资源情况 明显看出java的两个进程22714,12406占用过高cpu. 2.查找线程 使用top -H -p ...
- Linux下如何定位Java进程CPU利用率过高原因
首先通过Top命令查看占用CPU较高的进程PID,执行Top之后按1可以查看每个核占用比例 1 top 这里由于我是用的虚拟机,即使我的Java进程占用CPU很高也只是占的虚拟机的,而对整个机器的CP ...
- java 进程 cpu占用_JAVA进程CPU占用高的故障排查 – 运维那些事
问题分析: 1.程序属于CPU密集型,和开发沟通过,排除此类情况. 2.程序代码有问题,出现死循环,可能性极大. 解决过程: 1.根据top命令,发现PID为2633的Java进程占用CPU高达300 ...
- Linux java进程CPU占用过高解决方案
总目录 一.前言: 二.模拟java程序CPU过高 1 修改代码为死循环 2 部署在linux上 访问该接口 根据top命令查看CPU参数 3 通过ps命令查看这个程序的线程信息,tid代码线程ID, ...
- Java进程CPU占用高导致的网页请求超时的故障排查
作者:荣书 来源:https://blog.51cto.com/rongshu/2426712 一.发现问题的系统检查: 一个管理平台门户网页进统计页面提示请求超时,随进服务器操作系统检查load a ...
- java进程cpu使用率高_什么会导致Java应用程序的CPU使用率飙升?
问题 无限循环的while会导致CPU使用率飙升吗? 经常使用Young GC会导致CPU占用率飙升吗? 具有大量线程的应用程序的CPU使用率是否较高? CPU使用率高的应用程序的线程数是多少? 处于 ...
最新文章
- sougou ubuntu 优麒麟_优麒麟(Ubuntu Kylin)17.04 正式版及银河麒麟社区版发布
- java线程在什么时候结束,java – 什么时候线程超出范围?
- Hadoop入门(二)集群安装
- 【前端面试题】2021/3/12挺经典的面试题,这个经历很深刻。
- redis集群linux安装教程,linux下redis集群的原生安装方式部署
- SpringBoot搭建天气预报微服务系统
- java 中文件outputstream的操作注意
- 搭建持续集成接口测试平台(Jenkins+Ant+Jmeter)
- AutoCAD2012从入门到精通中文视频教程 第13课 正多边形(个人收藏)
- 解决:启动word等office相关软件时,比较慢,会卡在一步Foxit PDF Creator COM Add-in很久
- 软件工程-基本流程图
- 【Vivado那些事】OOC综合方式
- 项目管理中的项目干系人
- 文档流及其特性 块级元素与行内元素的区别 浮动的清除方法(解决浮动塌陷)
- mp4文档ISO/IEC 14496 part 12解读
- 如何将caj转换成word
- Unity3D摄像机(Camera)跟随角色移动的代码控制和演示动画
- 物联网渐行渐近 你准备好了吗?
- 春暖花开--2013年度总结
- 荣耀7.0系统机器最简单激活Xposed框架的步骤
热门文章
- [亲测可行]Ubuntu16.04+opencv3.4+opencv_contrib+cuda9.0安装
- linux安装nginx详细步骤和make编译报错问题(保姆级)
- Jetpack新成员,一篇文章带你玩转Hilt和依赖注入
- Python中‘r‘,‘r+‘,‘w‘,‘w+‘,‘a‘,‘a+‘区别总结
- 【Android】在res中的图片下载导入到手机相册中的实现
- 苹果电子邮件怎么注册_外贸技巧 | 6种简单的电子邮件营销技巧,你知道几个?...
- oracle实例的内存(SGA和PGA)的调整和优化(转载)
- 005 |《共同富裕背景下党支部领办新型农村集体经济发展路径研究—以X村合作社为例》 | 大学生创新训练项目申请书 | 极致技术工厂
- 亚马逊A9算法是什么?有什么作用?(案例详解)
- 变频器必须设置的5大参数