目录
实例一:BLOCKED (on object monitor)
实例三:TIMED_WAITING (on object monitor)
一、查看CPU上下文切换
1. vmstat命令
vmstat是一个常用的系统性能分析工具,主要用来分析系统的内存使用情况和分析CPU上下文切换和中断的次数。vmstat默认是1秒采集一次。
所属 | 内容 | 描述 |
procs | r (Running or Runnable) | 1. 运行队列长度:多少个进程真的分配到CPU 2. 值超出CPU核数,就会出现CPU瓶颈了。也和top负载有关系 |
b(Blocked) | 阻塞:处于不可中断睡眠状态的进程数 | |
memory (byte) | swdp | 1. 虚拟内存已使用的大小 2. 大于0,表示机器物理内存不足或者内存泄露 |
free | 空闲的物理内存的大小 | |
buff | IO数据结构的缓存区缓存 | |
cache | 从磁盘读取文件的内容缓存 | |
swap | si | 1. 每秒从磁盘读入虚拟内存的大小 2. 大于0,表示物理内存不够用或者内存泄露 |
so | 1. 每秒虚拟内存写入磁盘的大小 2. 大于0,表示物理内存不够用或者内存泄露 | |
io | bi | 1. 块设备(所有的磁盘和其他块设备)每秒接收的块数量,如写磁盘等 2. 要接近0,不然就是IO过于频繁 |
bo | 1. 块设备(所有的磁盘和其他块设备)每秒发送的块数量,如读取文件 2. 要接近0,不然就是IO过于频繁 | |
system (每秒次数) | in(interrupt) | 每秒CPU的中断次数,包括时间中断 |
cs(context switch) | 1. 每秒上下文切换次数,如线程/进程切换、调用系统函数 2. 值越小越好,进行性能压测的重要参数 | |
cpu (百分比) | us | 用户CPU时间 |
sy | 1. 系统CPU时间 2. 太高,表示系统调用时间长,如IO操作频繁 | |
id | 空闲CPU时间,us + sy + id = 100 | |
wd | 1. 等待IO时间 2. 过高时,说明io等待比较严重,可能磁盘大量随机访问造成 | |
st | 虚拟机偷取的CPU时间 |
2. pidstat命令
pidstat -w可以查看每个进程的上下文切换次数。
#CentOS使用pidstat
yum install sysstat
主要参数:
-u:默认的参数,显示各个进程的cpu使用统计
-r:显示各个进程的内存使用统计
-d:显示各个进程的IO使用情况
-p:指定进程号
-w:显示每个进程的上下文切换情况
所属 | 内容 | 描述 |
-u | PID | 当前进程ID |
%usr | 当前进程在用户空间占用cpu的百分比 | |
%system | 当前进程在内核空间占用cpu的百分比 | |
%guest | 当前进程在虚拟机占用cpu的百分比 | |
%CPU | 当前进程占用cpu的百分比 | |
CPU | 处理当前进程的cpu编号 | |
Command | 当前进程对应的命令 | |
-w | cswch/s | 1. 每秒主动任务上下文切换数量 2. 说明进程等待资源,有可能发生了I/O等其他问题 |
nvcswch/s | 1. 每秒被动任务上下文切换数量 2. 说明进程被强制调度,都在争抢CPU,说明CPU的确成了瓶颈 | |
-r | minflt/s | 每秒次缺页错误次数(minor page faults),即:虚拟内存地址映射成物理内存地址产生的page fault次数 |
majflt/s | 每秒主缺页错误次数(major page faults),即:主缺页错误次数(虚拟内存地址映射成物理内存地址时,相应的page在swap中),一般在内存使用紧张时产生 | |
VSZ | 进程使用的虚拟内存(kB) | |
RSS | 进程使用的物理内存(kB) | |
%MEM | 进程使用内存的百分比 |
二、JVM的jstack命令
1. JVM的jstack命令
jstack(Java Stack Trace)查看某个Java进程内的线程堆栈信息。如果java程序崩溃生成core文件,jstack工具获得core文件的java stack和native stack的信息,可以轻松地知道java程序是如何崩溃和在程序何处发生问题。也可以获取正在运行的java程序java stack和native stack的信息,用以优化代码等。
如下图所示,jstack命令使用。
-F:当正常输出的请求不被响应时,强制输出线程堆栈
-m:如果调用到本地方法的话,可以显示 C/C++ 的堆栈
-l:除堆栈外,显示关于锁的附加信息,在发生死锁时可以用 jstack -l pid 来观察锁持有情况
"mysql-cj-abandoned-connection-cleanup" #53 daemon prio=5 os_prio=0 tid=0x00007fd891d4c800 nid=0x60d in Object.wait() [0x00007fd7fc3de000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
- locked <0x00000000c335c7d8> (a java.lang.ref.ReferenceQueue$Lock)
at com.mysql.cj.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:85)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
以上是堆栈信息,主要参数:
- "mysql-cj-abandoned-connection-cleanup":线程名
- #53:堆栈序号
- daemon:有daemon,表示当前线程是守护线程;无,则不是
- prio=5:JVM线程优先级
- os_prio=0:OS层次的线程优先级
- tid=0x00007fd891d4c800:线程标识
- nid=0x60d:线程ID
2. 堆栈信息的线程状态
线程状态参考:Java线程<一> _ 介绍
- 死锁:deadlock(重点关注)
- 执行中:Runnable
- 等待资源:waiting on condition(重点关注)
- 等待获取监视器:waiting for monitor entry(重点关注)
- 暂停,Suspended
- 对象等待中,Object.wait() 或 TIMED_WAITING
- 阻塞,Blocked(重点关注)
- 停止,Parked
三、 Thread Dump日志分析
1. 导出堆栈信息
step1:进入JDK的bin目录下,执行jstack命令
jstack -l 2605 > /home/dump2605
step2:统计线程所处状态
grep java.lang.Thread.State /home/dump2605 | awk '{print $2$3$4$5}' | sort | uniq -c
step3:导出dump2605文件
2. 堆栈信息实例
实例一:BLOCKED (on object monitor)
(1)线程状态是BLOCKED,实际是死锁。"Thread-11"与"Thread-10"为死锁;
(2)locked <0x00000000c0002388>:线程"Thread-11"已经锁住0x00000000c0002388这个地址的对象;
(3)waiting to lock <0x00000000c0002370>:线程"Thread-11"等待给0x00000000c0002370这个地址的对象上锁,已进入对象的锁池中(Entry Set队列);
(4)waiting for monitor entry [0x00007f108ab65000]:线程"Thread-11"等待获取监控对象(对象的锁对象)。
"Thread-11" #121 daemon prio=5 os_prio=0 tid=0x00007f10e02e0000 nid=0xb93 waiting for monitor entry [0x00007f108ab65000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.common.instance.test.service.impl.NginxCacheServiceImpl$3.run(NginxCacheServiceImpl.java:110)
- waiting to lock <0x00000000c0002370> (a java.lang.String)
- locked <0x00000000c0002388> (a java.lang.String)
at java.lang.Thread.run(Thread.java:748)
Locked ownable synchronizers:
- None
"Thread-10" #120 daemon prio=5 os_prio=0 tid=0x00007f10e0378800 nid=0xb92 waiting for monitor entry [0x00007f108abe6000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.common.instance.test.service.impl.NginxCacheServiceImpl$2.run(NginxCacheServiceImpl.java:100)
- waiting to lock <0x00000000c0002388> (a java.lang.String)
- locked <0x00000000c0002370> (a java.lang.String)
at java.lang.Thread.run(Thread.java:748)
Locked ownable synchronizers:
- None
Found one Java-level deadlock:
=============================
"Thread-11":
waiting to lock monitor 0x00007f10d4010248 (object 0x00000000c0002370, a java.lang.String),
which is held by "Thread-10"
"Thread-10":
waiting to lock monitor 0x00007f10cc295ab8 (object 0x00000000c0002388, a java.lang.String),
which is held by "Thread-11"
Java stack information for the threads listed above:
===================================================
"Thread-11":
at com.common.instance.test.service.impl.NginxCacheServiceImpl$3.run(NginxCacheServiceImpl.java:110)
- waiting to lock <0x00000000c0002370> (a java.lang.String)
- locked <0x00000000c0002388> (a java.lang.String)
at java.lang.Thread.run(Thread.java:748)
"Thread-10":
at com.common.instance.test.service.impl.NginxCacheServiceImpl$2.run(NginxCacheServiceImpl.java:100)
- waiting to lock <0x00000000c0002388> (a java.lang.String)
- locked <0x00000000c0002370> (a java.lang.String)
at java.lang.Thread.run(Thread.java:748)
Found 1 deadlock.
实例二:TIMED_WAITING (sleeping)
(1)线程状态是TIMED_WAITING,限时等待。Druid连接池中的连接等待销毁;
(2)waiting on condition [0x00007f1091cf2000]:该线程在等待sleep()结束,把自己唤醒。
"Druid-ConnectionPool-Destroy-1324165839" #61 daemon prio=5 os_prio=0 tid=0x00007f1171ef8000 nid=0xb58 waiting on condition [0x00007f1091cf2000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at com.alibaba.druid.pool.DruidDataSource$DestroyConnectionThread.run(DruidDataSource.java:2913)
Locked ownable synchronizers:
- None
实例三:TIMED_WAITING (on object monitor)
(1)线程状态是TIMED_WAITING,限期等待对象锁。某个对象的锁对象被其他占用;
(2)locked <0x00000000c3dc02b0>:"Atomikos:1"已锁住0x00000000c3dc02b0地址的对象;
(3)waiting on <0x00000000c3dc02b0>:"Atomikos:1"等待获取锁(发生自锁);
(4)in Object.wait() [0x00007f1091a71000]:"Atomikos:1"等待0x00000000c3dc02b0地址的对象的锁对象0x00007f1091a71000;
(5) Locked ownable synchronizers:发生自锁。
"Atomikos:1" #63 daemon prio=5 os_prio=0 tid=0x00007f1171fe8000 nid=0xb59 in Object.wait() [0x00007f1091a71000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000c3dc02b0> (a java.lang.Object)
at com.atomikos.timing.PooledAlarmTimer.doWait(PooledAlarmTimer.java:105)
- locked <0x00000000c3dc02b0> (a java.lang.Object)
at com.atomikos.timing.PooledAlarmTimer.run(PooledAlarmTimer.java:71)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Locked ownable synchronizers:
- <0x00000000c3dc0330> (a java.util.concurrent.ThreadPoolExecutor$Worker)
实例四:WAITING (parking)
(1)线程状态是WAITING ,无限期等待。Druid连接池中的连接等待创建;
(2)parking to wait for <0x00000000c1c790d0>:无限期等待,直至某个条件(创建连接)。
"Druid-ConnectionPool-Create-1324165839" #60 daemon prio=5 os_prio=0 tid=0x00007f1171ef5000 nid=0xb57 waiting on condition [0x00007f1091d73000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000c1c790d0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at com.alibaba.druid.pool.DruidDataSource$CreateConnectionThread.run(DruidDataSource.java:2813)
Locked ownable synchronizers:
- None
四、参考资料
Java线程<一> _ 介绍_爱我所爱0505-CSDN博客