伴随着微服务和云原生的普及,现在越来越多的企业都走上了容器化的道路,使用K8S和Docker管理应用程序
使用Docker,也有着一定的好处
比如使用Docker,将应用程序和依赖直接打包到镜像中,方便部署
单体应用进行拆分,导致每个微服务可以单独的管理和维护
每个微服务都可以进行横向扩展
不过,Docker也带来了一定的性能问题,我们拿一个案例进行相关的讲解和学习
我们直接启动一个特定的Docker容器
我们启动Tomcat容器,监听8080端口
| # -m表示设置内存为512MB
$ docker run –name tomcat –cpus 0.1 -m 512M -p 8080:8080 -itd feisky/tomcat:8 Unable to find image ‘feisky/tomcat:8’ locally 8: Pulling from feisky/tomcat 741437d97401: Pull complete … 22cd96a25579: Pull complete Digest: sha256:71871cff17b9043842c2ec99f370cc9f1de7bc121cd2c02d8e2092c6e268f7e2 Status: Downloaded newer image for feisky/tomcat:8 WARNING: Your kernel does not support swap limit capabilities or the cgroup is not mounted. Memory limited without swap. 2df259b752db334d96da26f19166d662a82283057411f6332f3cbdbcab452249 |
尝试访问8080端口,确定已经成功启动
但是不出意外,在这个容器启动的时候,会启动失败
我们尝试看一下对应的docker log,查看问题
docker logs 查看日志,不过需要加上-f参数
| $ docker logs -f tomcat
Using CATALINA_BASE: /usr/local/tomcat Using CATALINA_HOME: /usr/local/tomcat Using CATALINA_TMPDIR: /usr/local/tomcat/temp Using JRE_HOME: /docker-java-home/jre Using CLASSPATH: /usr/local/tomcat/bin/bootstrap.jar:/usr/local/tomcat/bin/tomcat-juli.jar |
很有可能返回的是容器还在启动中,在不断的ping中,会在一定时间后发现初始化完成
但是仔细查看容器的状态
会发现容器处于了Exited状态
| $ docker ps -a
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 0f2b3fcdd257 feisky/tomcat:8 “catalina.sh run” 2 minutes ago Exited (137) About a minute ago tomcat |
那么是怎么一回事呢?
我们尝试从容器本身入手
查看docker输出的状态
docker inspect tomcat -f ‘{{json.State}}’ | jq
| # 显示容器状态，jq用来格式化json输出
$ docker inspect tomcat -f ‘{{json .State}}’ | jq { “Status”: “exited”, “Running”: false, “Paused”: false, “Restarting”: false, “OOMKilled”: true, “Dead”: false, “Pid”: 0, “ExitCode”: 137, “Error”: “”, … } |
被OOM kill了,我们是给docker限制了内存大小,为512M,但是一般来说,都是足够的
我们可以在终端中执行dmsg命令,查看OOM相关日志
| $ dmesg
[193038.106393] java invoked oom-killer: gfp_mask=0x14000c0(GFP_KERNEL), nodemask=(null), order=0, oom_score_adj=0 [193038.106396] java cpuset=0f2b3fcdd2578165ea77266cdc7b1ad43e75877b0ac1889ecda30a78cb78bd53 mems_allowed=0 [193038.106402] CPU: 0 PID: 27424 Comm: java Tainted: G OE 4.15.0-1037 #39-Ubuntu [193038.106404] Hardware name: Microsoft Corporation Virtual Machine/Virtual Machine, BIOS 090007 06/02/2017 [193038.106405] Call Trace: [193038.106414] dump_stack+0x63/0x89 [193038.106419] dump_header+0x71/0x285 [193038.106422] oom_kill_process+0x220/0x440 [193038.106424] out_of_memory+0x2d1/0x4f0 [193038.106429] mem_cgroup_out_of_memory+0x4b/0x80 [193038.106432] mem_cgroup_oom_synchronize+0x2e8/0x320 [193038.106435] ? mem_cgroup_css_online+0x40/0x40 [193038.106437] pagefault_out_of_memory+0x36/0x7b [193038.106443] mm_fault_error+0x90/0x180 [193038.106445] __do_page_fault+0x4a5/0x4d0 [193038.106448] do_page_fault+0x2e/0xe0 [193038.106454] ? page_fault+0x2f/0x50 [193038.106456] page_fault+0x45/0x50 [193038.106459] RIP: 0033:0x7fa053e5a20d [193038.106460] RSP: 002b:00007fa0060159e8 EFLAGS: 00010206 [193038.106462] RAX: 0000000000000000 RBX: 00007fa04c4b3000 RCX: 0000000009187440 [193038.106463] RDX: 00000000943aa440 RSI: 0000000000000000 RDI: 000000009b223000 [193038.106464] RBP: 00007fa006015a60 R08: 0000000002000002 R09: 00007fa053d0a8a1 [193038.106465] R10: 00007fa04c018b80 R11: 0000000000000206 R12: 0000000100000768 [193038.106466] R13: 00007fa04c4b3000 R14: 0000000100000768 R15: 0000000010000000 [193038.106468] Task in /docker/0f2b3fcdd2578165ea77266cdc7b1ad43e75877b0ac1889ecda30a78cb78bd53 killed as a result of limit of /docker/0f2b3fcdd2578165ea77266cdc7b1ad43e75877b0ac1889ecda30a78cb78bd53 [193038.106478] memory: usage 524288kB, limit 524288kB, failcnt 77 [193038.106480] memory+swap: usage 0kB, limit 9007199254740988kB, failcnt 0 [193038.106481] kmem: usage 3708kB, limit 9007199254740988kB, failcnt 0 [193038.106481] Memory cgroup stats for /docker/0f2b3fcdd2578165ea77266cdc7b1ad43e75877b0ac1889ecda30a78cb78bd53: cache:0KB rss:520580KB rss_huge:450560KB shmem:0KB mapped_file:0KB dirty:0KB writeback:0KB inactive_anon:0KB active_anon:520580KB inactive_file:0KB active_file:0KB unevictable:0KB [193038.106494] [ pid ] uid tgid total_vm rss pgtables_bytes swapents oom_score_adj name [193038.106571] [27281] 0 27281 1153302 134371 1466368 0 0 java [193038.106574] Memory cgroup out of memory: Kill process 27281 (java) score 1027 or sacrifice child [193038.148334] Killed process 27281 (java) total-vm:4613208kB, anon-rss:517316kB, file-rss:20168kB, shmem-rss:0kB [193039.607503] oom_reaper: reaped process 27281 (java), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB |
发现其OOM记录中,标记了杀死的是一个java,而且是虚拟内存达到了4.3G超过了cgroups限制的512M了
我们启动tomcat容器,并调用java命令行来查看堆大小
| # 重新启动容器
$ docker rm -f tomcat $ docker run –name tomcat –cpus 0.1 -m 512M -p 8080:8080 -itd feisky/tomcat:8 # 查看堆内存，注意单位是字节 $ docker exec tomcat java -XX:+PrintFlagsFinal -version | grep HeapSize uintx ErgoHeapSizeLimit = 0 {product} uintx HeapSizePerGCThread = 87241520 {product} uintx InitialHeapSize := 132120576 {product} uintx LargePageHeapSizeThreshold = 134217728 {product} uintx MaxHeapSize := 2092957696 {product} |
发现容器内部因为不知道512M的内存限制,而设置了最大堆内存为1.95G,导致突破了内存限制
这样,就解决了Exitd的问题,但是启动慢的问题,并没解决
这样,我们尝试从CPU开始下手
首先是top命令,运行并观察终端
直接从top来看的话,CPU的使用率只有10%左右,其实并不高
然后执行pidstat,尝试分析进程的CPU相关使用率
pidstat -t -p $PID 1
| 12:59:28 UID TGID TID %usr %system %guest %wait %CPU CPU Command
12:59:29 0 29850 – 10.00 0.00 0.00 0.00 10.00 0 java 12:59:29 0 – 29850 0.00 0.00 0.00 0.00 0.00 0 |__java 12:59:29 0 – 29897 5.00 1.00 0.00 86.00 6.00 1 |__java … 12:59:29 0 – 29905 3.00 0.00 0.00 97.00 3.00 0 |__java 12:59:29 0 – 29906 2.00 0.00 0.00 49.00 2.00 1 |__java 12:59:29 0 – 29908 0.00 0.00 0.00 45.00 0.00 0 |__java |
显示出了, %wait比较高
从这里可以看出CPU的使用率比较低
这是因为容器启动的时候,设置的–cpus 0.1是吗,导致只有0.1CPU可使用,也就是大部分都在等待的原因
这样,我们重新设置了docker的启动命令
| # 删除旧容器
$ docker rm -f tomcat # 运行新容器 $ docker run –name tomcat –cpus 1 -m 512M -e JAVA_OPTS=’-Xmx512m -Xms512m’ -p 8080:8080 -itd feisky/tomcat:8 # 查看容器日志 $ docker logs -f tomcat … 18-Feb-2019 12:54:02.139 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 2001 ms |
Tomcat启动基本无误了
那么,今天,我们分析了容器化后应用程序的性能问题
Docker中运行原因,需要保证资源限制的时候,配置好JVM的资源选项
在配置cgroups的资源隔离的同事,需要分析cgroups对于应用程序的影响