JMX堆栈分析

线程堆栈：

线程堆栈也称线程调用堆栈，是虚拟机中线程（包括锁）状态的一个瞬间快照，即系统在某一个时刻所有线程的运行状态，包括每一个线程的调用堆栈，锁的持有情况。虽然不同的虚拟机打印出来的格式有些不同，但是线程堆栈的信息都包含：

  • 线程名字，id，线程的数量等。
  • 线程的运行状态，锁的状态（锁被哪个线程持有，哪个线程在等待锁等）
  • 调用堆栈（即函数的调用层次关系）调用堆栈包含完整的类名，所执行的方法，源代码的行数。

借助堆栈信息可以帮助分析很多问题，如线程死锁，锁争用，死循环，识别耗时操作等等。在多线程场合下的稳定性问题分析和性能问题分析，线程堆栈分析湿最有效的方法，在多数情况下，无需对系统了解就可以进行相应的分析。
由于线程堆栈是系统某个时刻的线程运行状况（即瞬间快照），对于历史痕迹无法追踪。只能结合日志分析。总的来说线程堆栈是多线程类应用程序非功能型问题定位的最有效手段，最善于分析如下类型问题：

  • 系统无缘无故的cpu过高
  • 系统挂起，无响应
  • 系统运行越来越慢
  • 性能瓶颈（如无法充分利用cpu等）
  • 线程死锁，死循环等
  • 由于线程数量太多导致的内存溢出（如无法创建线程等）

死锁：

一个 web 服务器使用几十到几百个线程来处理大量并发用户，如果一个或多个线程使用相同的资源，线程之间的竞争就不可避免了，并且可能会发生死锁。

死锁是线程竞争的一个特殊状态，一个或是多个线程在等待其他线程完成它们的任务。

线程状态：

  • NEW：线程刚被创建，但是还没有被处理。
  • RUNNABLE：当调用thread.start()后，线程变成为Runnable状态。只要得到CPU，就可以执行
  • Running：线程正在执行
  • BLOCKED：该线程正在等待另外的不同的线程释放锁，阻塞状态
  • WAITING：该线程正在等待，通过使用了 wait, join 或者是 park 方法
  • TIMED_WAITING：该线程正在等待，通过使用了 sleep, wait, join 或者是 park 方法，与Waiting的区别在于Timed_Waiting的等待有时间限制
  • Dead：线程执行完毕，或者抛出了未捕获的异常之后，会进入dead状态，表示该线程结束

输出堆栈：

通常将堆栈信息重定向到一个文件中，

命令 : $jstack [option] pid >> 文件

堆栈解读：

只需要关注java用户线程，其他由虚拟机自动创建的，在实际分析中可以暂时忽略：

一般来讲，我们只需要关注处于RUNNABLE状态的线程并且包含com.xxx的一行(从下往上看)

"http-nio-40243-exec-9" #125 daemon prio=5 os_prio=0 tid=0x00007fd234d9f800 nid=0x7114 runnable [0x00007fd194e87000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:170)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at okio.Okio$2.read(Okio.java:139)
        at okio.AsyncTimeout$2.read(AsyncTimeout.java:237)
        at okio.RealBufferedSource.indexOf(RealBufferedSource.java:345)
        at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:217)
        at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:211)
        at okhttp3.internal.http1.Http1Codec.readResponseHeaders(Http1Codec.java:189)
        at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:75)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92)
        at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92)
        xxxxxxxxxxxxxxxx
        at feign.ReflectiveFeign$FeignInvocationHandler.invoke(ReflectiveFeign.java:103)
        at com.sun.proxy.$Proxy176.getCampaignShopCouponLimitRule(Unknown Source)
        at com.yazuo.kbpos.scan.dinner.service.impl.CouponsServiceImpl.queryCouponLimitRuleList(CouponsServiceImpl.java:478)
        at com.yazuo.kbpos.scan.dinner.controller.CouponsController.queryCouponLimitRuleList(CouponsController.java:115)
        at com.yazuo.kbpos.scan.dinner.controller.CouponsController$$FastClassBySpringCGLIB$$95e09cc2.invoke(<generated>)
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:738

