怎样分析java线程堆栈日志

怎样分析java线程堆栈⽇志
注: 该⽂章的原⽂是由 Tae Jin Gu 编写,原⽂地址为
当有障碍,或者是⼀个基于 JAVA 的 WEB 应⽤运⾏的⽐预期慢的时候,我们需要使⽤ thread dumps。如果对于你来说,thread dumps 是⾮常复杂的,这篇⽂章或许能对你有所帮助。在这⾥我将解释在 JAVA 中什么是 threads,他们的类型,怎么被创建的,怎样管理它们,你怎样从正在运⾏的应⽤中 dump threads,最后你可以怎样分析它以及确定瓶颈或者是阻塞线程。本⽂来⾃于 JAVA 应⽤程序长期调试经验的结果。
Java and Thread
⼀个 web 服务器使⽤⼏⼗到⼏百个线程来处理⼤量并发⽤户,如果⼀个或多个线程使⽤相同的资源,线程之间的竞争就不可避免了,并且有时候可能会发⽣死锁。
Thread contention 是⼀个线程等待锁的⼀个状态,这个锁被另外⼀个线程持有,等待被释放,不同的线程频繁访问 WEB 应⽤的共享资源。例如,记录⼀条⽇志,线程尝试记录⽇志之前必须先获取锁来访问共享资源。
死锁是线程竞争的⼀个特殊状态,⼀个或是多个线程在等待其他线程完成它们的任务为了完成它们⾃⼰
的任务。
线程竞争会引起各种不同的问题,为了分析这些这些问题,你需要使⽤ dump threads,dump threads 能给你提供每个线程的精确状态信息。
JAVA 线程的背景资料
线程同步
⼀个线程可以与其他线程在同⼀时间内被处理。为了确保⼀致性,当多个线程试图使⽤共享资源的时候,通过使⽤ hread synchronization 在同⼀时间内,应该只有⼀个线程能访问共享资源
JAVA 中的线程同步可以使⽤监视器,每个 JAVA 对象都有⼀个单独的监视器,这个监视器仅仅只能被⼀个线程拥有,对于拥有⼀个由不同的线程所拥有的监视器的线程,确实需要在队列中等待,以便其他线程释放它的监视器。
线程状态
为了分析⼀个 thread dump ⽂件,你需要知道线程状态。线程情况在 java.lang.Thread.State 中阐明了。
图1:线程状态
NEW:线程刚被创建,但是还没有被处理。
RUNNABLE:线程占⽤了 CPU 并且处理了⼀个任务。(或是是在等待状态由于操作系统的资源分配)
BLOCKED:该线程正在等待另外的不同的线程释放锁,以便获取监视器锁
WAITING:该线程正在等待,通过使⽤了 wait, join 或者是 park ⽅法
TIMED_WAITING:该线程正在等待,通过使⽤了 sleep, wait, join 或者是 park ⽅法。(这个与 WAITING 不同是通过⽅法参数指定了最⼤等待时间,WAITING 可以通过时间或者是外部的变化解除)
线程类型
我们将介绍三种最常⽤的⽅法,记住,有⾮常多的其他⽅法可以获取thread dump,⼀个 thread dump 仅仅只能在测量的时候显⽰线程状态。因此为了看得线程状态的变化,建议每隔5秒提取5到10次的记录。
使⽤ jstack 获取 Thread Dump
在 JDK1.6 或者是更⾼的版本中,通过使⽤ jstack, 在 MS Windows 平台上可能可以获取到 Thread Dump。
通过使⽤ jps 检查当前正在运⾏的JAVA进程的 PID。
[user@linux ~]$ jps -v
25780 RemoteTestRunner -ding=UTF-8
i.registry.RegistryImpl 2999 -Dapplication.home=/home1/user/java/jdk.1.6.0_24 -Xms8m
ls.jps.Jps -mlvV -Dapplication.home=/home1/user/java/jdk.1.6.0_24 -Xms8m
使⽤明确的 PID 作为 jstack 的参数来获取 thread dumps。
[user@linux ~]$ jstack -f 5824nbp
使⽤ jVisualVM ⽣成 Thread Dump
通过使⽤⼀个程序 jVisualVM 来⽣成 Thread Dump。
如上图在左侧的任务表⽰当前正在运⾏的进程列表,点击你想要信息的那个线程,然后选择 thread tab 页来检查实时的线程信息。点击右边的 Thread Dump 按钮来获取 thread dump ⽂件。
在 Linux 控制台⽣成
通过使⽤ ps -ef 命令来获取当前正在运⾏的 JAVA 应⽤程序的进程 ID。
[user@linux ~]$ ps - ef | grep java
user      2477          1    0 Dec23 ?        00:10:45 ...
user    25780 25361  0 15:02 pts/3    00:00:02 ./jstatd -J -Djava.security.policy=jstatd.all.policy -p 2999
爱美说user    26335 25361  0 15:49 pts/3    00:00:00 grep java
使⽤精确的 pid 作为 kill –SIGQUIT(3) 的参数来获取 thread dump。
Thread Dump ⽂件的线程信息
"pool-1-thread-13" prio=6 tid=0x000000000729a000 nid=0x2fb4 runnable [0x0000000007f0f000] java.lang.Thread.State: RUNNABLE
at java.SocketInputStream.socketRead0(Native Method)
at ad(SocketInputStream.java:129)
at sun.nio.adBytes(StreamDecoder.java:264)
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)
at sun.nio.ad(StreamDecoder.java:158)
- locked <0x0000000780b7e688> (a java.io.InputStreamReader)
at java.ad(InputStreamReader.java:167)
at java.io.BufferedReader.fill(BufferedReader.java:136)
at java.adLine(BufferedReader.java:299)
- locked <0x0000000780b7e688> (a java.io.InputStreamReader)
at java.adLine(BufferedReader.java:362)
线程名字:当使⽤ Java.lang.Thread 类⽣成⼀个线程的时候,该线程将被命名为 Thread-(Number)。但是当使
⽤urrent.ThreadFactory 类的时候,它将被命名为 pool-(number)-thread-(number)。
优先级:代表该线程的优先级
线程 ID:代表该线程的唯⼀ ID,(⼀些有⽤的信息,⽐如该线程的 CPU 使⽤率或者是内存使⽤率,都能通过该线程 ID 获取到)。
线程状态:代表该线程当前的状态
线程调⽤栈:代表该线程的调⽤栈信息
Thread Dump Patterns by Type When Unable to Obtain a Lock (BLOCKED)
这个应⽤程序的整体性能下降是因为⼀个线程占⽤了锁阻⽌了其他线程获得锁,在下⾯的⽰例中,BLOCKED_TEST pool-1-thread-1 线程占⽤了 <0x0000000780a000b0> 锁,然⽽ BLOCKED_TEST pool-1-thread-2 和 BLOCKED_TEST pool-1-thread-3 threads 正在等待获取锁。
"BLOCKED_TEST pool-1-thread-1" prio=6 tid=0x0000000006904800 nid=0x28f4 runnable [0x000000000785f000]
java.lang.Thread.State: RUNNABLE
at java.io.FileOutputStream.writeBytes(Native Method)
at java.io.FileOutputStream.write(FileOutputStream.java:282)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
- locked <0x0000000780a31778> (a java.io.BufferedOutputStream)
at java.io.PrintStream.write(PrintStream.java:432)
- locked <0x0000000780a04118> (a java.io.PrintStream)
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:202)
at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:272)
at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:85)
- locked <0x0000000780a040c0> (a java.io.OutputStreamWriter)
at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:168)
at java.wLine(PrintStream.java:496)
- locked <0x0000000780a04118> (a java.io.PrintStream)
dota6.51
at java.io.PrintStream.println(PrintStream.java:687)
- locked <0x0000000780a04118> (a java.io.PrintStream)
at com.nbp.theplatform.itorLock(ThreadBlockedState.java:44)
- locked <0x0000000780a000b0> (a com.nbp.theplatform.threaddump.ThreadBlockedState)
at com.nbp.theplatform.threaddump.ThreadBlockedState$1.run(ThreadBlockedState.java:7)
at urrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at urrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Locked ownable synchronizers:
- <0x0000000780a31758> (a urrent.locks.ReentrantLock$NonfairSync)
"BLOCKED_TEST pool-1-thread-2" prio=6 tid=0x0000000007673800 nid=0x260c waiting for monitor entry [0x0000000008abf000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.nbp.theplatform.itorLock(ThreadBlockedState.java:43)
- waiting to lock <0x0000000780a000b0> (a com.nbp.theplatform.threaddump.ThreadBlockedState)
at com.nbp.theplatform.threaddump.ThreadBlockedState\$2.run(ThreadBlockedState.java:26)
at urrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at urrent.ThreadPoolExecutor\$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Locked ownable synchronizers:
- <0x0000000780b0c6a0> (a urrent.locks.ReentrantLock$NonfairSync)
"BLOCKED_TEST pool-1-thread-3" prio=6 tid=0x00000000074f5800 nid=0x1994 waiting for monitor entry [0x0000000008bbf000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.nbp.theplatform.itorLock(ThreadBlockedState.java:42)
- waiting to lock <0x0000000780a000b0> (a com.nbp.theplatform.threaddump.ThreadBlockedState)
at com.nbp.theplatform.threaddump.ThreadBlockedState\$3.run(ThreadBlockedState.java:34)
at urrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886
现代主义音乐at urrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Locked ownable synchronizers:
- <0x0000000780b0e1b8> (a urrent.locks.ReentrantLock$NonfairSync)
当在死锁状态
这是当线程 A 需要获取线程 B 的锁来继续它的任务,然⽽线程 B 也需要获取线程 A 的锁来继续它的任务的时候发⽣的。在thread dump 中,你能看到 DEADLOCK_TEST-1 线程持有 0x00000007d58f5e48 锁,并且尝试获取 0x00000007d58f5e60锁。你也能看
到 DEADLOCK_TEST-2 线程持有 0x00000007d58f5e60,并且尝试获取 0x00000007d58f5e78,同时 DEADLOCK_TEST-3 线程持
有 0x00000007d58f5e78,并且在尝试获取 0x00000007d58f5e48 锁,如你所见,每个线程都在等待获取另外⼀个线程的锁,这状态将不会被改变直到⼀个线程丢弃了它的锁。
"DEADLOCK_TEST-1" daemon prio=6 tid=0x000000000690f800 nid=0x1820 waiting for monitor entry [0x000000000805f000]
java.lang.Thread.State: BLOCKED (on object monitor)扭力
at com.nbp.theplatform.threaddump.MonitorDeadlock(ThreadDeadLockState.java:197)
- waiting to lock <0x00000007d58f5e60> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)
at com.nbp.theplatform.threaddump.itorOurLock(ThreadDeadLockState.java:182)
- locked <0x00000007d58f5e48> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)
at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.run(ThreadDeadLockState.java:135)
Locked ownable synchronizers:
- None
"DEADLOCK_TEST-2" daemon prio=6 tid=0x0000000006858800 nid=0x17b8 waiting for monitor entry [0x000000000815f000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.nbp.theplatform.threaddump.MonitorDeadlock(ThreadDeadLockState.java:197)
- waiting to lock <0x00000007d58f5e78> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)
at com.nbp.theplatform.threaddump.itorOurLock(ThreadDeadLockState.java:182)
- locked <0x00000007d58f5e60> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)
at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.run(ThreadDeadLockState.java:135)
Locked ownable synchronizers:
- None
"DEADLOCK_TEST-3" daemon prio=6 tid=0x0000000006859000 nid=0x25dc waiting for monitor entry [0x000000000825f000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.nbp.theplatform.threaddump.MonitorDeadlock(ThreadDeadLockState.java:197)
- waiting to lock <0x00000007d58f5e48> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)
at com.nbp.theplatform.threaddump.itorOurLock(ThreadDeadLockState.java:182)
- locked <0x00000007d58f5e78> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)
at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.run(ThreadDeadLockState.java:135)
Locked ownable synchronizers:
中国少年儿童队改名为中国少年先锋队时间- None
当持续等待从远处服务器接收消息
该线程是正常的,因为它的状态为 RUNNABLE,尽管如此,当你按照时间顺序排列 Thread Dump,你会发现 socketReadThread 线程正在⽆限等待读取 socket。
"socketReadThread" prio=6 tid=0x0000000006a0d800 nid=0x1b40 runnable [0x00000000089ef000]
java.lang.Thread.State: RUNNABLE
at java.SocketInputStream.socketRead0(Native Method)
at ad(SocketInputStream.java:129)
at sun.nio.adBytes(StreamDecoder.java:264)
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)
at sun.nio.ad(StreamDecoder.java:158)
- locked <0x00000007d78a2230> (a java.io.InputStreamReader)
at sun.nio.ad0(StreamDecoder.java:107)
- locked <0x00000007d78a2230> (a java.io.InputStreamReader)
at sun.nio.ad(StreamDecoder.java:93)
at java.ad(InputStreamReader.java:151)
at com.nbp.theplatform.threaddump.ThreadSocketReadState$1.run(ThreadSocketReadState.java:27)
at java.lang.Thread.run(Thread.java:662)
当 Waiting 时
线程保持在 Waiting 状态,在 Thread Dump 中,IoWaitThread 线程保持等待状态来从 LinkedBlockingQueue 接收消息。如
果 LinkedBlockingQueue ⼀直没有消息,该线程的状态将不会改变。

本文发布于:2024-09-22 01:36:05,感谢您对本站的认可!

本文链接:https://www.17tex.com/xueshu/695054.html

版权声明:本站内容均来自互联网,仅供演示用,请勿用于商业和其他非法用途。如果侵犯了您的权益请与我们联系,我们将在24小时内删除。

标签:线程   状态   获取   等待
留言与评论(共有 0 条评论)
   
验证码:
Copyright ©2019-2024 Comsenz Inc.Powered by © 易纺专利技术学习网 豫ICP备2022007602号 豫公网安备41160202000603 站长QQ:729038198 关于我们 投诉建议