大部分内容参考http://www.linuxidc.com/Linux/2012-04/58178.htm
J2SE中提供了一个简单的命令行工具来对java程序的cpu和heap进行 profiling,叫做HPROF。HPROF实际上是JVM中的一个native的库,它会在JVM启动的时候通过命令行参数来动态加载,并成为 JVM进程的一部分。
要使用hprof,可以通过在运行java程序时指定-agentlib或者-Xrunhprof参数来使用,它会将cpu、heap等想着信息保存到一份文件中(默认情况是当前目录的java.hprof.txt。 其实,HPROF产生的profiling数据可以是二进制的,也可以是文本格式的。这些日志可以用来跟踪和分析 java进程的性能问题和瓶颈,解决内存使用上不优的地方或者程序实现上的不优之处。二进制格式的日志还可以被JVM中的HAT工具来进行浏览和分析,用 以观察java进程的heap中各种类型和数据的情况。一、HPROF的参数 通过以下命令执行hporf java -agentlib:hprof[=options] ToBeProfiledClass 或者 java -Xrunhprof[:options] ToBeProfiledClass HPROF 完整参数列表: java -agentlib:hprof=help HPROF: Heap and CPU Profiling Agent (JVM TI Demonstration Code) hprof usage: java -agentlib:hprof=[help]|[=, ...] 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= write data to file java.hprof[.txt] net=: send data over a socket off depth= stack trace depth 4 interval= sample interval in ms 10 cutoff= 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 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功能二、hprof的使用方式 1、在eclipse中使用hporfile 2、命令行运行hprof 三、实际例子 注意,进行hprof分析时,会将整个JVM中的情况进行分析,不只是当前的类。 我们可以自己写一个java应用程序,但是例子 里将使用一个J2SE中已有的java应用程序,javac。 或者使用java -agentlib:hprof=heap=sites Hello.java命令 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 时间。 四、在Hadoop中使用hprof 在JobConf中,有几个配置选项是可以用来控制task profiling行为的。比如对一个job,想要开启对其tasks的profiling功能,并设置profiling相应的HPROF参数,可以按如下方式: conf.setProfileEnabled(true); conf.setProfileParams("-agentlib:hprof=cpu=samples,heap=sites,depth=6," + "force=n,thread=y,verbose=n,file=%s"); conf.setProfileTaskRange(true, "0-2"); 第一行表示打开profiling task的功能,该功能默认情况下是关闭的。调用该接口相当于设置配置选项 mapred.task.profile=true,可以利用这种方式在hadoop job提交命令行上动态指定。 第二行是通过conf接口来设置对tasks进行HPROF 的profiling的采集参数,采用profiling enable的方式运行的tasks,会采用每个task一个独立的JVM的运行方式运行(即使enable了job的jvm reuse功能)。HPROF相关的采集参数设置,可以见其他资料。该选项也可以通过设置 mapred.task.profile.params 选项来指定。 第三行表示对job的哪些tasks需要进行profiling采集,第一true参数表示采集的是map tasks的性能数据,false的话表示采集reduce的性能数据,第二个参数表示只采集编号为0,1,2的tasks的数据,(默认为0-2)。如果想要采集除2,3,5编号的tasks,可以设置该参数为: 0-1,4,6- Example 还是拿wordcount来举例,提交job命令如下: bin/hadoop jar hadoop-examples-0.20.2-luoli.jar wordcount / -D mapred.reduce.tasks=10 / -D keep.failed.task.files=fales / -D mapred.task.profile=true / -D mapred.task.profile.params="-agentlib:hprof=cpu=samples,heap=sites,depth=6,force=n,thread=y,verbose=n,file=%s" / $input / $output 这样,当job运行时,就会对前三个task进行profiling的采集,采集信息包括cpu的采样信息,内存分配的信息数据,stack trace 6层的堆栈信息。这里需要注意的是,由于前三个tasks被进行了HPROF的性能采样,所以这几个tasks的执行效率会受到一定的影响,profiling的信息越详细,性能影响就越大。如下图,前三个map就明显比其他的map运行的要慢很多。 不过这种运行方式通常都不是线上运行方式,而是用来进行优化调试,所以关系不大。 而当job运行完成后,这三个tasks对应的profiling日志也会会传到提交机器上,供用户分析判断。如下图: 与此同时,tasks在tasktracker上也将这些profiling日志信息记录到了一个profile.out的日志文件中,该文件通常位于tasktracker机器上的上${HADOOP_HOME}/logs/userlogs/${attempt_id}下,和该task的stderr,stdout,syslog保存在同一个目录下,如下图: 该文件中的内容,还可以通过taskdetails.jsp的页面查看到。如下图: 有了这些信息,相信对于任何一位hadoop应用程序的开发者来说,就拥有了足够的定位job瓶颈的信息了。MR的应用程序开发同学,请优化您的job吧~~ linux