当前位置:   article > 正文

Java线程<二> _ Thread Dump日志分析_mysql-cj-abandoned-connection-cleanup

mysql-cj-abandoned-connection-cleanup

目录

一、查看CPU上下文切换

1. vmstat命令

2. pidstat命令

二、JVM的jstack命令

1. JVM的jstack命令

2. 堆栈信息的线程状态

三、 Thread Dump日志分析

1. 导出堆栈信息

2. 堆栈信息实例

        实例一:BLOCKED (on object monitor)

        实例二:TIMED_WAITING (sleeping)

        实例三:TIMED_WAITING (on object monitor)

        实例四:WAITING (parking)

四、参考资料


一、查看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空闲的物理内存的大小
buffIO数据结构的缓存区缓存
cache从磁盘读取文件的内容缓存
swapsi

1. 每秒从磁盘读入虚拟内存的大小

2. 大于0,表示物理内存不够用或者内存泄露

so

1. 每秒虚拟内存写入磁盘的大小

2. 大于0,表示物理内存不够用或者内存泄露

iobi

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:显示每个进程的上下文切换情况

所属内容描述
-uPID当前进程ID
%usr当前进程在用户空间占用cpu的百分比
%system当前进程在内核空间占用cpu的百分比
%guest当前进程在虚拟机占用cpu的百分比
%CPU当前进程占用cpu的百分比
CPU处理当前进程的cpu编号
Command当前进程对应的命令
-wcswch/s

1. 每秒主动任务上下文切换数量

2. 说明进程等待资源,有可能发生了I/O等其他问题

nvcswch/s

1. 每秒被动任务上下文切换数量

2. 说明进程被强制调度,都在争抢CPU,说明CPU的确成了瓶颈

-rminflt/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 来观察锁持有情况

  1. "mysql-cj-abandoned-connection-cleanup" #53 daemon prio=5 os_prio=0 tid=0x00007fd891d4c800 nid=0x60d in Object.wait() [0x00007fd7fc3de000]
  2. java.lang.Thread.State: TIMED_WAITING (on object monitor)
  3. at java.lang.Object.wait(Native Method)
  4. at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
  5. - locked <0x00000000c335c7d8> (a java.lang.ref.ReferenceQueue$Lock)
  6. at com.mysql.cj.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:85)
  7. at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
  8. at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
  9. 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"等待获取监控对象(对象的锁对象)。

  1. "Thread-11" #121 daemon prio=5 os_prio=0 tid=0x00007f10e02e0000 nid=0xb93 waiting for monitor entry [0x00007f108ab65000]
  2. java.lang.Thread.State: BLOCKED (on object monitor)
  3. at com.common.instance.test.service.impl.NginxCacheServiceImpl$3.run(NginxCacheServiceImpl.java:110)
  4. - waiting to lock <0x00000000c0002370> (a java.lang.String)
  5. - locked <0x00000000c0002388> (a java.lang.String)
  6. at java.lang.Thread.run(Thread.java:748)
  7. Locked ownable synchronizers:
  8. - None
  9. "Thread-10" #120 daemon prio=5 os_prio=0 tid=0x00007f10e0378800 nid=0xb92 waiting for monitor entry [0x00007f108abe6000]
  10. java.lang.Thread.State: BLOCKED (on object monitor)
  11. at com.common.instance.test.service.impl.NginxCacheServiceImpl$2.run(NginxCacheServiceImpl.java:100)
  12. - waiting to lock <0x00000000c0002388> (a java.lang.String)
  13. - locked <0x00000000c0002370> (a java.lang.String)
  14. at java.lang.Thread.run(Thread.java:748)
  15. Locked ownable synchronizers:
  16. - None
  17. Found one Java-level deadlock:
  18. =============================
  19. "Thread-11":
  20. waiting to lock monitor 0x00007f10d4010248 (object 0x00000000c0002370, a java.lang.String),
  21. which is held by "Thread-10"
  22. "Thread-10":
  23. waiting to lock monitor 0x00007f10cc295ab8 (object 0x00000000c0002388, a java.lang.String),
  24. which is held by "Thread-11"
  25. Java stack information for the threads listed above:
  26. ===================================================
  27. "Thread-11":
  28. at com.common.instance.test.service.impl.NginxCacheServiceImpl$3.run(NginxCacheServiceImpl.java:110)
  29. - waiting to lock <0x00000000c0002370> (a java.lang.String)
  30. - locked <0x00000000c0002388> (a java.lang.String)
  31. at java.lang.Thread.run(Thread.java:748)
  32. "Thread-10":
  33. at com.common.instance.test.service.impl.NginxCacheServiceImpl$2.run(NginxCacheServiceImpl.java:100)
  34. - waiting to lock <0x00000000c0002388> (a java.lang.String)
  35. - locked <0x00000000c0002370> (a java.lang.String)
  36. at java.lang.Thread.run(Thread.java:748)
  37. Found 1 deadlock.

        实例二:TIMED_WAITING (sleeping)

