龙空技术网

为什么应用容器化后,启动慢了很多?

弈秋的美好生活 1092

前言:

而今各位老铁们对“docker java oom”都比较注意,各位老铁们都想要知道一些“docker java oom”的相关文章。那么小编也在网上收集了一些关于“docker java oom””的相关资讯,希望兄弟们能喜欢,朋友们快快来了解一下吧!

目录

案例准备

案例分析

启动服务

访问服务

查看日志

查询容器的状态

操作系统层面查看OOM

重启容器并查看java堆内存大小

如何解决?

启动tomcat需要21s正常吗?

top查看性能

pidstat查看具体进程

小结

随着 Kubernetes、Docker 等技术的普及,越来越多的企业,都已经走上了应用程序容器化的道路。我相信,你在了解学习这些技术的同时,一定也听说过不少,基于 Docker 的微服务架构带来的各种优势,比如:

使用 Docker ,把应用程序以及相关依赖打包到镜像中后,部署和升级更快捷;把传统的单体应用拆分成多个更小的微服务应用后,每个微服务的功能都更简单,并且可以单独管理和维护;每个微服务都可以根据需求横向扩展。即使发生故障,也只是局部服务不可用,而不像以前那样,导致整个服务不可用。

不过,任何技术都不是银弹。这些新技术,在带来诸多便捷功能之外,也带来了更高的复杂性,比如性能降低、架构复杂、排错困难等等。

今天,我就通过一个 Tomcat 案例,带你一起学习,如何分析应用程序容器化后的性能问题。

案例准备

vagrant 拉起的虚拟机

机器配置:1 CPU,2GB 内存。预先安装 docker、curl、jq、pidstat 等工具

其中,jq 工具专门用来在命令行中处理 json。为了更好的展示 json 数据,我们用这个工具,来格式化 json 输出。

案例分析

我们今天要分析的案例,是一个 Tomcat 应用。Tomcat 是 Apache 基金会旗下,Jakarta 项目开发的轻量级应用服务器,它基于 Java 语言开发。Docker 社区也维护着 Tomcat 的官方镜像,你可以直接使用这个镜像,来启动一个 Tomcat 应用。

我们的案例,也基于 Tomcat 的官方镜像构建,其核心逻辑很简单,就是分配一点儿内存,并输出 “Hello, world!”。

<%byte data[] = new byte[256*1024*1024];out.println("Hello, wolrd!");%>

启动服务

[root@hadoop100 /opt]#docker run --name tomcat --cpus 0.1 -m 128M -p 8080:8080 -itd feisky/tomcat:8c3064a28fdf8e1606b2e5ceb84b0808d547fe274ce87cbd2781c844cdd0de9aa

根据服务器配置调整cgroup分配的内存。

访问服务

观察一会儿,可以看到,一段时间后,curl 终于给出了我们想要的结果 “Hello, wolrd!”。但是,随后又出现了 “Empty reply from server” ,和一直持续的 “Connection refused” 错误。换句话说,Tomcat 响应一次请求后,就再也不响应了。

 /opt]#for ((i=1; i<=30; i++));do curl 192.168.56.10:8080; sleep 1s; donecurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (52) Empty reply from servercurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refusedcurl: (7) Failed connect to 192.168.56.10:8080; Connection refused

查看日志

docker logs

