性能监控(8)-导出JVM的线程堆栈信息
jstack用于导出jvm的线程堆栈信息,可以分析线程是否有死锁,以及线程的状态。
可以使用
top -Hp pid 查询出进程内线程的资源占用率
将pid转为16进制(printf “%x\n” 2290)之后就是与jstack 导出的信息的nid相对应。
基本语法为
Jstack –l<pid>用于打印附加信息。
将线程堆栈信息保存至指定文件
Jstack –l <pid> > /opt/pid
打印的线程堆栈信息为
其中
1 |
"XNIO-2 task-38{线程名}" #208 prio=5{优先级} os_prio=0{系统优先级} tid=0x000000001bcd0000{JAVA线程ID} nid=0x330c{Native线程ID 对应于系统线程的16进制} waiting for monitor entry [0x00000000312dc000] |
线程的状态
1,线程状态为“waiting for monitor entry”:
意味着它 在等待进入一个临界区 ,所以它在”Entry Set“队列中等待。
此时线程状态一般都是 Blocked:
- java.lang.Thread.State: BLOCKED (on object monitor)
2,线程状态为“waiting on condition”:
说明它在等待另一个条件的发生,来把自己唤醒,或者干脆它是调用了 sleep(N)。
此时线程状态大致为以下几种:
- java.lang.Thread.State: WAITING (parking):一直等那个条件发生;
- java.lang.Thread.State: TIMED_WAITING (parking或sleeping):定时的,那个条件不到来,也将定时唤醒自己。
3,如果大量线程在“waiting for monitor entry”:
可能是一个全局锁阻塞住了大量线程。
如果短时间内打印的 thread dump 文件反映,随着时间流逝,waiting for monitor entry 的线程越来越多,没有减少的趋势,可能意味着某些线程在临界区里呆的时间太长了,以至于越来越多新线程迟迟无法进入临界区。
4,如果大量线程在“waiting on condition”:
可能是它们又跑去获取第三方资源,尤其是第三方网络资源,迟迟获取不到Response,导致大量线程进入等待状态。
所以如果你发现有大量的线程都处在 Wait on condition,从线程堆栈看,正等待网络读写,这可能是一个网络瓶颈的征兆,因为网络阻塞导致线程无法执行。
线程状态为“in Object.wait()”:
说明它获得了监视器之后,又调用了 java.lang.Object.wait() 方法。
每个 Monitor在某个时刻,只能被一个线程拥有,该线程就是 “Active Thread”,而其它线程都是 “Waiting Thread”,分别在两个队列 “ Entry Set”和 “Wait Set”里面等候。在 “Entry Set”中等待的线程状态是 “Waiting for monitor entry”,而在 “Wait Set”中等待的线程状态是 “in Object.wait()”。
当线程获得了 Monitor,如果发现线程继续运行的条件没有满足,它则调用对象(一般就是被 synchronized 的对象)的 wait() 方法,放弃了 Monitor,进入 “Wait Set”队列。
此时线程状态大致为以下几种:
- java.lang.Thread.State: TIMED_WAITING (on object monitor);
- java.lang.Thread.State: WAITING (on object monitor);
一般都是RMI相关线程(RMI RenewClean、 GC Daemon、RMI Reaper),GC线程(Finalizer),引用对象垃圾回收线程(Reference Handler)等系统线程处于这种状态。
在linux中线程信息可以通过以下命令查找
1 2 3 |
<span class="number">1)ps -Lfp pid 2)ps -mp pid -o THREAD, tid, <span class="keyword">time 3)top -Hp pid</span></span> |
主要关心如下两个状态
- BLOCKED 线程在等待monitor锁(synchronized,lock关键字)
- WAITING 线程在无限等待唤醒 notify
举个MQ影响HTTP连接的实例,以下为jstack返回的信息:
- controller.TaskPublicController.batch连接被BLOCKED,
RabbitMqSender.SendEbs 调用MQ.ChannelN.basicPublish推送消息,锁住三个资源,它等待其他线程释放0x000000008391a758锁。
1 |
<0x000000008391a738> <0x00000000d639c468> <0x00000000834347e8> |
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 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 |
"XNIO-2 task-38" #208 prio=5 os_prio=0 tid=0x000000001bcd0000 nid=0x330c waiting for monitor entry [0x00000000312dc000] java.lang.Thread.State: BLOCKED (on object monitor) at java.io.BufferedOutputStream.write(BufferedOutputStream.java:94) <span style="color: #ff0000;"> #等待锁0x000000008391a758 - waiting to lock <0x000000008391a758> (a java.io.BufferedOutputStream)</span> at java.io.DataOutputStream.writeByte(DataOutputStream.java:153) at com.rabbitmq.client.impl.Frame.writeTo(Frame.java:188) at com.rabbitmq.client.impl.SocketFrameHandler.writeFrame(SocketFrameHandler.java:153) #锁住0x000000008391a738 - locked <0x000000008391a738> (a java.io.DataOutputStream) at com.rabbitmq.client.impl.AMQConnection.writeFrame(AMQConnection.java:524) at com.rabbitmq.client.impl.AMQCommand.transmit(AMQCommand.java:104) - locked <0x00000000d639c468> (a com.rabbitmq.client.impl.CommandAssembler) at com.rabbitmq.client.impl.AMQChannel.quiescingTransmit(AMQChannel.java:337) - locked <0x00000000834347e8> (a java.lang.Object) at com.rabbitmq.client.impl.AMQChannel.transmit(AMQChannel.java:313) - locked <0x00000000834347e8> (a java.lang.Object) at com.rabbitmq.client.impl.ChannelN.basicPublish(ChannelN.java:664) at com.rabbitmq.client.impl.ChannelN.basicPublish(ChannelN.java:646) at com.rabbitmq.client.impl.ChannelN.basicPublish(ChannelN.java:636) at com.hzcf.api.components.rabbitMq.RabbitMqSender.SendEbs(RabbitMqSender.java:32) at com.hzcf.api.common.base.BasePublicService.addQueryLog(BasePublicService.java:158) at com.hzcf.api.common.base.BasePublicService$$FastClassBySpringCGLIB$$d0be27a1.invoke(<generated>) at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:738) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:85) at org.springframework.cloud.sleuth.instrument.async.TraceAsyncAspect.traceBackgroundThread(TraceAsyncAspect.java:69) at sun.reflect.GeneratedMethodAccessor66.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:629) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:618) at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:673) at com.hzcf.api.common.base.BasePublicService$$EnhancerBySpringCGLIB$$8cecc6d.addQueryLog(<generated>) at com.hzcf.api.common.aspect.ServiceLogAspect.doAfterReturning(ServiceLogAspect.java:33) at sun.reflect.GeneratedMethodAccessor64.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:629) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:611) at org.springframework.aop.aspectj.AspectJAfterReturningAdvice.afterReturning(AspectJAfterReturningAdvice.java:65) at org.springframework.aop.framework.adapter.AfterReturningAdviceInterceptor.invoke(AfterReturningAdviceInterceptor.java:53) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:673) at com.hzcf.api.task.service.impl.TaskServiceImpl$$EnhancerBySpringCGLIB$$45cca553.getBatch(<generated>) at com.hzcf.api.task.controller.TaskPublicController.batch(TaskPublicController.java:51) at com.hzcf.api.task.controller.TaskPublicController$$FastClassBySpringCGLIB$$6ae593d3.invoke(<generated>) at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:738) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:52) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:673) at com.hzcf.api.task.controller.TaskPublicController$$EnhancerBySpringCGLIB$$a9f3b67.batch(<generated>) at sun.reflect.GeneratedMethodAccessor118.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872) at javax.servlet.http.HttpServlet.service(HttpServlet.java:661) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846) at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129) at org.springframework.boot.web.filter.ApplicationContextHeaderFilter.doFilterInternal(ApplicationContextHeaderFilter.java:55) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at com.hzcf.security.filter.AuthenticationFilter.doFilter(AuthenticationFilter.java:61) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:110) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:108) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:81) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at org.springframework.cloud.sleuth.instrument.web.TraceFilter.doFilter(TraceFilter.java:164) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at org.springframework.boot.actuate.autoconfigure.MetricsFilter.doFilterInternal(MetricsFilter.java:106) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84) at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62) at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:64) at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36) at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131) at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46) at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64) at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60) at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77) at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.server.handlers.GracefulShutdownHandler.handleRequest(GracefulShutdownHandler.java:69) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292) at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81) at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138) at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135) at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48) at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43) at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272) at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81) at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104) at io.undertow.server.Connectors.executeRootHandler(Connectors.java:336) at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830) 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) |
- 查看0x000000008391a738被谁锁住,搜索0x000000008391a738,发现被ChannelN.basicAck(ChannelN.java:1138)锁住,此线程正在接收MQ的消息并ack,他们使用了同一个Socket中的outputstream,所以并发会有问题。
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 |
"MQ-Connection-25" #53 daemon prio=5 os_prio=0 tid=0x000000001e185800 nid=0x5ea4 runnable [0x00000000262fe000] java.lang.Thread.State: RUNNABLE at java.net.SocketOutputStream.socketWrite0(Native Method) at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111) at java.net.SocketOutputStream.write(SocketOutputStream.java:155) at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82) at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140) <span style="color: #ff0000;">#锁住0x000000008391a758 - locked <0x000000008391a758> (a java.io.BufferedOutputStream)</span> at java.io.DataOutputStream.flush(DataOutputStream.java:123) at com.rabbitmq.client.impl.SocketFrameHandler.flush(SocketFrameHandler.java:159) at com.rabbitmq.client.impl.AMQConnection.flush(AMQConnection.java:532) at com.rabbitmq.client.impl.AMQCommand.transmit(AMQCommand.java:127) at com.rabbitmq.client.impl.AMQChannel.quiescingTransmit(AMQChannel.java:337) #锁住0x0000000083426668 - locked <0x0000000083426668> (a java.lang.Object) at com.rabbitmq.client.impl.AMQChannel.transmit(AMQChannel.java:313) - locked <0x0000000083426668> (a java.lang.Object) at com.rabbitmq.client.impl.AMQChannel.transmit(AMQChannel.java:306) - locked <0x0000000083426668> (a java.lang.Object) at com.rabbitmq.client.impl.ChannelN.basicAck(ChannelN.java:1138) at com.hzcf.api.components.rabbitMq.RabbitMqConsumer.handleDelivery(RabbitMqConsumer.java:59) at com.rabbitmq.client.impl.ConsumerDispatcher$5.run(ConsumerDispatcher.java:149) at com.rabbitmq.client.impl.ConsumerWorkService$WorkPoolRunnable.run(ConsumerWorkService.java:100) 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) |
实例2
等待另一个条件发生来将自己唤醒:
1 2 3 4 5 6 7 8 9 10 |
RMI TCP Connection(idle)" daemon prio=10 tid=0x00007fd50834e800 nid=0x56b2 waiting on condition [0x00007fd4f1a59000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000acd84de8> (a java.util.concurrent.SynchronousQueue$TransferStack) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:874) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:945) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907) |
1)“TIMED_WAITING (parking)”中的 timed_waiting 指等待状态,但这里指定了时间,到达指定的时间后自动退出等待状态;parking指线程处于挂起中。
2)“waiting on condition”需要与堆栈中的“parking to wait for <0x00000000acd84de8> (a java.util.concurrent.SynchronousQueue$TransferStack)” 结合来看。首先,本线程肯定是在等待某个条件的发生,来把自己唤醒。其次,SynchronousQueue 并不是一个队列,只是线程之间移交信息的机制,当我们把一个元素放入到 SynchronousQueue 中时必须有另一个线程正在等待接受移交的任务,因此这就是本线程在等待的条件。
©版权声明:本文为【翰林小院】(huhanlin.com)原创文章,转载时请注明出处!
发表评论