(1)线程状态是TIMED_WAITING,限时等待。Druid连接池中的连接等待销毁;

(2)waiting on condition [0x00007f1091cf2000]:该线程在等待sleep()结束,把自己唤醒。

  1. "Druid-ConnectionPool-Destroy-1324165839" #61 daemon prio=5 os_prio=0 tid=0x00007f1171ef8000 nid=0xb58 waiting on condition [0x00007f1091cf2000]
  2. java.lang.Thread.State: TIMED_WAITING (sleeping)
  3. at java.lang.Thread.sleep(Native Method)
  4. at com.alibaba.druid.pool.DruidDataSource$DestroyConnectionThread.run(DruidDataSource.java:2913)
  5. Locked ownable synchronizers:
  6. - 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:发生自锁。

  1. "Atomikos:1" #63 daemon prio=5 os_prio=0 tid=0x00007f1171fe8000 nid=0xb59 in Object.wait() [0x00007f1091a71000]
  2. java.lang.Thread.State: TIMED_WAITING (on object monitor)
  3. at java.lang.Object.wait(Native Method)
  4. - waiting on <0x00000000c3dc02b0> (a java.lang.Object)
  5. at com.atomikos.timing.PooledAlarmTimer.doWait(PooledAlarmTimer.java:105)
  6. - locked <0x00000000c3dc02b0> (a java.lang.Object)
  7. at com.atomikos.timing.PooledAlarmTimer.run(PooledAlarmTimer.java:71)
  8. at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
  9. at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
  10. at java.lang.Thread.run(Thread.java:748)
  11. Locked ownable synchronizers:
  12. - <0x00000000c3dc0330> (a java.util.concurrent.ThreadPoolExecutor$Worker)

        实例四:WAITING (parking)

(1)线程状态是WAITING ,无限期等待。Druid连接池中的连接等待创建;

(2)parking to wait for  <0x00000000c1c790d0>:无限期等待,直至某个条件(创建连接)。

  1. "Druid-ConnectionPool-Create-1324165839" #60 daemon prio=5 os_prio=0 tid=0x00007f1171ef5000 nid=0xb57 waiting on condition [0x00007f1091d73000]
  2. java.lang.Thread.State: WAITING (parking)
  3. at sun.misc.Unsafe.park(Native Method)
  4. - parking to wait for <0x00000000c1c790d0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
  5. at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
  6. at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
  7. at com.alibaba.druid.pool.DruidDataSource$CreateConnectionThread.run(DruidDataSource.java:2813)
  8. Locked ownable synchronizers:
  9. - None

四、参考资料

Java线程<一> _ 介绍_爱我所爱0505-CSDN博客

JVM 性能调优监控工具_慕课手记

三个实例演示 Java Thread Dump 日志分析 - 旁观者 - 博客园

JVM监控命令详解(转) - 舒润 - 博客园

CPU 上下文切换是什么意思?(下)_一亩三分地-CSDN博客

声明:本文内容由网友自发贡献,不代表【wpsshop博客】立场,版权归原作者所有,本站不承担相应法律责任。如您发现有侵权的内容,请联系我们。转载请注明出处:https://www.wpsshop.cn/w/羊村懒王/article/detail/635553
推荐阅读
相关标签
  

闽ICP备14008679号