jps
-- List all java processes and related information, like fully qualified main class names, arguments passed to main method, etc.[hadoop@m15018 ~]$ jps -ml 30134 org.apache.hadoop.hdfs.server.datanode.DataNode 15141 org.apache.hadoop.mapred.YarnChild 192.168.7.27 28170 attempt_1417419796124_63329_m_000018_1 97 1820 org.apache.hadoop.mapred.YarnChild 192.168.7.14 36058 attempt_1417419796124_63299_m_000037_0 33 28191 org.apache.hadoop.mapred.YarnChild 192.168.7.21 55163 attempt_1417419796124_63322_m_000018_0 21 15275 org.apache.hadoop.mapreduce.v2.app.MRAppMaster 18325 org.apache.hadoop.mapred.YarnChild 192.168.7.55 6926 attempt_1417419796124_63255_m_000014_1 166 10693 org.apache.hadoop.mapred.YarnChild 192.168.7.85 20883 attempt_1417419796124_63282_m_000055_0 34 6001 org.apache.hadoop.mapred.YarnChild 192.168.7.17 9187 attempt_1417419796124_62366_m_000050_0 64 30311 org.apache.hadoop.yarn.server.nodemanager.NodeManager 30111 org.apache.hadoop.mapred.YarnChild 192.168.7.75 23820 attempt_1417419796124_63324_m_000047_0 29 28712 org.apache.hadoop.mapreduce.v2.app.MRAppMaster 4474 org.apache.hadoop.mapred.YarnChild 192.168.7.29 49996 attempt_1417419796124_62449_r_000019_0 101 6041 org.apache.hadoop.mapred.YarnChild 192.168.7.17 9187 attempt_1417419796124_62366_r_000008_0 57 6792 org.apache.hadoop.mapred.YarnChild 192.168.7.20 56878 attempt_1417419796124_63313_m_000016_0 18 25847 org.apache.hadoop.mapred.YarnChild 192.168.7.46 8277 attempt_1417419796124_63290_m_000005_0 7 6089 org.apache.hadoop.mapred.YarnChild 192.168.7.17 9187 attempt_1417419796124_62366_r_000005_0 50 20277 org.apache.hadoop.mapred.YarnChild 192.168.7.26 45093 attempt_1417419796124_63268_m_000014_0 20 5578 org.apache.hadoop.mapred.YarnChild 192.168.7.72 15929 attempt_1417419796124_63271_m_000011_0 14 26194 org.apache.hadoop.mapred.YarnChild 192.168.7.46 8277 attempt_1417419796124_63290_m_000011_0 13 18747 sun.tools.jps.Jps -ml
In which:
-m Output the arguments passed to the main method. The output may be null for embedded JVMs. -l Output the full package name for the application’s main class or the full path name to the application’s JAR file. -v Output the arguments passed to the JVM.
jstack
-- Show current stack trace of a running java process.[hadoop@K1213 ~]$ jstack 19552 2014-12-31 10:21:05 Full thread dump Java HotSpot(TM) 64-Bit Server VM (23.6-b04 mixed mode): "Attach Listener" daemon prio=10 tid=0x000000000a3ae000 nid=0x81a waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "ResponseProcessor for block BP-714842383-192.168.7.11-1393991369860:blk_1111587326_1099569551548" daemon prio=10 tid=0x00002aaab8293000 nid=0x7098 runnable [0x00000000417e5000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) - locked <0x000000077742ab40> (a sun.nio.ch.Util$2) - locked <0x000000077742ab50> (a java.util.Collections$UnmodifiableSet) - locked <0x000000077742aaf8> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:335) at org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:157) at org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:161) at org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:131) at org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:118) at java.io.FilterInputStream.read(FilterInputStream.java:83) at java.io.FilterInputStream.read(FilterInputStream.java:83) at org.apache.hadoop.hdfs.protocolPB.PBHelper.vintPrefixed(PBHelper.java:1490) at org.apache.hadoop.hdfs.protocol.datatransfer.PipelineAck.readFields(PipelineAck.java:116) at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer$ResponseProcessor.run(DFSOutputStream.java:721) "DataStreamer for file /user/monitor/test_with_reduce_zhudi/_temporary/1/_temporary/attempt_1417419796124_63366_m_000033_0/0-m-00033 block BP-714842383-192.168.7.11-1393991369860:blk_1111587326_1099569551548" daemon prio=10 tid=0x00002aaab4cbb000 nid=0x4ca3 runnable [0x0000000040316000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) - locked <0x000000077742e4e8> (a sun.nio.ch.Util$2) - locked <0x000000077742e4f8> (a java.util.Collections$UnmodifiableSet) - locked <0x000000077742e4a0> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:335) at org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:157) at org.apache.hadoop.net.SocketOutputStream.write(SocketOutputStream.java:159) at org.apache.hadoop.net.SocketOutputStream.write(SocketOutputStream.java:117) at java.io.BufferedOutputStream.write(BufferedOutputStream.java:122) - locked <0x0000000747910230> (a java.io.BufferedOutputStream) at java.io.DataOutputStream.write(DataOutputStream.java:107) - locked <0x0000000747910248> (a java.io.DataOutputStream) at org.apache.hadoop.hdfs.DFSOutputStream$Packet.writeTo(DFSOutputStream.java:278) at org.apache.hadoop.hdfs.DFSOutputStream$DataStreamer.run(DFSOutputStream.java:568) ... "main" prio=10 tid=0x0000000009fad000 nid=0x4c61 in Object.wait() [0x000000004089e000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at org.apache.hadoop.hdfs.DFSOutputStream.waitAndQueueCurrentPacket(DFSOutputStream.java:1475) - locked <0x00000007770010a0> (a java.util.LinkedList) at org.apache.hadoop.hdfs.DFSOutputStream.writeChunk(DFSOutputStream.java:1543) - locked <0x00000007770abdc8> (a org.apache.hadoop.hdfs.DFSOutputStream) at org.apache.hadoop.fs.FSOutputSummer.writeChecksumChunk(FSOutputSummer.java:175) at org.apache.hadoop.fs.FSOutputSummer.flushBuffer(FSOutputSummer.java:150) - locked <0x00000007770abdc8> (a org.apache.hadoop.hdfs.DFSOutputStream) at org.apache.hadoop.fs.FSOutputSummer.flushBuffer(FSOutputSummer.java:139) - eliminated <0x00000007770abdc8> (a org.apache.hadoop.hdfs.DFSOutputStream) at org.apache.hadoop.fs.FSOutputSummer.write1(FSOutputSummer.java:130) at org.apache.hadoop.fs.FSOutputSummer.write(FSOutputSummer.java:104) - locked <0x00000007770abdc8> (a org.apache.hadoop.hdfs.DFSOutputStream) at org.apache.hadoop.fs.FSDataOutputStream$PositionCache.write(FSDataOutputStream.java:59) at java.io.DataOutputStream.write(DataOutputStream.java:107) - locked <0x0000000777294690> (a org.apache.hadoop.hdfs.client.HdfsDataOutputStream) at org.apache.hadoop.mapreduce.lib.output.TextOutputFormat$LineRecordWriter.writeObject(TextOutputFormat.java:83) at org.apache.hadoop.mapreduce.lib.output.TextOutputFormat$LineRecordWriter.write(TextOutputFormat.java:104) - locked <0x000000077722f338> (a org.apache.hadoop.mapreduce.lib.output.TextOutputFormat$LineRecordWriter) at org.apache.hadoop.mapreduce.lib.output.MultipleOutputs.write(MultipleOutputs.java:433) at org.apache.hadoop.mapreduce.lib.output.MultipleOutputs.write(MultipleOutputs.java:411) at AdMonitorDMReaderJob$Mapper.map(AdMonitorDMReaderJob.java:45) at AdMonitorDMReaderJob$Mapper.map(AdMonitorDMReaderJob.java:30) at org.apache.hadoop.mapreduce.Mapper.run(Mapper.java:145) at org.apache.hadoop.mapred.MapTask.runNewMapper(MapTask.java:772) at org.apache.hadoop.mapred.MapTask.run(MapTask.java:339) at org.apache.hadoop.mapred.YarnChild$2.run(YarnChild.java:162) at java.security.AccessController.doPrivileged(Native Method) at javax.security.auth.Subject.doAs(Subject.java:415) at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1491) at org.apache.hadoop.mapred.YarnChild.main(YarnChild.java:157) "VM Thread" prio=10 tid=0x000000000a02c000 nid=0x4c62 runnable "VM Periodic Task Thread" prio=10 tid=0x00002aaab401a800 nid=0x4c69 waiting on condition JNI global references: 276
jinfo
-- List all configuration info for current java process, including system properties and java-specified properties.[hadoop@K1213 ~]$ jinfo 19552 Attaching to process ID 19552, please wait... Debugger attached successfully. Server compiler detected. JVM version is 23.6-b04 Java System Properties: java.runtime.name = Java(TM) SE Runtime Environment java.vm.version = 23.6-b04 sun.boot.library.path = /usr/java/jdk1.7.0_11/jre/lib/amd64 hadoop.root.logger = INFO,CLA java.vendor.url = http://java.oracle.com/ java.vm.vendor = Oracle Corporation path.separator = : file.encoding.pkg = sun.io java.vm.name = Java HotSpot(TM) 64-Bit Server VM sun.os.patch.level = unknown sun.java.launcher = SUN_STANDARD user.country = CN user.dir = /home/data4/hdfsdir/nm-local-dir/usercache/monitor/appcache/application_1417419796124_63366/container_1417419796124_63366_01_000063 java.vm.specification.name = Java Virtual Machine Specification java.runtime.version = 1.7.0_11-b21 java.awt.graphicsenv = sun.awt.X11GraphicsEnvironment os.arch = amd64 java.endorsed.dirs = /usr/java/jdk1.7.0_11/jre/lib/endorsed line.separator = java.io.tmpdir = /home/data4/hdfsdir/nm-local-dir/usercache/monitor/appcache/application_1417419796124_63366/container_1417419796124_63366_01_000063/tmp yarn.app.container.log.dir = /home/workspace/hadoop/logs/userlogs/application_1417419796124_63366/container_1417419796124_63366_01_000063 java.vm.specification.vendor = Oracle Corporation os.name = Linux log4j.configuration = container-log4j.properties sun.jnu.encoding = UTF-8 java.library.path = /home/data4/hdfsdir/nm-local-dir/usercache/monitor/appcache/application_1417419796124_63366/container_1417419796124_63366_01_000063:/home/workspace/hadoop/lib/native:/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib java.specification.name = Java Platform API Specification java.class.version = 51.0 sun.management.compiler = HotSpot 64-Bit Tiered Compilers os.version = 2.6.18-308.el5 yarn.app.container.log.filesize = 209715200 user.home = /home/hadoop user.timezone = Asia/Shanghai java.awt.printerjob = sun.print.PSPrinterJob file.encoding = UTF-8 java.specification.version = 1.7 user.name = hadoop java.class.path = ... java.vm.specification.version = 1.7 sun.arch.data.model = 64 sun.java.command = org.apache.hadoop.mapred.YarnChild 192.168.7.86 14667 attempt_1417419796124_63366_m_000033_0 63 java.home = /usr/java/jdk1.7.0_11/jre user.language = zh java.specification.vendor = Oracle Corporation awt.toolkit = sun.awt.X11.XToolkit java.vm.info = mixed mode java.version = 1.7.0_11 java.ext.dirs = /usr/java/jdk1.7.0_11/jre/lib/ext:/usr/java/packages/lib/ext sun.boot.class.path = /usr/java/jdk1.7.0_11/jre/lib/resources.jar:/usr/java/jdk1.7.0_11/jre/lib/rt.jar:/usr/java/jdk1.7.0_11/jre/lib/sunrsasign.jar:/usr/java/jdk1.7.0_11/jre/lib/jsse.jar:/usr/java/jdk1.7.0_11/jre/lib/jce.jar:/usr/java/jdk1.7.0_11/jre/lib/charsets.jar:/usr/java/jdk1.7.0_11/jre/lib/jfr.jar:/usr/java/jdk1.7.0_11/jre/classes java.vendor = Oracle Corporation file.separator = / java.vendor.url.bug = http://bugreport.sun.com/bugreport/ sun.io.unicode.encoding = UnicodeLittle sun.cpu.endian = little sun.cpu.isalist = VM Flags: -XX:+UseSerialGC -Xms1024M -Xmx3096m -XX:PermSize=64m -XX:MaxPermSize=128M -Djava.io.tmpdir=/home/data4/hdfsdir/nm-local-dir/usercache/monitor/appcache/application_1417419796124_63366/container_1417419796124_63366_01_000063/tmp -Dlog4j.configuration=container-log4j.properties -Dyarn.app.container.log.dir=/home/workspace/hadoop/logs/userlogs/application_1417419796124_63366/container_1417419796124_63366_01_000063 -Dyarn.app.container.log.filesize=209715200 -Dhadoop.root.logger=INFO,CLA
strace
-- Show calls on function of underlying system (Linux). This is suitable for all processes in Linux.[hadoop@K1213 ~]$ strace -p 19552
Process 19552 attached - interrupt to quit
futex(0x408a09d0, FUTEX_WAIT, 19553, NULL <unfinished ...>
Process 19552 detached
[hadoop@K1213 ~]$ strace -p 19553
Process 19553 attached - interrupt to quit
futex(0x9fada54, FUTEX_WAIT_PRIVATE, 1747, NULL) = 0
futex(0x9fada28, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x9fada54, FUTEX_WAIT_PRIVATE, 1749, NULL) = 0
futex(0x9fada28, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x9fada54, FUTEX_WAIT_PRIVATE, 1751, NULL) = 0
futex(0x9fada28, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x9fada54, FUTEX_WAIT_PRIVATE, 1753, NULL) = 0
futex(0x9fada28, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x9fada54, FUTEX_WAIT_PRIVATE, 1755, NULL) = 0
futex(0x9fada28, FUTEX_WAKE_PRIVATE, 1) = 0
read(160, "\0\2\4\4\0\31", 6) = 6
read(160, "\t\0\0 \5\0\0\0\0\21\220\2\0\0\0\0\0\0\30\0%\0\0\2\0\243\255X\321\20\314g"..., 132121) = 68529
read(160, 0x2aaab4ca2457, 63592) = -1 EAGAIN (Resource temporarily unavailable)
epoll_ctl(175, EPOLL_CTL_ADD, 160, {EPOLLIN, {u32=160, u64=12336768231720091808}}) = 0
epoll_wait(175, {{EPOLLIN, {u32=160, u64=12336768231720091808}}}, 8192, 3600000) = 1
epoll_ctl(175, EPOLL_CTL_DEL, 160, {0, {u32=160, u64=719115788937592992}}) = 0
epoll_wait(175, {}, 8192, 0) = 0
read(160, "\332a\375\f\237\331\235\31YD2\304\5\362;#\232A\225\37?\203<w0%\371%S/\275\232"..., 63592) = 10136
read(160, 0x2aaab4ca4bef, 53456) = -1 EAGAIN (Resource temporarily unavailable)
epoll_ctl(175, EPOLL_CTL_ADD, 160, {EPOLLIN, {u32=160, u64=4371809895922532512}}) = 0
...
jstat
-- Java Virtual Machine Statistics Monitoring Tool, which is used to monitor information on compile, GC, etc.The most frequently-used way for me is to get GC statistical information from a current java process:
[hadoop@K1213 ~]$ jstat -gc 11036 S0C S1C S0U S1U EC EU OC OU PC PU YGC YGCT FGC FGCT GCT 34944.0 34944.0 763.4 0.0 279616.0 218484.1 699072.0 572871.8 65536.0 22317.0 12 0.423 0 0.000 0.423 [hadoop@K1213 ~]$ jstat -gcutil 11036 S0 S1 E O P YGC YGCT FGC FGCT GCT 0.00 7.17 93.65 81.95 34.06 13 0.432 0 0.000 0.432
The description for all columns is listed here, and you could find more detailed usage for 'jstat' in that webpage. As for the above command, I always pay more attention to FGC (full GC times). Chances are that there are something wrong like memory leak in our code provided that FGC is relatively a large number.
jmap
-- Retrieve current heap space info, including classes, amount of objects, occupied memory, etc. It's just like getting all the info from 'jhat' at runtime.[hadoop@k1291 ~]$ jmap -histo 11711 | head -n 50 num #instances #bytes class name ---------------------------------------------- 1: 22834 144531152 [B 2: 699375 123144384 [D 3: 1153782 94102184 [Ljava.util.HashMap$Entry; 4: 1827000 89984520 [C 5: 1148737 64329272 java.util.HashMap 6: 331311 58298464 [J 7: 1423855 34172520 java.lang.String 8: 331138 29140144 com.miaozhen.yo.tcpreporter.report.Counter 9: 659720 21111040 java.util.HashMap$Entry 10: 271052 13010496 java.util.StringTokenizer 11: 151911 10937592 com.miaozhen.yo.tcpreporter.report.RFPanel 12: 243543 9741720 java.util.TreeMap$Entry 13: 47619 6636000 <constMethodKlass> 14: 47619 6486248 <methodKlass> 15: 236361 5672664 java.lang.Long 16: 168142 5380544 com.miaozhen.yo.tcpreporter.history.HistoryCount 17: 3844 4571976 <constantPoolKlass> 18: 165569 3973656 com.miaozhen.yo.tcpreporter.report.RFCounter 19: 92516 3700640 java.util.HashMap$EntryIterator 20: 146659 3519816 java.lang.StringBuffer 21: 75587 3023480 com.miaozhen.app.MzSequenceFile$SMeta 22: 3844 2944464 <instanceKlassKlass> 23: 105924 2542176 java.lang.StringBuilder 24: 3185 2520192 <constantPoolCacheKlass> 25: 3288 2124824 [I 26: 42750 1710000 sun.misc.FloatingDecimal 27: 17819 1298352 [Ljava.lang.Object; 28: 9867 1105104 com.miaozhen.yo.tcpreporter.Purelog 29: 41796 1003104 com.miaozhen.tools.MyDouble 30: 51896 830336 java.util.HashMap$EntrySet 31: 33984 815616 java.lang.Double 32: 15043 633656 [Ljava.lang.String; 33: 1291 593104 <methodDataKlass> 34: 11493 551664 java.nio.HeapByteBuffer 35: 11487 551376 java.nio.HeapCharBuffer 36: 33945 543120 com.miaozhen.yo.tcpreporter.history.HistoryLevelOne 37: 4158 503104 java.lang.Class 38: 19564 469536 java.util.Date 39: 9777 469296 java.util.TreeMap$AscendingSubMap 40: 11487 459480 java.util.ArrayList$SubList 41: 11487 459480 java.util.ArrayList$SubList$1 42: 6415 407520 [S 43: 6775 369960 [[I 44: 11816 283584 java.util.ArrayList 45: 15982 255712 com.miaozhen.yo.tcpreporter.history.HistoryLevelTwo 46: 10619 254856 org.apache.hadoop.io.Text 47: 1571 175952 org.apache.hadoop.hdfs.protocol.DatanodeInfo
[hadoop@k1291 ~]$ jmap -heap 11711 Attaching to process ID 11711, please wait... Debugger attached successfully. Server compiler detected. JVM version is 23.6-b04 using thread-local object allocation. Mark Sweep Compact GC Heap Configuration: MinHeapFreeRatio = 40 MaxHeapFreeRatio = 70 MaxHeapSize = 3221225472 (3072.0MB) NewSize = 1310720 (1.25MB) MaxNewSize = 17592186044415 MB OldSize = 5439488 (5.1875MB) NewRatio = 2 SurvivorRatio = 8 PermSize = 21757952 (20.75MB) MaxPermSize = 85983232 (82.0MB) G1HeapRegionSize = 0 (0.0MB) Heap Usage: New Generation (Eden + 1 Survivor Space): capacity = 316669952 (302.0MB) used = 276925888 (264.09710693359375MB) free = 39744064 (37.90289306640625MB) 87.44937315681912% used Eden Space: capacity = 281542656 (268.5MB) used = 266371136 (254.03131103515625MB) free = 15171520 (14.46868896484375MB) 94.61128902612896% used From Space: capacity = 35127296 (33.5MB) used = 10554752 (10.0657958984375MB) free = 24572544 (23.4342041015625MB) 30.04715193563433% used To Space: capacity = 35127296 (33.5MB) used = 0 (0.0MB) free = 35127296 (33.5MB) 0.0% used tenured generation: capacity = 703594496 (671.0MB) used = 625110416 (596.1517486572266MB) free = 78484080 (74.84825134277344MB) 88.84526805621856% used Perm Generation: capacity = 25690112 (24.5MB) used = 25664256 (24.475341796875MB) free = 25856 (0.024658203125MB) 99.89935427295919% used 8870 interned Strings occupying 738840 bytes.
By using the following command, the output HeapDump file can be analysed by 'jhat'.
jmap -dump:live,format=b,file=/home/data8/heapdump.log [PID]
HeapDumpOnOutOfMemoryError
When facing OOM in heap space error, we could simply add the following arguments to our java programming at the startup. In this way, the heap space snapshot is dumped out when OOM occurs. Apply `jhat` command to the HeapDump file for analysing.-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/data8/heapspaceerror.out
FYI: If we intend to specify the above arguments in MapReduce program, we should do it in the following way:
hadoop jar mr.jar MainClass -Dmapreduce.map.java.opts="-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/data8/heapspaceerror.out" argu1 argu2
jhat
-- HAT, abbreviation for Heap Analysis Tool, which is used to analyse HeapDump file.$ jhat heapdump.out Reading from log.log... Dump file created Wed Mar 14 12:01:45 CST 2012 Snapshot read, resolving... Resolving 6762 objects... Chasing references, expect 1 dots. Eliminating duplicate references. Snapshot resolved. Started HTTP server on port 7000 Server is ready.
When the server is ready, we could check out the result in browser: http://hostname:7000/. In the webpage, all classes which exists in heap space is listed here, but it is somewhat useless for us. Luckily, some portals which provide with more intuitive analytic result can be found at the end of the webpage.
We could step into "Show instance counts for all classes" to see the count of all objects for each class individually, which is sorted in the webpage.
As we can see in current scenario, there are too many LoggingEvent that results in OOM in heap space, which provides us with a hint where the problem might be.
© 2014-2017 jason4zhu.blogspot.com All Rights Reserved
If transfering, please annotate the origin: Jason4Zhu