线程解读：

  • 线程名,“http-nio-40243-exec-10”
  • 线程属性（如果是Daemon线程，会有Daemon标识，否则，什么都没有）
  • 线程优先级，prio
  • java线程对应的本地线程的优先级os_prio
  • java线程标识tid
  • java线程对应的本地线程标识nid
  • 线程状态（运行中、等待等）
  • 线程的栈信息
  • 线程锁信息

线程堆栈里面的最直观的信息是当前线程的调用上下文，即从哪个函数调用到哪个函数（从下往上看），正执行到哪一类的哪一行，借助这些信息，我们就对当前系统正在做什么一目了然。

示例中基本可以定位到出现问题的方法为getCampaignShopCouponLimitRule

BLOCKED状态示例：

 折叠源码
"http-nio-40243-exec-393" #1212 daemon prio=5 os_prio=0 tid=0x00007f4fdc3d9000 nid=0xe30 runnable [0x00007f4fc09d0000]
   java.lang.Thread.State: RUNNABLE
        at java.lang.Throwable.getStackTraceElement(Native Method)
        at java.lang.Throwable.getOurStackTrace(Throwable.java:827)
        - locked <0x00000000faf1f990> (a java.lang.Throwable)
        at java.lang.Throwable.getStackTrace(Throwable.java:816)
        at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:497)
        at org.apache.log4j.spi.LocationInfo.<init>(LocationInfo.java:139)
        at org.apache.log4j.spi.LoggingEvent.getLocationInformation(LoggingEvent.java:253)
        at org.apache.log4j.pattern.LineLocationPatternConverter.format(LineLocationPatternConverter.java:58)
        at org.apache.log4j.pattern.BridgePatternConverter.format(BridgePatternConverter.java:119)
        at org.apache.log4j.EnhancedPatternLayout.format(EnhancedPatternLayout.java:546)
        at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:310)
        at org.apache.log4j.WriterAppender.append(WriterAppender.java:162)
        at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
        - locked <0x00000000e00a2d40> (a org.apache.log4j.ConsoleAppender)
        at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
        at org.apache.log4j.Category.callAppenders(Category.java:206)
        - locked <0x00000000e009adf0> (a org.apache.log4j.Logger)
        at org.apache.log4j.Category.forcedLog(Category.java:391)
        at org.apache.log4j.Category.log(Category.java:856)
        XXXXXXXXXXXXXX
"http-nio-40243-exec-392" #1211 daemon prio=5 os_prio=0 tid=0x00007f4fd8095000 nid=0xe2f waiting for monitor entry [0x00007f4fc0dd4000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.apache.log4j.Category.callAppenders(Category.java:204)
        - waiting to lock <0x00000000e009adf0> (a org.apache.log4j.Logger)
        at org.apache.log4j.Category.forcedLog(Category.java:391)
        at org.apache.log4j.Category.log(Category.java:856)
        at org.slf4j.impl.Log4jLoggerAdapter.debug(Log4jLoggerAdapter.java:230)
        at com.navercorp.pinpoint.profiler.logging.Slf4jPLoggerAdapter.debug(Slf4jPLoggerAdapter.java:285)
        at com.navercorp.pinpoint.plugin.redis.interceptor.ProtocolSendCommandAndReadMethodInterceptor.before(ProtocolSendCommandAndReadMethodIntercept
or.java:71)

上面的示例中，http-nio-40243-exec-393线程占用了<0x00000000e009adf0>锁，然而http-nio-40243-exec-392正在等待获取锁。

  • 当一个线程占有一个锁的时候，线程堆栈会打印一个－locked
  • 当一个线程正在等在其他线程释放该锁，线程堆栈会打印一个－waiting to lock
  • 当一个线程占有一个锁，但又执行在该锁的wait上，线程堆栈中首先打印locked,然后打印－waiting on

