最后我们就可以查询占用 CPU 最高的线程的线程栈日志了。 首先把 top -Hp PID 命令中查询出来的占用 CPU 最高的线程栈 ID 转为十六进制数 然后使用这个十六进制数在 thread_jstack.log日志中搜索即可,会匹配到日志中 nid 这里的值。 日志中会详细的把线程名称、状态以及对应的代码打印出来,这样就能够知道是哪块的代码占用了大量 CPU,从而有针对性的排查问题了
"http-nio-8412-exec-7" Id=88 cpuUsage=59.46% deltaTime=159ms time=17460ms TIMED_WAITING 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 com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:101) at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:144) at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:174) at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3011) at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3472) at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3462) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3905) at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2530) //省略详细堆栈日志
$ thread -b "http-bio-8080-exec-4" Id=27 TIMED_WAITING at java.lang.Thread.sleep(Native Method) at test.arthas.TestThreadBlocking.doGet(TestThreadBlocking.java:22) - locked java.lang.Object@725be470 <---- but blocks 4 other threads! at javax.servlet.http.HttpServlet.service(HttpServlet.java:624) at javax.servlet.http.HttpServlet.service(HttpServlet.java:731) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) at test.filter.TestDurexFilter.doFilter(TestDurexFilter.java:46) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505) at com.taobao.tomcat.valves.ContextLoadFilterValve$FilterChainAdapter.doFilter(ContextLoadFilterValve.java:191) at com.taobao.eagleeye.EagleEyeFilter.doFilter(EagleEyeFilter.java:81) at com.taobao.tomcat.valves.ContextLoadFilterValve.invoke(ContextLoadFilterValve.java:150) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:429) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1085) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625) at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:318) - locked org.apache.tomcat.util.net.SocketWrapper@7127ee12 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:745)
Number of locked synchronizers = 1 - java.util.concurrent.ThreadPoolExecutor$Worker@31a6493e