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瓶颈分析(转)相关推荐

  1. Java进程CPU使用率高排查

    1.使用top 定位到占用CPU高的进程PID top 通过ps aux | grep PID命令 2.获取线程信息,并找到占用CPU高的线程 ps -mp pid -o THREAD,tid,tim ...

  2. java进程CPU占用高如何排查-案例二

    近期项目新版本上线遇到cpu冲高现象,依据之前的经验,把这次排查过程记录下. 这次排查参考了之前记录的经验,还是很有用的:java进程cpu占用高如何排查_停5s的博客-CSDN博客_java进程cp ...

  3. java进程cpu占用高如何排查

    问题: 公司参加HW期间,项目两台双活的jboss服务器频繁触发cpu利用率过高告警,cpu利用率长时间在90%以上. 排查思路: 第一步:在两台Linux服务器上,执行top命令,并按大写P以cpu ...

  4. linux查看java进程cpu占用过高

    linux下查找java进程占用CPU过高原因 1. 查找进程 top查看进程占用资源情况 明显看出java的两个进程22714,12406占用过高cpu.   2.查找线程 使用top -H -p ...

  5. Linux下如何定位Java进程CPU利用率过高原因

    首先通过Top命令查看占用CPU较高的进程PID,执行Top之后按1可以查看每个核占用比例 1 top 这里由于我是用的虚拟机,即使我的Java进程占用CPU很高也只是占的虚拟机的,而对整个机器的CP ...

  6. java 进程 cpu占用_JAVA进程CPU占用高的故障排查 – 运维那些事

    问题分析: 1.程序属于CPU密集型,和开发沟通过,排除此类情况. 2.程序代码有问题,出现死循环,可能性极大. 解决过程: 1.根据top命令,发现PID为2633的Java进程占用CPU高达300 ...

  7. Linux java进程CPU占用过高解决方案

    总目录 一.前言: 二.模拟java程序CPU过高 1 修改代码为死循环 2 部署在linux上 访问该接口 根据top命令查看CPU参数 3 通过ps命令查看这个程序的线程信息,tid代码线程ID, ...

  8. Java进程CPU占用高导致的网页请求超时的故障排查

    作者:荣书 来源:https://blog.51cto.com/rongshu/2426712 一.发现问题的系统检查: 一个管理平台门户网页进统计页面提示请求超时,随进服务器操作系统检查load a ...

  9. java进程cpu使用率高_什么会导致Java应用程序的CPU使用率飙升?

    问题 无限循环的while会导致CPU使用率飙升吗? 经常使用Young GC会导致CPU占用率飙升吗? 具有大量线程的应用程序的CPU使用率是否较高? CPU使用率高的应用程序的线程数是多少? 处于 ...

最新文章

  1. sougou ubuntu 优麒麟_优麒麟(Ubuntu Kylin)17.04 正式版及银河麒麟社区版发布
  2. java线程在什么时候结束,java – 什么时候线程超出范围?
  3. Hadoop入门(二)集群安装
  4. 【前端面试题】2021/3/12挺经典的面试题,这个经历很深刻。
  5. redis集群linux安装教程,linux下redis集群的原生安装方式部署
  6. SpringBoot搭建天气预报微服务系统
  7. java 中文件outputstream的操作注意
  8. 搭建持续集成接口测试平台(Jenkins+Ant+Jmeter)
  9. AutoCAD2012从入门到精通中文视频教程 第13课 正多边形(个人收藏)
  10. 解决:启动word等office相关软件时,比较慢,会卡在一步Foxit PDF Creator COM Add-in很久
  11. 软件工程-基本流程图
  12. 【Vivado那些事】OOC综合方式
  13. 项目管理中的项目干系人
  14. 文档流及其特性 块级元素与行内元素的区别 浮动的清除方法(解决浮动塌陷)
  15. mp4文档ISO/IEC 14496 part 12解读
  16. 如何将caj转换成word
  17. Unity3D摄像机(Camera)跟随角色移动的代码控制和演示动画
  18. 物联网渐行渐近 你准备好了吗?
  19. 春暖花开--2013年度总结
  20. 荣耀7.0系统机器最简单激活Xposed框架的步骤

热门文章

  1. [亲测可行]Ubuntu16.04+opencv3.4+opencv_contrib+cuda9.0安装
  2. linux安装nginx详细步骤和make编译报错问题(保姆级)
  3. Jetpack新成员,一篇文章带你玩转Hilt和依赖注入
  4. Python中‘r‘,‘r+‘,‘w‘,‘w+‘,‘a‘,‘a+‘区别总结
  5. 【Android】在res中的图片下载导入到手机相册中的实现
  6. 苹果电子邮件怎么注册_外贸技巧 | 6种简单的电子邮件营销技巧,你知道几个?...
  7. oracle实例的内存(SGA和PGA)的调整和优化(转载)
  8. 005 |《共同富裕背景下党支部领办新型农村集体经济发展路径研究—以X村合作社为例》 | 大学生创新训练项目申请书 | 极致技术工厂
  9. 亚马逊A9算法是什么?有什么作用?(案例详解)
  10. 变频器必须设置的5大参数