有一个新项目,在测试环境部署后,发现tomcat进程耗费的CPU非常高,排查过程如下:
日志搜集
先通过top,查找耗费CPU最高的线程
top -Hp pid
将线程ID转为16进制
printf "%x " 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连接参数,误配置成了正式环境的参数;而测试环境和正式环境的网络是隔离的,无法连通,因此出现该问题。