一般情况下，当一个或一些线程正在等待一个锁的时候，应该有一个线程占用了这个锁，即如果有一个线程正在等待一个锁，该锁必然被另一个线程占用，从线程堆栈中看，如果看到waiting to lock<0x22bffb60>,应该也应该有locked<0x22bffb60>,大多数情况下确实如此，但是有些情况下，会发现线程堆栈中可能根本没有locked<0x22bffb60>,而只有waiting to ，这是什么原因呢，实际上，在一个线程释放锁和另一个线程被唤醒之间有一个时间窗，如果这个期间，恰好打印堆栈信息，那么只会找到waiting to ，但是找不到locked 该锁的线程，当然不同的JAVA虚拟机有不同的实现策略，不一定会立刻响应请求，也许会等待正在执行的线程执行完成。

现实场景中，一般遇到的都是两类问题：

1、CPU高，程序响应慢

1）TOP命令获取占用CPU最高的程序PID

2）找到此进程中消耗CPU较高的线程ID

# top -Hp 2093

在上图TIME+列，表示为消耗CPU时间。如图得出消耗时间较长的线程ID为：2163 2094

3）将线程ID转换为16进制

# printf "%x\n" 2163

4）使用jstack打印堆栈信息

$ jstack  -l 2093 >2093.log

5）结果中查询

情况一：直接打印出代码类名，这种情况就很好定位是代码的问题，优化代码即可

情况二："C2 CompilerThread*"开头的堆栈信息，此信息表示java编译的线程，说明java编译器编译过于频繁，tomcat程序则加上参数 -XX:CICompilerCount=4 此设置表示改变编译器线程为4线程并行处理

情况三："catalina-exec-***"开头的堆栈信息，此信息表示程序正常处理的线程，则表示程序本身有待优化

基本思路只需要关注处于RUNNABLE状态的线程并且包含com.xxx的一行即可(从下往上看)

2、CPU正常，但是系统性能比较差，同时可能繁忙线程高

此时需要多次dump，然后找出 BLOCKED 状态的线程列表。

总结：

如果说系统慢，那么要特别关注Blocked,Waiting on condition
如果说系统的cpu耗的高，那么肯定是线程执行有死循环，那么此时要关注下Runable状态。

备注：

1.处于RUNNABLE状态的线程不一定会消耗cpu，像socket IO操作，线程正在从网络上读取数据，尽管线程状态RUNNABLE，但实际上网络io，线程绝大多数时间是被挂起的，只有当数据到达后，线程才会被唤起，挂起发生在本地代码（native）中，虚拟机无法知道真正的线程状态，因此一概显示为RUNNABLE。如果是纯java运算代码，则消耗cpu，如果网络io，很少消耗cpu。

2.处于timed_waiting,waiting状态的线程一定不消耗cpu.

原文地址：https://www.cnblogs.com/aresxin/p/9490938.html

时间： 2024-10-18 00:56:04

JMX堆栈分析的相关文章

使用Tcmalloc进行堆栈分析

在前一篇译文<使用TCmalloc的堆栈检查>,介绍了Tcmalloc进行堆栈检查,今天翻译<heap-profiling using tcmalloc>,了解如何 TCmalloc进行堆栈分析. 一.堆栈分析的用法: 这篇技术文档描述了如何使用C++程序来分析堆栈.可以用来做一下三条事情: 在任何时间了解程序的堆栈情况 定位内存泄漏 找到大量内存分配的位置 1.链接堆栈分析器 你可以对任何链接了tcmalloc的程序进行堆栈分析,并且不需要重新编译. 把tcmalloc链接到你的

java 堆栈分析

