利用线程Dump来查找高消耗CPU代码

对于CPU消耗高的代码,可以用下面的方法来进行定位分析。

前提

运行一段Java代码,让它消耗CPU。

定位

  1. top查找出高消耗CPU PID

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    [root@Automation logs]# top
    top - 10:14:33 up 19:47, 4 users, load average: 0.48, 0.41, 0.32
    Tasks: 189 total, 1 running, 188 sleeping, 0 stopped, 0 zombie
    Cpu(s): 11.8%us, 15.0%sy, 0.0%ni, 70.4%id, 0.0%wa, 1.4%hi, 1.4%si, 0.0%st
    Mem: 3389932k total, 3284936k used, 104996k free, 182736k buffers
    Swap: 3522556k total, 11740k used, 3510816k free, 1144964k cached

    PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
    14538 root 20 0 1916m 52m 10m S 30.8 1.6 8:33.55 java
    14087 root 20 0 100m 4688 3504 S 16.3 0.1 14:21.79 sshd
    10032 root 20 0 1125m 277m 49m S 4.0 8.4 99:02.94 firefox

  2. top -p <PID>查找出线程ID - (输入H查看所有线程的统计信息)

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    [root@Automation logs]# top -p 14538
    top - 10:21:53 up 19:54, 4 users, load average: 0.48, 0.44, 0.35
    Tasks: 3 total, 0 running, 3 sleeping, 0 stopped, 0 zombie
    Cpu(s): 11.9%us, 15.8%sy, 0.0%ni, 69.9%id, 0.0%wa, 0.9%hi, 1.6%si, 0.0%st
    Mem: 3389932k total, 3243372k used, 146560k free, 182704k buffers
    Swap: 3522556k total, 12700k used, 3509856k free, 1105400k cached

    PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
    14539 root 20 0 1916m 52m 10m S 33.0 1.6 10:53.38 java
    14540 root 20 0 1916m 52m 10m S 25.6 1.6 0:00.77 java
    14538 root 20 0 1916m 52m 10m S 0.0 1.6 0:00.00 java

  3. jstack <PID>做线程Dump

    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
    [root@Automation logs]# jstack 14538
    2018-06-20 10:18:12
    Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.80-b11 mixed mode):

    "Attach Listener" daemon prio=10 tid=0x00007f6cbc001000 nid=0x38fe waiting on condition [0x0000000000000000]
    java.lang.Thread.State: RUNNABLE

    "Service Thread" daemon prio=10 tid=0x00007f6ce8093000 nid=0x38d4 runnable [0x0000000000000000]
    java.lang.Thread.State: RUNNABLE

    "C2 CompilerThread1" daemon prio=10 tid=0x00007f6ce8090800 nid=0x38d3 waiting on condition [0x0000000000000000]
    java.lang.Thread.State: RUNNABLE

    "C2 CompilerThread0" daemon prio=10 tid=0x00007f6ce808d800 nid=0x38d2 waiting on condition [0x0000000000000000]
    java.lang.Thread.State: RUNNABLE

    "Signal Dispatcher" daemon prio=10 tid=0x00007f6ce808b000 nid=0x38d1 runnable [0x0000000000000000]
    java.lang.Thread.State: RUNNABLE

    "Finalizer" daemon prio=10 tid=0x00007f6ce806a800 nid=0x38d0 in Object.wait() [0x00007f6cd7efd000]
    java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000cc4028c0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000cc4028c0> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

    "Reference Handler" daemon prio=10 tid=0x00007f6ce8068800 nid=0x38cf in Object.wait() [0x00007f6cd7ffe000]
    java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000cc4025c0> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Object.java:503)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
    - locked <0x00000000cc4025c0> (a java.lang.ref.Reference$Lock)

    "main" prio=10 tid=0x00007f6ce8008800 nid=0x38cb runnable [0x00007f6ceec18000]
    java.lang.Thread.State: RUNNABLE
    at java.io.FileOutputStream.writeBytes(Native Method)
    at java.io.FileOutputStream.write(FileOutputStream.java:345)
    at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
    at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
    - locked <0x00000000cc405728> (a java.io.BufferedOutputStream)
    at java.io.PrintStream.write(PrintStream.java:482)
    - locked <0x00000000cc405708> (a java.io.PrintStream)
    at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
    at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
    at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104)
    - locked <0x00000000cc405800> (a java.io.OutputStreamWriter)
    at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185)
    at java.io.PrintStream.write(PrintStream.java:527)
    - locked <0x00000000cc405708> (a java.io.PrintStream)
    at java.io.PrintStream.print(PrintStream.java:597)
    at java.io.PrintStream.println(PrintStream.java:736)
    - locked <0x00000000cc405708> (a java.io.PrintStream)
    at TestA.testA(TestA.java:10)
    at TestA.main(TestA.java:3)

    "VM Thread" prio=10 tid=0x00007f6ce8064000 nid=0x38ce runnable

    "GC task thread#0 (ParallelGC)" prio=10 tid=0x00007f6ce801e000 nid=0x38cc runnable

    "GC task thread#1 (ParallelGC)" prio=10 tid=0x00007f6ce8020000 nid=0x38cd runnable

    "VM Periodic Task Thread" prio=10 tid=0x00007f6ce809e000 nid=0x38d5 waiting on condition

    JNI global references: 138
  4. 转换(十进制 - 十六进制)nid

    1
    14539 --> 38cb
  5. 在Dump中查找相应nid

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    19
    20
    21
    "main" prio=10 tid=0x00007f6ce8008800 nid=0x38cb runnable [0x00007f6ceec18000]
    java.lang.Thread.State: RUNNABLE
    at java.io.FileOutputStream.writeBytes(Native Method)
    at java.io.FileOutputStream.write(FileOutputStream.java:345)
    at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
    at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
    - locked <0x00000000cc405728> (a java.io.BufferedOutputStream)
    at java.io.PrintStream.write(PrintStream.java:482)
    - locked <0x00000000cc405708> (a java.io.PrintStream)
    at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
    at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
    at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104)
    - locked <0x00000000cc405800> (a java.io.OutputStreamWriter)
    at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185)
    at java.io.PrintStream.write(PrintStream.java:527)
    - locked <0x00000000cc405708> (a java.io.PrintStream)
    at java.io.PrintStream.print(PrintStream.java:597)
    at java.io.PrintStream.println(PrintStream.java:736)
    - locked <0x00000000cc405708> (a java.io.PrintStream)
    at TestA.testA(TestA.java:10)
    at TestA.main(TestA.java:3)

基本上一定位一个准。

唐胡璐 wechat
欢迎您扫一扫上面的微信公众号,订阅我的博客!
分享创造价值,您的支持将鼓励我继续前行!