Blog Logo
  • Home
  • SACC2013
  • Categories
  • Tags
  • About
  • Feed

在Docker内定位使用CPU过高的Java进程

by Ruanjf — on java jvm linux docker 04 Jan 2018

当访问应用需要很长时间才响应时可以登录到系统上使用top命令查看CPU使用情况,如果发现CPU使用过高则可以通过下面所讲的方法定位问题。本文将介绍如何定位Docker内使用CPU过高的Java进程

首先,通过top命令找到CPU使用过高的进程(如:7152),如下信息已忽略top的头信息

 PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
7152 root      20   0 1668880 308248   4640 S  1.3 16.4   8:14.01 java
1390 root      20   0  129848   7080   1708 S  0.3  0.4 153:43.35 AliYunDun
2451 root      20   0  166704   4548    440 S  0.3  0.2  30:11.21 ilogtail
2509 root      20   0  134896   2788      0 S  0.3  0.1   1:16.78 docker-containe

确定进程信息

判断该进程是否在Docker容器中(如果有在则找出对于的容器)有两种方式

  • 使用cat /proc/7152/cgroup查看打印内容是否包含:/docker/。原理是Docker使用了Linux cgroups

      11:memory:/docker/b7a84996139a834966df09d10b8a50082b5043153f633f5f5fd2638de0ebc206
      10:hugetlb:/docker/b7a84996139a834966df09d10b8a50082b5043153f633f5f5fd2638de0ebc206
      9:cpuset:/docker/b7a84996139a834966df09d10b8a50082b5043153f633f5f5fd2638de0ebc206
      8:cpuacct,cpu:/docker/b7a84996139a834966df09d10b8a50082b5043153f633f5f5fd2638de0ebc206
      7:perf_event:/docker/b7a84996139a834966df09d10b8a50082b5043153f633f5f5fd2638de0ebc206
      6:freezer:/docker/b7a84996139a834966df09d10b8a50082b5043153f633f5f5fd2638de0ebc206
      5:devices:/docker/b7a84996139a834966df09d10b8a50082b5043153f633f5f5fd2638de0ebc206
      4:net_prio,net_cls:/docker/b7a84996139a834966df09d10b8a50082b5043153f633f5f5fd2638de0ebc206
      3:blkio:/docker/b7a84996139a834966df09d10b8a50082b5043153f633f5f5fd2638de0ebc206
      2:pids:/docker/b7a84996139a834966df09d10b8a50082b5043153f633f5f5fd2638de0ebc206
      1:name=systemd:/docker/b7a84996139a834966df09d10b8a50082b5043153f633f5f5fd2638de0ebc206
    

    如果有打印docker信息则可以通过docker inspect --format ' b7a849961查询到容器的名称,其中b7a849961为容器id的前几个字符

  • 使用pstree -s 7152查看打印的进程树是否包含docker-containe,显示信息如下:

      systemd(1)───docker(1101)───docker-containe(1447)───docker-containe(7088)───entrypoint.sh(7099)───java(7152)─┬─{java}(7177)
    

    其中只显示了第一行,后面包含多个线程未显示出来 如果有包含docker-containe则可以通过docker ps -q | xargs docker inspect --format ' ' |grep 7099显示出容器名称,其中7099为容器进程ID

如果是非Docker容器进程则可以通过ps -ef |grep 7152查看进程启动信息,以确定具体的应用。

确定进程中的线程CPU使用情况

通过top -H -p 7152,如下信息已忽略top的头信息

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
27603 root      20   0 1669908 308540   4580 S  4.7 16.4   0:00.43 java
 7182 root      20   0 1669908 308540   4580 S  0.3 16.4   0:16.46 java
27602 root      20   0 1669908 308540   4580 S  0.3 16.4   0:13.82 java
 7152 root      20   0 1669908 308540   4580 S  0.0 16.4   0:00.01 java
 7177 root      20   0 1669908 308540   4580 S  0.0 16.4   0:16.04 java

或者ps -To pcpu,tid,pid,user 7152 |sort -r -k1 |more

%CPU   TID   PID USER
 6.3  7234  7152 root
 0.0  8715  7152 root
 0.0  8650  7152 root
 0.0  8563  7152 root
 0.0  8558  7152 root

找出CPU使用过高的线程ID(如:7234)。