[root@hadoop100 ~]#docker logs -f tomcatUsing CATALINA_BASE:   /usr/local/tomcatUsing CATALINA_HOME:   /usr/local/tomcatUsing CATALINA_TMPDIR: /usr/local/tomcat/tempUsing JRE_HOME:        /docker-java-home/jreUsing CLASSPATH:       /usr/local/tomcat/bin/bootstrap.jar:/usr/local/tomcat/bin/tomcat-juli.jar10-Feb-2022 08:59:37.189 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.3810-Feb-2022 08:59:37.381 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Feb 5 2019 11:42:42 UTC10-Feb-2022 08:59:37.382 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.5.38.010-Feb-2022 08:59:37.382 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux10-Feb-2022 08:59:37.382 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            3.10.0-1160.36.2.el7.x86_6410-Feb-2022 08:59:37.382 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd6410-Feb-2022 08:59:37.382 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /usr/lib/jvm/java-8-openjdk-amd64/jre10-Feb-2022 08:59:37.382 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_181-8u181-b13-2~deb9u1-b1310-Feb-2022 08:59:37.382 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation10-Feb-2022 08:59:37.382 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /usr/local/tomcat10-Feb-2022 08:59:37.383 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/local/tomcat10-Feb-2022 08:59:37.383 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties10-Feb-2022 08:59:37.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager10-Feb-2022 08:59:37.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=204810-Feb-2022 08:59:37.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources10-Feb-2022 08:59:37.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=002710-Feb-2022 08:59:37.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=10-Feb-2022 08:59:37.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat10-Feb-2022 08:59:37.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat10-Feb-2022 08:59:37.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp10-Feb-2022 08:59:37.481 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded APR based Apache Tomcat Native library [1.2.21] using APR version [1.5.2].10-Feb-2022 08:59:37.482 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].10-Feb-2022 08:59:37.482 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]10-Feb-2022 08:59:37.581 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 1.1.0j  20 Nov 2018]10-Feb-2022 08:59:39.987 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]10-Feb-2022 08:59:40.487 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read10-Feb-2022 08:59:40.984 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"]10-Feb-2022 08:59:41.085 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read10-Feb-2022 08:59:41.180 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 25094 ms10-Feb-2022 08:59:41.588 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]10-Feb-2022 08:59:41.588 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.3810-Feb-2022 08:59:42.384 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/ROOT]10-Feb-2022 08:59:51.287 WARNING [localhost-startStop-1] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [206] milliseconds.10-Feb-2022 08:59:51.684 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/ROOT] has finished in [9,300] ms10-Feb-2022 08:59:51.684 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/docs]10-Feb-2022 08:59:52.185 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/docs] has finished in [501] ms10-Feb-2022 08:59:52.185 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/examples]10-Feb-2022 09:00:00.085 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/examples] has finished in [7,900] ms10-Feb-2022 09:00:00.085 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/host-manager]10-Feb-2022 09:00:00.684 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/host-manager] has finished in [598] ms10-Feb-2022 09:00:00.684 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/manager]10-Feb-2022 09:00:01.487 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/manager] has finished in [803] ms10-Feb-2022 09:00:01.687 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]10-Feb-2022 09:00:01.988 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]10-Feb-2022 09:00:02.283 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 21102 ms

从内容上可以看到,Tomcat 在启动 21s 后完成初始化,并且正常启动。从日志上来看,没有什么问题。

不过,细心的你肯定注意到了最后一行,明显是回到了 Linux 的 SHELL 终端中,而没有继续等待 Docker 输出的容器日志。

输出重新回到 SHELL 终端,通常表示上一个命令已经结束。而我们的上一个命令,是 docker logs -f 命令。那么,它的退出就只有两种可能了,要么是容器退出了,要么就是 dockerd 进程退出了。

究竟是哪种情况呢?这就需要我们进一步确认了。我们可以在终端一中,执行下面的命令,查看容器的状态:

[root@hadoop100 /opt]#docker ps -aCONTAINER ID   IMAGE             COMMAND             CREATED         STATUS                       PORTS     NAMESc3064a28fdf8   feisky/tomcat:8   "catalina.sh run"   8 minutes ago   Exited (137) 7 minutes ago             tomcat

查询容器的状态

你会看到,容器处于 Exited 状态,说明是第一种情况,容器已经退出。不过为什么会这样呢?显然,在前面容器的日志里,我们并没有发现线索,那就只能从 Docker 本身入手了。

[root@hadoop100 /opt]#docker inspect tomcat -f '{{json .State}}' | jq{  "Status": "exited",  "Running": false,  "Paused": false,  "Restarting": false,  "OOMKilled": true,  "Dead": false,  "Pid": 0,  "ExitCode": 137,  "Error": "",  "StartedAt": "2022-02-10T08:59:12.485543342Z",  "FinishedAt": "2022-02-10T09:00:27.213292165Z"}

这次你可以看到,容器已经处于 exited 状态,OOMKilled 是 true,ExitCode 是 137。这其中,OOMKilled 表示容器被 OOM 杀死了。

