jstack 과 thread Id, CPU, Mem 사용량 체크.
jstack 은 자바 애플리케이션의 쓰레드(Thread) 덤프를 뜰 수 있도록 도와주는 도구 입니다. 자바 애플리케이션의 쓰레드의 상태를 상세히 알 수 있어서 자바 애플리케이션의 프로파일링을 할 수 있고 이를 통해서 성능을 개선할 수 있습니다.
예를들면 다음과 같습니다.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 |
2015-01-21 21:11:12 Full thread dump OpenJDK 64-Bit Server VM (23.25-b01 mixed mode): "Attach Listener" daemon prio=10 tid=0x00007fa830001000 nid=0x3c5a waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "ajp-bio-8309-AsyncTimeout" daemon prio=10 tid=0x00007fa85ca18000 nid=0x2e47 waiting on condition [0x00007fa8508f4000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.apache.tomcat.util.net.JIoEndpoint$AsyncTimeout.run(JIoEndpoint.java:152) at java.lang.Thread.run(Thread.java:701) Locked ownable synchronizers: - None "ajp-bio-8309-Acceptor-0" daemon prio=10 tid=0x00007fa85ca16000 nid=0x2e46 runnable [0x00007fa8509f5000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:375) at java.net.ServerSocket.implAccept(ServerSocket.java:478) at java.net.ServerSocket.accept(ServerSocket.java:446) at org.apache.tomcat.util.net.DefaultServerSocketFactory.acceptSocket(DefaultServerSocketFactory.java:60) at org.apache.tomcat.util.net.JIoEndpoint$Acceptor.run(JIoEndpoint.java:220) at java.lang.Thread.run(Thread.java:701) Locked ownable synchronizers: - None "http-bio-8380-AsyncTimeout" daemon prio=10 tid=0x00007fa85ca13800 nid=0x2e45 waiting on condition [0x00007fa850af6000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.apache.tomcat.util.net.JIoEndpoint$AsyncTimeout.run(JIoEndpoint.java:152) at java.lang.Thread.run(Thread.java:701) Locked ownable synchronizers: - None "http-bio-8380-Acceptor-0" daemon prio=10 tid=0x00007fa85ca12000 nid=0x2e44 runnable [0x00007fa850bf7000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:375) at java.net.ServerSocket.implAccept(ServerSocket.java:478) at java.net.ServerSocket.accept(ServerSocket.java:446) at org.apache.tomcat.util.net.DefaultServerSocketFactory.acceptSocket(DefaultServerSocketFactory.java:60) at org.apache.tomcat.util.net.JIoEndpoint$Acceptor.run(JIoEndpoint.java:220) at java.lang.Thread.run(Thread.java:701) Locked ownable synchronizers: - None "ContainerBackgroundProcessor[StandardEngine[Catalina]]" daemon prio=10 tid=0x00007fa85ca0f800 nid=0x2e43 waiting on condition [0x00007fa850cf8000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1513) at java.lang.Thread.run(Thread.java:701) Locked ownable synchronizers: - None "GroupChannel-Heartbeat-1" daemon prio=10 tid=0x00007fa85ca0b800 nid=0x2e40 waiting on condition [0x00007fa85100d000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.apache.catalina.tribes.group.GroupChannel$HeartbeatThread.run(GroupChannel.java:689) Locked ownable synchronizers: - None "Tribes-MembershipSender" daemon prio=10 tid=0x00007fa85ca0a000 nid=0x2e3e waiting on condition [0x00007fa85110e000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.apache.catalina.tribes.membership.McastServiceImpl$SenderThread.run(McastServiceImpl.java:580) Locked ownable synchronizers: - None "Tribes-MembershipReceiver" daemon prio=10 tid=0x00007fa85ca08800 nid=0x2e3d runnable [0x00007fa85120f000] java.lang.Thread.State: RUNNABLE at java.net.PlainDatagramSocketImpl.receive0(Native Method) - locked <0x00000000a5730da0> (a java.net.PlainDatagramSocketImpl) at java.net.AbstractPlainDatagramSocketImpl.receive(AbstractPlainDatagramSocketImpl.java:136) - locked <0x00000000a5730da0> (a java.net.PlainDatagramSocketImpl) at java.net.DatagramSocket.receive(DatagramSocket.java:759) - locked <0x00000000a5803e80> (a java.net.DatagramPacket) - locked <0x00000000a5803e48> (a java.net.MulticastSocket) at org.apache.catalina.tribes.membership.McastServiceImpl.receive(McastServiceImpl.java:339) at org.apache.catalina.tribes.membership.McastServiceImpl$ReceiverThread.run(McastServiceImpl.java:533) Locked ownable synchronizers: - None "NioReceiver" daemon prio=10 tid=0x00007fa85c9da800 nid=0x2e3c runnable [0x00007fa851310000] 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:83) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) - locked <0x00000000a57ca768> (a sun.nio.ch.Util$1) - locked <0x00000000a57ca758> (a java.util.Collections$UnmodifiableSet) - locked <0x00000000a57ca710> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at org.apache.catalina.tribes.transport.nio.NioReceiver.listen(NioReceiver.java:283) at org.apache.catalina.tribes.transport.nio.NioReceiver.run(NioReceiver.java:433) at java.lang.Thread.run(Thread.java:701) Locked ownable synchronizers: - None "GC Daemon" daemon prio=10 tid=0x00007fa85c934000 nid=0x2e38 in Object.wait() [0x00007fa85183a000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000a55cc360> (a sun.misc.GC$LatencyLock) at sun.misc.GC$Daemon.run(GC.java:117) - locked <0x00000000a55cc360> (a sun.misc.GC$LatencyLock) Locked ownable synchronizers: - None "Low Memory Detector" daemon prio=10 tid=0x00007fa85c0fa000 nid=0x2e36 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "C2 CompilerThread1" daemon prio=10 tid=0x00007fa85c0f8000 nid=0x2e35 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "C2 CompilerThread0" daemon prio=10 tid=0x00007fa85c0f5000 nid=0x2e34 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "Signal Dispatcher" daemon prio=10 tid=0x00007fa85c0f2800 nid=0x2e33 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "Finalizer" daemon prio=10 tid=0x00007fa85c0a4000 nid=0x2e32 in Object.wait() [0x00007fa85254c000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000a57188a8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:133) - locked <0x00000000a57188a8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:149) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189) Locked ownable synchronizers: - None "Reference Handler" daemon prio=10 tid=0x00007fa85c0a2000 nid=0x2e31 in Object.wait() [0x00007fa85264d000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000a57ff5a0> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:502) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) - locked <0x00000000a57ff5a0> (a java.lang.ref.Reference$Lock) Locked ownable synchronizers: - None "main" prio=10 tid=0x00007fa85c009000 nid=0x2e2b runnable [0x00007fa86611b000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:375) at java.net.ServerSocket.implAccept(ServerSocket.java:478) at java.net.ServerSocket.accept(ServerSocket.java:446) at org.apache.catalina.core.StandardServer.await(StandardServer.java:453) at org.apache.catalina.startup.Catalina.await(Catalina.java:777) at org.apache.catalina.startup.Catalina.start(Catalina.java:723) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:622) at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:321) at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:455) Locked ownable synchronizers: - None "VM Thread" prio=10 tid=0x00007fa85c093000 nid=0x2e30 runnable "GC task thread#0 (ParallelGC)" prio=10 tid=0x00007fa85c016800 nid=0x2e2c runnable "GC task thread#1 (ParallelGC)" prio=10 tid=0x00007fa85c018800 nid=0x2e2d runnable "GC task thread#2 (ParallelGC)" prio=10 tid=0x00007fa85c01a000 nid=0x2e2e runnable "GC task thread#3 (ParallelGC)" prio=10 tid=0x00007fa85c01c000 nid=0x2e2f runnable "VM Periodic Task Thread" prio=10 tid=0x00007fa85c105000 nid=0x2e37 waiting on condition JNI global references: 127 |
문제는 이렇게 jstack 의 결과을 보면 당시 쓰레드에 OS 의 자원사용량을 알 방법이 없습니다. OS의 자원이라고 하면 CPU, MEM 등과 같은 것입니다.
jstack 의 결과에는 tid 라고 해서 Thread ID 가 헥사(16 진수)로 표시됩니다. 이는 OS상에서 자바 애플리케이션의 쓰레드의 PID 를 가리킵니다.
그래서 jstack 을 이용할때에 top 명령어를 이용해서 로그를 나기고 이둘을 스크립트를 이용해서 조합해서 가지고 올 수 있도록 누군가 만들었더군요.
stack overflow: Inspecting Java threads in Linux using top
답변을 다신분의 스크립트는 다음과 같습니다.
1 2 3 |
#!/bin/sh top -H -b -n 1 | grep java > /tmp/top.log jstack -l `ps fax | grep java | grep tomcat | sed "s/ *\([0-9]*\) .*/\1/g"` > /tmp/jstack.log |
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 |
#!/usr/bin/perl my ($sec, $min, $hour, $mday, $mon, $year, $wday, $yday, $isdst) = localtime; my $now = sprintf("%04d-%02d-%02d_%02d:%02d:%02d", $year + 1900, $mon + 1, $mday, $hour, $min, $sec); system("sh cpu-java.sh $now"); open LOG, "/tmp/top.log" or die $!; print "PID\tCPU\tMem\tJStack Info\n"; while ($l = <LOG>) { $pid = $l; $pid =~ s/root.*//g; $pid =~ s/ *//g; $hex_pid = sprintf("%#x", $pid); @values = split(/\s{2,}/, $l); $pct = $values[4]; $mem = $values[5]; open JSTACK, "/tmp/jstack.log" or die $!; while ($j = <JSTACK>){ if ($j =~ /.*nid=.*/){ if ($j =~ /.*$hex_pid.*/){ $j =~ s/\n//; $pid =~ s/\n//; print $pid . "\t" . $pct . "\t" . $mem . "\t" . $j . "\n"; } } } close JSTACK; } close LOG; |
결과는 다음과 같이 나옵니다.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 |
[instance3@localhost ~]$ ./jstsck_pid.pl PID CPU Mem JStack Info 11819instanc+200362155611765210972S0.02.00:01.36java 0.0 2.0 "main" prio=10 tid=0x00007fa85c009000 nid=0x2e2b runnable [0x00007fa86611b000] 11820instanc+200362155611765210972S0.02.00:00.03java 0.0 2.0 "GC task thread#0 (ParallelGC)" prio=10 tid=0x00007fa85c016800 nid=0x2e2c runnable 11821instanc+200362155611765210972S0.02.00:00.04java 0.0 2.0 "GC task thread#1 (ParallelGC)" prio=10 tid=0x00007fa85c018800 nid=0x2e2d runnable 11822instanc+200362155611765210972S0.02.00:00.04java 0.0 2.0 "GC task thread#2 (ParallelGC)" prio=10 tid=0x00007fa85c01a000 nid=0x2e2e runnable 11823instanc+200362155611765210972S0.02.00:00.04java 0.0 2.0 "GC task thread#3 (ParallelGC)" prio=10 tid=0x00007fa85c01c000 nid=0x2e2f runnable 11824instanc+200362155611765210972S0.02.00:00.18java 0.0 2.0 "VM Thread" prio=10 tid=0x00007fa85c093000 nid=0x2e30 runnable 11825instanc+200362155611765210972S0.02.00:00.00java 0.0 2.0 "Reference Handler" daemon prio=10 tid=0x00007fa85c0a2000 nid=0x2e31 in Object.wait() [0x00007fa85264d000] 11826instanc+200362155611765210972S0.02.00:00.00java 0.0 2.0 "Finalizer" daemon prio=10 tid=0x00007fa85c0a4000 nid=0x2e32 in Object.wait() [0x00007fa85254c000] 11827instanc+200362155611765210972S0.02.00:00.00java 0.0 2.0 "Signal Dispatcher" daemon prio=10 tid=0x00007fa85c0f2800 nid=0x2e33 runnable [0x0000000000000000] 11828instanc+200362155611765210972S0.02.00:01.97java 0.0 2.0 "C2 CompilerThread0" daemon prio=10 tid=0x00007fa85c0f5000 nid=0x2e34 waiting on condition [0x0000000000000000] 11829instanc+200362155611765210972S0.02.00:01.52java 0.0 2.0 "C2 CompilerThread1" daemon prio=10 tid=0x00007fa85c0f8000 nid=0x2e35 waiting on condition [0x0000000000000000] 11830instanc+200362155611765210972S0.02.00:00.00java 0.0 2.0 "Low Memory Detector" daemon prio=10 tid=0x00007fa85c0fa000 nid=0x2e36 runnable [0x0000000000000000] 11831instanc+200362155611765210972S0.02.00:00.82java 0.0 2.0 "VM Periodic Task Thread" prio=10 tid=0x00007fa85c105000 nid=0x2e37 waiting on condition 11832instanc+200362155611765210972S0.02.00:00.00java 0.0 2.0 "GC Daemon" daemon prio=10 tid=0x00007fa85c934000 nid=0x2e38 in Object.wait() [0x00007fa85183a000] 11836instanc+200362155611765210972S0.02.00:00.06java 0.0 2.0 "NioReceiver" daemon prio=10 tid=0x00007fa85c9da800 nid=0x2e3c runnable [0x00007fa851310000] 11837instanc+200362155611765210972S0.02.00:00.59java 0.0 2.0 "Tribes-MembershipReceiver" daemon prio=10 tid=0x00007fa85ca08800 nid=0x2e3d runnable [0x00007fa85120f000] 11838instanc+200362155611765210972S0.02.00:00.71java 0.0 2.0 "Tribes-MembershipSender" daemon prio=10 tid=0x00007fa85ca0a000 nid=0x2e3e sleeping[0x00007fa85110e000] 11840instanc+200362155611765210972S0.02.00:00.06java 0.0 2.0 "GroupChannel-Heartbeat-1" daemon prio=10 tid=0x00007fa85ca0b800 nid=0x2e40 waiting on condition [0x00007fa85100d000] 11843instanc+200362155611765210972S0.02.00:00.98java 0.0 2.0 "ContainerBackgroundProcessor[StandardEngine[Catalina]]" daemon prio=10 tid=0x00007fa85ca0f800 nid=0x2e43 waiting on condition [0x00007fa850cf8000] 11844instanc+200362155611765210972S0.02.00:00.00java 0.0 2.0 "http-bio-8380-Acceptor-0" daemon prio=10 tid=0x00007fa85ca12000 nid=0x2e44 runnable [0x00007fa850bf7000] 11845instanc+200362155611765210972S0.02.00:00.10java 0.0 2.0 "http-bio-8380-AsyncTimeout" daemon prio=10 tid=0x00007fa85ca13800 nid=0x2e45 waiting on condition [0x00007fa850af6000] 11846instanc+200362155611765210972S0.02.00:00.00java 0.0 2.0 "ajp-bio-8309-Acceptor-0" daemon prio=10 tid=0x00007fa85ca16000 nid=0x2e46 runnable [0x00007fa8509f5000] 11847instanc+200362155611765210972S0.02.00:00.10java 0.0 2.0 "ajp-bio-8309-AsyncTimeout" daemon prio=10 tid=0x00007fa85ca18000 nid=0x2e47 waiting on condition [0x00007fa8508f4000] 15450instanc+200362155611765210972S0.02.00:00.00java 0.0 2.0 "Attach Listener" daemon prio=10 tid=0x00007fa830001000 nid=0x3c5a waiting on condition [0x0000000000000000] |