注意,如果是在Docker中的容器的话需要进入到对应的容器中否则执行出来的线程ID将不对应,无法匹配后续的信息。可以通过docker exec -it b7a849961 ps -ef列出容器内部的进程列表(由于容器基本上是单进程或者少数几个进程可以很方便的辨认出对于的需要查看的进程),打印信息如下:

UID        PID  PPID  C STIME TTY          TIME CMD
root         1     0  0 Mar02 ?        00:00:00 /bin/sh /sbin/entrypoint.sh
root         5     1  0 Mar02 ?        00:08:44 /usr/lib/jvm/java-7-openjdk-amd6
root        90     0  0 16:16 ?        00:00:00 ps -ef

通过观察发现进程号为5因此修改上面的命令为docker exec -it b7a849961 top -H -p 5或者docker exec -it b7a849961 ps -To pcpu,tid,pid,user 5 |sort -r -k1 |more这时可打印类似上面的结果

%CPU   TID   PID USER
 9.3    26     5 root
 0.0    66     5 root
 0.0    65     5 root
 0.0    63     5 root
 0.0    62     5 root
 0.0    56     5 root
 0.0     5     5 root
 0.0    54     5 root

这时可找出CPU使用过高的线程ID(如:26)。

进行Jvm线程Dump

通过Jvm线程Dump可以查出线程对应的Class,从而达到定位Java代码的作用

这里介绍两种进行线程Dump的方法

  • 通过jstack命令,使用jstack -l <pid>将结果输出到控制台,如果想将内容保存到文件中请使用jstack -l <pid> > jstack_$(date "+%Y%m%d%H%M%S").txt,其中<pid>为进程ID。如果机器只安装了jre可能不存在jstack命令,那你可以通过下面的方式。

  • 通过kill命令,使用kill -3 <pid>将结果输出到默认的日志文件中,如果在Docker容器内日志可能被接管了,这时可以通过docker logs b7a849961查看如果想输出到文件中可以使用docker logs b7a849961 >& b7a849961_$(date "+%Y%m%d%H%M%S").log

打印的日志信息如下:

"org.springframework.jms.listener.DefaultMessageListenerContainer#0-1" prio=10 tid=0x00007f0ad4baa800 nid=0x1a runnable [0x00007f0aae3e8000]
   java.lang.Thread.State: RUNNABLE
	at org.apache.qpid.amqp_1_0.client.Receiver.receive(Receiver.java:264)
	at org.apache.qpid.amqp_1_0.jms.impl.MessageConsumerImpl.receive0(MessageConsumerImpl.java:306)
	at org.apache.qpid.amqp_1_0.jms.impl.MessageConsumerImpl.receiveImpl(MessageConsumerImpl.java:275)
	at org.apache.qpid.amqp_1_0.jms.impl.MessageConsumerImpl.receive(MessageConsumerImpl.java:258)
	at org.apache.qpid.amqp_1_0.jms.impl.MessageConsumerImpl.receive(MessageConsumerImpl.java:58)
	at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveMessage(AbstractPollingMessageListenerContainer.java:413)
	at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.doReceiveAndExecute(AbstractPollingMessageListenerContainer.java:293)
	at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:246)
	at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:1142)
	at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.executeOngoingLoop(DefaultMessageListenerContainer.java:1134)
	at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:1031)
	at java.lang.Thread.run(Thread.java:745)

接下来将上一节中获取到线程ID26转化为16进制数(如果需要将16进制转为10进制可以使用echo $((16#1a))),可以使用命令echo "obase=16;ibase=10;26" | bc | tr '[:upper:]' '[:lower:]'得到结果1a。通过查找之前保存的日志中的nid=0x1a可以找到对应的线程所执行的代码以及线程的状态,如果在Linux下可以使用命令grep -n -A 15 nid=0x1a jstack_20180104112345.txt快速定位到对应的线程。

Windows下操作

  • 查看CPU,可以使用任务管理器
  • 查看线程,可以使用Process Explorer,如图

    显示线程信息

  • 进制转换,可以使用计算器(快捷键Win + R启动运行窗口然后输入calc,接着依次按下Alt、V、S切换到科学型)

参考

线程Dump

Process Explorer

Ruanjf Author

Ruanjf

ruanjiefeng@gmail.com

是我,这就是我

Comments

comments powered by Disqus
All content copyright Ruanjf © 2020 • All rights reserved.
Proudly published with Jekyll on Tuesday, 05 May 2020 at 05:34 PM UTC