有一個新項目,在測試環境部署后,發現tomcat進程耗費的CPU非常高,排查過程如下:
日志搜集
先通過top,查找耗費CPU最高的線程
top -Hp pid
將線程ID轉為16進制
printf "%x\n" threadid
搜集JVM的棧日志
jstack pid > ~/jvm.stack.log
通過線程的16進制標識,定位JVM棧信息
grep -rn threadTag ~/jvm.stack.log -A 100
原因分析
通過上面的操作,定位到具體的線程棧日志,如下:
"pool-8-thread-1" #253 prio=5 os_prio=0 tid=0x00007f538096f000 nid=0x7fdb runnable [0x00007f5363af8000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.IOUtil.drain(Native Method)
at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:104)
- locked <0x00000000f36f0960> (a java.lang.Object)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
- locked <0x00000000f36f0750> (a sun.nio.ch.Util$3)
- locked <0x00000000f36f0740> (a java.util.Collections$UnmodifiableSet)
- locked <0x00000000f36f0558> (a sun.nio.ch.EPollSelectorImpl)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
at org.apache.kafka.common.network.Selector.select(Selector.java:470)
at org.apache.kafka.common.network.Selector.poll(Selector.java:286)
at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:260)
at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232)
- locked <0x00000000f37037e8> (a org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient)
at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:209)
at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.awaitMetadataUpdate(ConsumerNetworkClient.java:148)
at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.awaitMetadataUpdate(ConsumerNetworkClient.java:136)
at org.apache.kafka.clients.consumer.internals.AbstractCoordinator.ensureCoordinatorReady(AbstractCoordinator.java:197)
- locked <0x00000000f3703820> (a org.apache.kafka.clients.consumer.internals.ConsumerCoordinator)
at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.poll(ConsumerCoordinator.java:248)
at org.apache.kafka.clients.consumer.KafkaConsumer.pollOnce(KafkaConsumer.java:1013)
// 可以看到是kafka的poll出現問題了,觸發locked
at org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:979)
at com.myhexin.kiv.service.impl.SyncTemplateServiceImpl.receiver(SyncTemplateServiceImpl.java:65)
at com.myhexin.kiv.job.SchedulerAllJob.registerJobs(SchedulerAllJob.java:105)
at com.myhexin.kiv.job.SchedulerAllJob.scheduleJobs(SchedulerAllJob.java:68)
at com.myhexin.kiv.job.SchedulerListener.schedule(SchedulerListener.java:37)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:65)
at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:81)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
從上面的日志可以看出,是kafka的poll出現問題了,觸發locked。然后經排查,發現是我們將測試環境的kafka連接參數,誤配置成了正式環境的參數;而測試環境和正式環境的網絡是隔離的,無法連通,因此出現該問題。