我们前面提到过,OOM 表示内存不足时,某些应用会被系统杀死。可是,为什么内存会不足呢?我们的应用分配了 256 MB 的内存,而容器启动时,明明通过 -m 选项,设置了 512 MB 的内存,按说应该是足够的。

操作系统层面查看OOM

当 OOM 发生时,系统会把相关的 OOM 信息,记录到日志中。所以,接下来,我们可以在终端中执行 dmesg 命令,查看系统日志,并定位 OOM 相关的日志:

[1136990.229993] java invoked oom-killer: gfp_mask=0xd0, order=0, oom_score_adj=0[1136990.237893] java cpuset=c3064a28fdf8e1606b2e5ceb84b0808d547fe274ce87cbd2781c844cdd0de9aa mems_allowed=0[1136990.245070] CPU: 0 PID: 9817 Comm: java Tainted: G        W  OE  ------------ T 3.10.0-1160.36.2.el7.x86_64 #1[1136990.255217] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006[1136990.257927] Call Trace:[1136990.259424]  [<ffffffff85583559>] dump_stack+0x19/0x1b[1136990.260871]  [<ffffffff8557e5f8>] dump_header+0x90/0x229[1136990.262437]  [<ffffffff8509d968>] ? ep_poll_callback+0xf8/0x220[1136990.264049]  [<ffffffff84fc1fc6>] ? find_lock_task_mm+0x56/0xc0[1136990.265534]  [<ffffffff8503d288>] ? try_get_mem_cgroup_from_mm+0x28/0x60[1136990.268505]  [<ffffffff84fc252d>] oom_kill_process+0x2cd/0x490[1136990.270999]  [<ffffffff8510f25c>] ? selinux_capable+0x1c/0x40[1136990.272588]  [<ffffffff8504167c>] mem_cgroup_oom_synchronize+0x55c/0x590[1136990.274919]  [<ffffffff85040ae0>] ? mem_cgroup_charge_common+0xc0/0xc0[1136990.277221]  [<ffffffff84fc2e14>] pagefault_out_of_memory+0x14/0x90[1136990.278936]  [<ffffffff8557cb35>] mm_fault_error+0x6a/0x157[1136990.282209]  [<ffffffff855908d1>] __do_page_fault+0x491/0x500[1136990.286043]  [<ffffffff85590975>] do_page_fault+0x35/0x90[1136990.287597]  [<ffffffff8558cac9>] ? error_swapgs+0xaa/0xc0[1136990.289074]  [<ffffffff8558c778>] page_fault+0x28/0x30[1136990.290658] Task in /docker/c3064a28fdf8e1606b2e5ceb84b0808d547fe274ce87cbd2781c844cdd0de9aa killed as a result of limit of /docker/c3064a28fdf8e1606b2e5ceb84b0808d547fe274ce87cbd2781c844cdd0de9aa[1136990.295345] memory: usage 131004kB, limit 131072kB, failcnt 24049[1136990.299530] memory+swap: usage 262144kB, limit 262144kB, failcnt 9[1136990.301239] kmem: usage 0kB, limit 9007199254740988kB, failcnt 0[1136990.302828] Memory cgroup stats for /docker/c3064a28fdf8e1606b2e5ceb84b0808d547fe274ce87cbd2781c844cdd0de9aa: cache:16KB rss:130992KB rss_huge:0KB mapped_file:4KB swap:131136KB inactive_anon:65548KB active_anon:65444KB inactive_file:12KB active_file:4KB unevictable:0KB[1136990.541127] [ pid ]   uid  tgid total_vm      rss nr_ptes swapents oom_score_adj name[1136990.542939] [ 9380]     0  9380   623636    35397     205    33151             0 java[1136990.544756] Memory cgroup out of memory: Kill process 9842 (java) score 1049 or sacrifice child[1136990.546634] Killed process 9380 (java), UID 0, total-vm:2494544kB, anon-rss:126448kB, file-rss:15140kB, shmem-rss:0kB[1136991.835588] docker0: port 1(veth574ca5f) entered disabled state[1136991.847573] docker0: port 1(veth574ca5f) entered disabled state[1136991.849892] device veth574ca5f left promiscuous mode[1136991.850558] docker0: port 1(veth574ca5f) entered disabled state

