载入中。。。 'S bLog
 
载入中。。。
 
载入中。。。
载入中。。。
载入中。。。
载入中。。。
载入中。。。
 
填写您的邮件地址,订阅我们的精彩内容:


 
HPROF: hadoop的一个分析工具,其实是Java自带的。
[ 2011/8/12 15:44:00 | By: 梦翔儿 ]
 

HPROF: 一个Heap/CPU Profiling工具

Sun JDK自带JVM内存使用分析工具HProf       使用Sun JDK自带JVM内存使用分析工具HProf可以分析JVM堆栈,从而找到占用内存较大的对象。这对应经常出现内存泄漏(OOM)的JAVA系统进行调优很有帮助。

HProf使用方法

·         在WeblogicServer启动脚本中增加-Xrunhprof:heap=sites,重新启动WeblogicServer。

·         使用kill -3 <pid> 或退出WeblogicServer均会生成java.hprof.txt文件,直接打开此文件便可分析JVM的具体运行情况。

从java.hprof.txt记录的JVM堆栈结果中可以发现JVM占用内存较大的对象:

          percent         live       alloc'ed stack class

rank   self accum    bytes objs   bytes objs trace name

    1 4.57% 4.57% 2289696 47702 8392224 174838 4251 [C

    2 3.99% 8.57% 2000016    1 2000016    1 12308 [C

    3 3.65% 12.22% 1827552 9622 1852672 10082 43265 [C

    4 2.58% 14.80% 1293912 53913 3929424 163726 4258 java.lang.String

    5 2.05% 16.85% 1028664 7585 3207272 24923 4252 [C

    6 2.03% 18.88% 1015816 159 1015816 159 18694 [B

    7 1.88% 20.77%   942080 230 2740224 669 20416 [B

    8 1.61% 22.37%   805752 2142 2150856 4635 45318 [B

    9 1.60% 23.98%   802880 772 802880 772 24710 weblogic.servlet.utils.URLMatchMap$URLMatchNode

   10 1.60% 25.57%   799400 19985 2781400 69535 45073 cnc.util.Field

   11 1.36% 26.93%   679360 3805 679360 3805   494 [B

   12 1.35% 28.28%   674856 28119 5181240 215885 2985 java.util.HashMap$Entry

……

……

   96 0.19% 63.73%    94776 3112   94776 3112 9146 [C

   97 0.19% 63.92%    93456 3894 123936 5164 23631 java.lang.String

   98 0.19% 64.10%    93224 3884 123968 5165 23644 java.lang.String

   99 0.19% 64.29%    93192 3883 123936 5164 23636 java.lang.String

100 0.18% 64.47%    89528 238 240264 520 33227 [B

101 0.17% 64.64%    86448 1901 103472 2255 18715 java.lang.Object

102 0.17% 64.81%    85464 676   85768 695 18715 [S

103 0.17% 64.98%    85184 1331   85184 1331 28266 weblogic.ejb20.internal.MethodDescriptor

104 0.17% 65.15%    84224 752   84224 752 24148 weblogic.servlet.internal.dd.ServletDescriptor

105 0.17% 65.32%    84136 528 50471136 348769    63 [C

106 0.16% 65.48%    79968 1428 388976 6946 5503 java.lang.reflect.Method

107 0.15% 65.63%    77520 1615   77520 1615 27967 weblogic.ejb20.deployer.mbimpl.MethodInfoImpl

108 0.15% 65.79%    77056 4816 469808 29363 20250 java.lang.Object

109 0.15% 65.94%    76960   74   76960   74 23695 [B

110 0.15% 66.09%    76104 3171 215040 8960 45071 cnc.util.FyCol

111 0.15% 66.24%    74688 3112   74688 3112 9152 java.util.Hashtable$Entry

112 0.15% 66.39%    74688 3112   74688 3112 9147 java.lang.String

113 0.15% 66.54%    74280   61 794328 788 45313 [C

114 0.14% 66.68%    72480 1510 436032 9084 45353 [C

115 0.14% 66.82%    70720   68   70720   68 25869 [B

116 0.14% 66.97%    70720   68   70720   68 27448 [B

117 0.14% 67.11%    70272 1279 142672 2439 5503 [C

118 0.14% 67.24%    69256   86   69256   86 6584 [S

119 0.13% 67.38%    67056   66   67056   66 28882 java.lang.Object

120 0.13% 67.51%    66176 752   66176 752 24170 weblogic.servlet.internal.dd.UIDescriptor

121 0.13% 67.64%    65688 715   65688 715 25389 [C

122 0.13% 67.77%    65600    4 885600   54 23939 [C

123 0.13% 67.90%    65600    4 623200   38 40639 [C

124 0.13% 68.03%    65576 367   65576 367 51686 [C

125 0.13% 68.17%    65568    2   65568    2 30610 java.util.HashMap$Entry

126 0.13% 68.30%    65568    2 130816   16 43271 java.util.HashMap$Entry

127 0.13% 68.43%    65552    1   65552    1 16617 [B

128 0.13% 68.56%    64600 1615   64600 1615 27969 java.util.HashMap

129 0.13% 68.68%    63888 2662   64032 2668 16951 java.util.HashMap$Entry

130 0.13% 68.81%    63888 2662   64032 2668 16997 java.util.HashMap$Entry

131 0.13% 68.94%    63888 2662   64032 2668 16996 weblogic.rmi.internal.ClientMethodDescriptor

132 0.13% 69.07%    63888 2662   99120 4130 16949 java.lang.String

133 0.13% 69.19%    63888 2662   64032 2668 16976 java.lang.String

134 0.13% 69.32%    63232 152   63232 152 9655 weblogic.utils.collections.ConcurrentHashMap$Entry

135 0.13% 69.45%    63232 152   63232 152 9704 weblogic.utils.collections.ConcurrentHashMap$Entry

136 0.12% 69.57%    62168 3885   82632 5164 23628 [B

137 0.12% 69.69%    61680 406   66904 468     1 [C

138 0.12% 69.82%    61504    4 246016   16 47372 [B

139 0.12% 69.94%    61144   36 91019160 23904    92 [B

140 0.12% 70.06%    61040 763   61040 763 24194 weblogic.servlet.internal.dd.ServletMappingDescriptor

141 0.12% 70.18%    60400 1510 363360 9084 45338 java.util.Hashtable

142 0.12% 70.30%    59544 827   59544 827 24746 weblogic.servlet.internal.ServletRuntimeMBeanImpl

143 0.12% 70.42%    59248 1058 484984 8664 33236 oracle.jdbc.ttc7.TTCItem

144 0.12% 70.53%    58152 232 187176 764   748 [C

145 0.12% 70.65%    57888 2412 161904 6746 16621 java.lang.String

146 0.11% 70.77%    57400 1435   57400 1435 16855 java.util.HashMap

……

……


根据以上的结果,在java.hprof.txt中定位到导致分配大内存的操作如下:

TRACE 63:

       java.lang.StringBuffer.expandCapacity(StringBuffer.java:202)

       java.lang.StringBuffer.append(StringBuffer.java:401)

       java.util.zip.ZipFile.getEntry(ZipFile.java:148)

       java.util.jar.JarFile.getEntry(JarFile.java:198)

TRACE 92:

       java.util.zip.InflaterInputStream.<init>(InflaterInputStream.java:71)

       java.util.zip.ZipFile$1.<init>(ZipFile.java:240)

       java.util.zip.ZipFile.getInputStream(ZipFile.java:212)

       java.util.zip.ZipFile.getInputStream(ZipFile.java:183)

再进一步分析则需要应用开发人员对应用代码做相应的分析定位。

注意:使用HProf非常消耗资源,切记不要在生产系统使用。

http://www.51testing.com/?uid-3354-action-viewspace-itemid-116628

J2SE中提供了一个简单的命令行工具来对java程序的cpu和heap进行 profiling,叫做HPROF。HPROF实际上是JVM中的一个native的库,它会在JVM启动的时候通过命令行参数来动态加载,并成为 JVM进程的一部分。若要在java进程启动的时候使用HPROF,用户可以通过各种命令行参数类型来使用HPROF对java进程的heap或者(和)cpu进行profiling的功能。HPROF产生的profiling数据可以是二进制的,也可以是文本格式的。这些日志可以用来跟踪和分析 java进程的性能问题和瓶颈,解决内存使用上不优的地方或者程序实现上的不优之处。二进制格式的日志还可以被JVM中的HAT工具来进行浏览和分析,用以观察java进程的heap中各种类型和数据的情况。

在J2SE 5.0以后的版本中,HPROF已经被并入到一个叫做Java Virtual Machine Tool Interface(JVM TI)中。


HPROF的启用



HPROF可以用来展示和跟踪cpu的使用情况,内存分配的统计数据等。不仅如此,它还支持对 java进程完整的内存dump,所有线程的monitor stats数据。HPROF被启用的方式可以如下:
java -agentlib:hprof[=options] ToBeProfiledClass
或者
java -Xrunhprof[:options] ToBeProfiledClass
HPROF如何构建java进程,并发送进程的jvm profiling信息,取决于HPROF在JVM启动时从命令行获取的参数指令。比如,以下指令将会获取java进程的heap allocation的profile:
java -agentlib:hprof=heap=sites ToBeProfiledClass

HPROF 可以被指定的参数非常的多,以下是完整的列表:

java -agentlib:hprof=help


        HPROF: Heap and CPU Profiling Agent (JVM TI Demonstration Code)

    hprof usage: java -agentlib:hprof=[help]|[<option>=<value>, ...]

    Option Name and Value  Description                    Default
    ---------------------  -----------                    -------
    heap=dump|sites|all    heap profiling                 all
    cpu=samples|times|old  CPU usage                      off
    monitor=y|n            monitor contention             n
    format=a|b             text(txt) or binary output     a
    file=<file>            write data to file             java.hprof[.txt]
    net=<host>:<port>      send data over a socket        off
    depth=<size>           stack trace depth              4
    interval=<ms>          sample interval in ms          10
    cutoff=<value>         output cutoff point            0.0001
    lineno=y|n             line number in traces?         y
    thread=y|n             thread in traces?              n
    doe=y|n                dump on exit?                  y
    msa=y|n                Solaris micro state accounting n
    force=y|n              force output to <file>         y
    verbose=y|n            print messages about dumps     y

    Obsolete Options
    ----------------
    gc_okay=y|n

    Examples
    --------
     - Get sample cpu information every 20 millisec, with a stack depth of 3:
         java -agentlib:hprof=cpu=samples,interval=20,depth=3 classname
     - Get heap usage information based on the allocation sites:
         java -agentlib:hprof=heap=sites classname

默认情况下,java进程profiling的信息(sites和dump)都会被写入到一个叫做java.hprof.txt的文件中。大多数情况下,该文件中都会对每个trace,threads,objects包含一个ID,每一个ID代表一个不同的观察对象。通常,traces会从300000开始。

默认,force=y,会将所有的信息全部输出到output文件中,所以如果含有多个JVMs都采用的HRPOF enable的方式运行,最好将force=n,这样能够将单独的JVM的profiling信息输出到不同的指定文件。

interval选项只在 cpu=samples的情况下生效,表示每隔多少毫秒对java进程的cpu使用情况进行一次采集。

msa选项仅仅在Solaris系统下才有效,表示会使用Solaris下的Micro State Accounting功能

Examples



我们可以自己写一个java应用程序,但是例子里将使用一个J2SE中已有的java应用程序,javac。

Heap Allocation Profiles(heap=sites)



以下是对一个java代码文件运行java编译器javac的heap allocation profile日志的一部分:
Command used: javac -J-agentlib:hprof=heap=sites Hello.java
从日志中可以看到程序在运行的每一个部分都消耗了多少内存的heap profile数据。以上日志可以看出,整个程序的heap中有44.73%的被分配给了java.util.zip.ZipEntry对象。同时可以观察到,live data的数量跟所有allocated的总数是匹配atch的,这就说明GC可能在HPROF遍历整个heap搜集信息的很短的时间之前已经做过一次内存回收了。通常情况下,live data的数量是会稍微少于所有allocated的总数的。
   
Heap Dump (heap=dump)



该选项用来对java进程的heap进行进行完全的dump:
Command used: javac -J-agentlib:hprof=heap=dump Hello.java
这样会产生一个非常大的输出文件,但是可以用任何编辑器进行打开和搜索。但是,更好的观察和分析办法是通过HAT来进行分析和观察。所有用heap=sites选项中获取的信息这里也都可以获取到。另外还加上一些特别的细节数据。如对每个对象的内存分配以及其引用的其他所有的对象。
该选项会使用很多的内存,因为它会将所有对象的内存分配情况全部记录下来,同时也可能会影响到应用程序本身的性能,因为数据的产生会影响对象分配和资源回收。

CPU Usage Sampling Profiles (cpu=samples)



HPROF可以用来搜集java进程中各个threads的cpu使用情况:
HPROF会对java进程中所有的threads进行周期性的stack traces采集。以上count一列就表示在采集中有多少次的stack trace被HPROF发现,并且是active的(而不是指一个method被执行了多少次)。这些stack traces包括cpu的使用,哪些是cpu消耗热点。
那么以上日志中可以看出什么信息呢?第一,统计数据的样本数据是很少的,只有126次的采样,如果是比较大的程序编译,那么应该能够产生更有代表性的数据。第二,该数据跟以上对heap=sites的采集数据比较匹配,ZipFile耗费了比较多的 cpu时间和调用次数。在以上采集中,可以发现,跟ZipFile相关的的性能在javac中都会消耗的比较高,该ZipFile的stack trace如下:

CPU Usage Times Profile (cpu=times)



HPROF可以通过对java应用程序的各个方法中注入code的方式来搜集各个method的执行情况。对每个methods的执行情况进行跟踪,count以及时间消耗的搜集。这种技术叫做 Byte Code Injection。所以这种采集方式的运行比cpu=samples要慢很多,以下是采集数据日志:
这里的count代表着该方法被真正执行了多少次,并且方法thread消耗了多少精确的cpu 时间。

http://blog.csdn.net/ae86_fc/article/details/5960719

值得一提的是这哥们的博客写得不错,对重构hadoop有很牛的经验:http://blog.csdn.net/AE86_FC

 
 
  • 标签:HPROF 分析工具 java hadoop 
  • 发表评论:
    载入中。。。

     
     
     

    梦翔儿网站 梦飞翔的地方 http://www.dreamflier.net
    中华人民共和国信息产业部TCP/IP系统 备案序号:辽ICP备09000550号

    Powered by Oblog.