再次,研究了一个下午的jhat好jmap.从一开始惊呆.懵懂于那样大量而无聊乏味的数据,到现在有那么一点点收货.赶紧记录下来.没办法,悟性太低... C:\Users\Administrator>jps 11896 12528 Jps C:\Users\Administrator>jps 11896 19016 Jps 5060 HttpServer C:\Users\Administrator>jmap -dump:file=testJmapa 5060 Dumping heap to

java 堆栈分析4

jprofiler ,又是一款好工具... —— 不过显然,我觉得有了jvisualvm就足够了,难道它会比jvisualvm还强大很多!?? 什么时候需要它呢?它有什么特别好用的地方吗? 带来什么方便之处吗? http://www.cnblogs.com/langtianya/p/3172180.html java 堆栈分析4

java 堆栈分析2

有了mat.同时我们发现Java有提供jvisualvm, jvisualvm是一个不错的工具: heap dump . thread dump. cpu/mem profile 无所不能. 不过观察发现,对同一个java程序,其导出的hrof格式数据跟jmap导出的bin格式数据有所不同,比如String类的count,size等.应该是底层实现不同吧 同时惊人的发现jconsole竟然也可以导出hrof格式的的堆栈信息(参考http://blog.csdn.net/moneyice/arti

java 堆栈分析3

很多方式,比如jconsole.jvisualvm,或者jstack -as 这样的形式, 都可以看到实时的java堆栈的变化: eden suvirried0 suvirried1 old perganget major gc minor gc 线程 等等的变化, 但是,问题是,有了这些信息,我们能从中发现什么有价值的东西呢? 总结 虽然电脑中,java程序运行很快,但是我们总是可以获取其一举一动,任何一个细节.其运行中的蛛丝马迹,我们都可以看得清清楚楚,这就现代科技的发达!! java 堆栈

【转】java线上程序排错经验2 - 线程堆栈分析

前言 在线上的程序中,我们可能经常会碰到程序卡死或者执行很慢的情况,这时候我们希望知道是代码哪里的问题,我们或许迫切希望得到代码运行到哪里了,是哪一步很慢,是否是进入了死循环,或者是否哪一段代码有问题导致程序很慢,或者出现了线程不安全的情况,或者是某些连接数或者打开文件数太多等问题,总之我们想知道程序卡在哪里了,哪块占用了大量的资源. 此时,或许通过线程堆栈的分析就能定位出问题. 如果能深入掌握堆栈分析的技术,很多问题都能迎刃而解,但是线程堆栈分析并不简单,设计到线上的排错问题,需要有一定的知识

Go语言的堆栈分析

本文为理解翻译,原文地址:http://www.goinggo.net/2015/01/stack-traces-in-go.html Introduction 在Go语言中有一些调试技巧能帮助我们快速找到问题,有时候你想尽可能多的记录异常但仍觉得不够,搞清楚堆栈的意义有助于定位Bug或者记录更完整的信息. 本文将讨论堆栈跟踪信息以及如何在堆栈中识别函数所传递的参数. Functions 先从这段代码开始: Listing 1 01 package main 02 03 func main()

tomcat服务无响应堆栈分析

tomcat服务突然无响应了,导出内存堆栈和线程堆栈,分析后发现是同步锁使用不合理导致的. [[email protected] ~]# pgrep java10472[[email protected] ~]# jmap -heap 10472Attaching to process ID 10472, please wait...Debugger attached successfully.Server compiler detected.JVM version is 25.111-b14

函数调用堆栈分析

原文链接:http://blog.csdn.net/liigo/archive/2006/12/23/1456938.aspx 转载请注明出处:http://blog.csdn.net/liigo 昨天和海洋一块研究了下函数调用栈,顺便写两句.不足或错误之处请包涵! 理解调用栈最重要的两点是:栈的结构,EBP寄存器的作用. 首先要认识到这样两个事实: 1.一个函数调用动作可分解为:零到多个PUSH指令(用于参数入栈),一个CALL指令.CALL指令内部其实还暗含了一个将返回地址(即CALL指令下