从 dmesg 的输出,你就可以看到很详细的 OOM 记录了。你应该可以看到下面几个关键点。

第一,被杀死的是一个 java 进程。从内核调用栈上的 mem_cgroup_out_of_memory 可以看出,它是因为超过 cgroup 的内存限制,而被 OOM 杀死的。第二,java 进程是在容器内运行的,而容器内存的使用量和限制都是 512M(524288kB)。目前使用量已经达到了限制,所以会导致 OOM。

2494544kB, anon-rss:126448kB, file-rss:15140kB,

第三,被杀死的进程,PID 为 9380,

虚拟内存为 2.37G(total-vm:2494544kB匿名内存为 123M(anon-rss:126448kB页内存为 14M(15140kB

换句话说,匿名内存是主要的内存占用。而且,匿名内存加上页内存,总共是 137M,已经超过了 128M 的限制。

综合这几点,可以看出,Tomcat 容器的内存主要用在了匿名内存中,而匿名内存,其实就是主动申请分配的堆内存。

重启容器并查看java堆内存大小

为什么 Tomcat 会申请这么多的堆内存呢?要知道,Tomcat 是基于 Java 开发的,所以应该不难想到,这很可能是 JVM 堆内存配置的问题。

我们知道,JVM 根据系统的内存总量,来自动管理堆内存,不明确配置的话,堆内存的默认限制是物理内存的四分之一。

不过,前面我们已经限制了容器内存为 512 M,java 的堆内存到底是多少呢?

我们继续在终端中,执行下面的命令,重新启动 tomcat 容器,并调用 java 命令行来查看堆内存大小:

[root@hadoop100 /opt]#docker run --name tomcat --cpus 0.1 -m 128M -p 8080:8080 -itd feisky/tomcat:8e5f74747154af6186c4913a8df55a319d8db3111ecc5c29792fb013621833288You have mail in /var/spool/mail/root[root@hadoop100 /opt]#[root@hadoop100 /opt]#[root@hadoop100 /opt]#docker exec tomcat java -XX:+PrintFlagsFinal -version | grep HeapSize    uintx ErgoHeapSizeLimit                         = 0                                   {product}    uintx HeapSizePerGCThread                       = 87241520                            {product}    uintx InitialHeapSize                          := 31457280                            {product}    uintx LargePageHeapSizeThreshold                = 134217728                           {product}    uintx MaxHeapSize                              := 482344960                           {product}openjdk version "1.8.0_181"OpenJDK Runtime Environment (build 1.8.0_181-8u181-b13-2~deb9u1-b13)OpenJDK 64-Bit Server VM (build 25.181-b13, mixed mode)

查看堆内存,注意单位是字节

你可以看到,初始堆内存的大小(InitialHeapSize)是 30MB,而最大堆内存则是 460MB,这可比容器限制的 128 MB 大多了。

之所以会这么大,其实是因为,容器内部看不到 Docker 为它设置的内存限制。虽然在启动容器时,我们通过 -m 128M 选项,给容器设置了 128M 的内存限制。

但实际上,从容器内部看到的限制,却并不是 128M。

这个最大堆内存460MB咋来的呢?

刚好 堆内存的默认限制是物理内存的四分之一。

如何解决?

通过环境变量 JAVA_OPTS=’-Xmx128m -Xms128m’ ,把 JVM 的初始内存和最大内存都设为 128MB:

$ docker run --name tomcat --cpus 0.1 -m 512M -e JAVA_OPTS='-Xmx128m -Xms128m' -p 8080:8080 -itd feisky/tomcat:8

启动tomcat需要21s正常吗?

启动过程,居然需要 22 秒,这也太慢了吧。

由于这个时间是花在容器启动上的,要排查这个问题,我们就要重启容器,并借助性能分析工具来分析容器进程。至于工具的选用,回顾一下我们前面的案例,我觉得可以先用 top 看看。

我们切换到终端二中,运行 top 命令;然后再切换到终端一,执行下面的命令,重启容器:

[root@hadoop100 /opt]#docker rm -f tomcattomcat[root@hadoop100 /opt]#[root@hadoop100 /opt]#[root@hadoop100 /opt]#docker run --name tomcat --cpus 0.1 -m 512M -e JAVA_OPTS='-Xmx512m -Xms512m' -p 8080:8080 -itd feisky/tomcat:8

top查看性能

看不出有啥问题。

pidstat查看具体进程

pidstat -t -p 8372 1

如果你观察不到这些指标可以使用docker 命令获取java进程。作为变量传递给pidstat

# 删除旧容器$ docker rm -f tomcat# 运行新容器$ docker run --name tomcat --cpus 0.1 -m 512M -e JAVA_OPTS='-Xmx512m -Xms512m' -p 8080:8080 -itd feisky/tomcat:8# 查询新容器中进程的 Pid$ PID=$(docker inspect tomcat -f '{{.State.Pid}}')# 执行 pidstat$ pidstat -t -p $PID 1

仔细观察这次的输出,你会发现,虽然 CPU 使用率(%CPU)很低,但等待运行的使用率(%wait)却非常高,最高甚至已经达到了 97%。这说明,这些线程大部分时间都在等待调度,而不是真正的运行。

注:如果你看不到 %wait 指标,请先升级 sysstat 后再试试。

为什么 CPU 使用率这么低,线程的大部分时间还要等待 CPU 呢?由于这个现象因 Docker 而起,自然的,你应该想到,这可能是因为 Docker 为容器设置了限制。

再回顾一下,案例开始时容器的启动命令。我们用 --cpus 0.1 ,为容器设置了 0.1 个 CPU 的限制,也就是 10% 的 CPU。这里也就可以解释,为什么 java 进程只有 10% 的 CPU 使用率,也会大部分时间都在等待了。

找出原因,最后的优化也就简单了,把 CPU 限制增大就可以了。比如,你可以执行下面的命令,将 CPU 限制增大到 1 ;然后再重启,并观察启动日志:

/opt]#docker run --name tomcat --cpus 1 -m 512M -e JAVA_OPTS='-Xmx512m -Xms512m' -p 8080:8080 -itd feisky/tomcat:8

现在可以看到,Tomcat 的启动过程,只需要 2 秒就完成了,果然比前面的 22 秒快多了 。

虽然我们通过增大 CPU 的限制,解决了这个问题。不过再碰到类似问题,你可能会觉得这种方法太麻烦了。因为要设置容器的资源限制,还需要我们预先评估应用程序的性能。显然还有更简单的方法,比如说直接去掉限制,让容器跑就是了。

不过,这种简单方法,却很可能带来更严重的问题。没有资源限制,就意味着容器可以占用整个系统的资源。这样,一旦任何应用程序发生异常,都有可能拖垮整台机器。

实际上,这也是在各大容器平台上最常见的一个问题。一开始图省事不设限,但当容器数量增长上来的时候,就会经常出现各种异常问题。最终查下来,可能就是因为某个应用资源使用过高,导致整台机器短期内无法响应。只有设置了资源限制,才能确保杜绝类似问题。

小结

这个问题应该是/proc 文件系统并不知道用户通过 Cgroups 给这个容器做了限制导致的

如果你在 Docker 容器中运行 Java 应用,一定要确保,在设置容器资源限制的同时,配置好 JVM 的资源选项(比如堆内存等)。当然,如果你可以升级 Java 版本,那么升级到 Java 10 ,就可以自动解决类似问题了。

当碰到容器化的应用程序性能时,你依然可以使用,我们前面讲过的各种方法来分析和定位。只不过要记得,容器化后的性能分析,跟前面内容稍微有些区别,比如下面这几点。

容器本身通过 cgroups 进行资源隔离,所以,在分析时要考虑 cgroups 对应用程序的影响。容器的文件系统、网络协议栈等跟主机隔离。虽然在容器外面,我们也可以分析容器的行为,不过有时候,进入容器的命名空间内部,可能更为方便。容器的运行可能还会依赖于其他组件,比如各种网络插件(比如 CNI)、存储插件(比如 CSI)、设备插件(比如 GPU)等,让容器的性能分析更加复杂。如果你需要分析容器性能,别忘了考虑它们对性能的影响。

标签: #docker java oom