某次压测时物理内存被用光 Tomcat 被 Kernel kill 掉的案例

8338人阅读 评论(0) 收藏 举报
分类:

背景描述

某项目结构图如下(前端交互式体验及对象存储为主,redis 及 rds 负载较小没有画出):

aem-architecture.png

web1 和 web2 是两个 Apache,publisher1 和 publisher2 是两个 Tomcat 容器下的 app 应用服务器。

在对该项目进行压测时,并发数加到 750 左右,阿里云 PTS 压测工具监测到在某个时间点后 tps 呈下降趋势:

pts-实时监控-业务指标-tps.png
作为对应指标的响应时间(rt)在这个时间点呈上升趋势:
pts-实时监控-业务指标-响应时间.png

查看实时监控-监控集指标,发现 publisher1 节点的 CPU 利用率已降为 1.9,在高并发的时候这个值肯定是有问题,很可能这个节点已经宕掉:

pts-实时监控-监控集指标-CPU.png

查看网络流量发现该节点果然已经没有了网络流量:

pts-实时监控-监控集指标-网络.png
ssh 登录 publisher1 ps 证实 Tomcat 确实已经 crash。但查 Tomcat 日志、应用日志,没有任何异常,find 也没找到类似于 hs_err_pidNNN.log 之类的 crash 日志。Tomcat 内存分配情况:
JAVA_OPTS="-Xmx3072m"

系统物理内存 8G,看上去绰绰有余。真的是这样吗?

原因分析

一般来讲,诸如内存溢出之类常见的 Tomcat 崩溃都会在容器日志或者 crash 日志中记录原因。但不排除这种情况:Linux 允许系统中的进程申请比现有系统可用内存还要多的内存,但当整个系统内存不足的时候,Kernel 会将耗用内存最多的那个进程给干掉,就是 Tomcat 了,但这并不能说明 Tomcat 发生了某些运行时的致命错误,所以我们没有看到任何容器、应用甚至 jvm 级别的异常,Tomcat 来不及做任何日志处理就 Over 了。
查看 /var/log/messages,在 PTS 指示的时间点找到了以下日志:
Jul 25 03:15:39 localhost kernel: [91918.878735] httpd invoked oom-killer: gfp_mask=0x24200ca(GFP_HIGHUSER_MOVABLE), nodemask=0, order=0, oom_score_adj=0

...

Jul 25 03:15:39 localhost kernel: [91919.032621] 0 pages in swap cache
Jul 25 03:15:39 localhost kernel: [91919.033999] Swap cache stats: add 0, delete 0, find 0/0
Jul 25 03:15:39 localhost kernel: [91919.036137] Free swap  = 0kB
Jul 25 03:15:39 localhost kernel: [91919.037343] Total swap = 0kB
Jul 25 03:15:39 localhost kernel: [91919.038605] 2097053 pages RAM
Jul 25 03:15:39 localhost kernel: [91919.039849] 0 pages HighMem/MovableOnly

...

Jul 25 03:15:39 localhost kernel: [91919.042738] [ pid ]   uid  tgid total_vm      rss nr_ptes nr_pmds swapents oom_score_adj name
Jul 25 03:15:39 localhost kernel: [91919.046327] [ 1623]     0  1623     2828      201      11       3        0         -1000 udevd
Jul 25 03:15:39 localhost kernel: [91919.231201] [  486]     0   486 12933081   879709    4090      53        0             0 java
Jul 25 03:15:39 localhost kernel: [91919.273553] [ 7903]     0  7903     1079       24       7       3        0             0 cronolog
...
Jul 25 03:15:39 localhost kernel: [91921.135391] Out of memory: Kill process 486 (java) score 419 or sacrifice child
Jul 25 03:15:39 localhost kernel: [91921.138827] Killed process 486 (java) total-vm:51732324kB, anon-rss:3518836kB, file-rss:0kB, shmem-rss:0kB

注意以上系统时间为 UTC 时间,对应北京时间为 Jul 25 11:15:39,PTS 监控到的 publisher1 节点的内存曲线图的顶点跟 OOM 的时间也基本一致:
pts-实时监控-监控集指标-内存.png

可以看到在 11:15 左右 publisher1 节点的 8G 物理内存已经用光。

解决方案

当 Linux 系统物理内存不够用的时候,需要将物理内存中的一部分空间释放出来以供当前运行程序使用。这些被释放出来的空间很可能来自于一些长时间没有什么操作的程序,这些被释放出来的空间会被临时存放到 SWAP 空间,等这些程序要运行时,再从 SWAP 恢复数据到内存。上述案例 publisher1 节点 SWAP 查看:
$ free -m
             total       used       free     shared    buffers     cached
Mem:          7985       4158       3826         10         13        219
-/+ buffers/cache:       3925       4059

Swap:            0          0          0

$ cat /proc/swaps
Filename                                Type            Size    Used    Priority

交换分区空间没有,系统在物理内存不够的时候也就没有临时空间可以利用,为了整个系统的正常运行,"oom_killer" 函数被调用了,于是 Tomcat 悲剧了。。。

解决方案似乎已经很明显了(参考博客《Linux 如何添加一个 Swap 文件》)。值得一提的是,在上面的 message 日志里,Kernel 在筛选要干掉的进程的日志里,在其前面紧挨着的便是指示 SWAP 为 0 无交换空间可用:)

参考资料

Tomcat stopped without any log or any stack
Out of Memory + httpd.worker invoked oom-killer

博主 20170727 日续:关于 Apache 的类似案例

上述案例中 app 节点,也就是 publisher1 节点修复以后,继续加压测试,在并发数达到 1000 的时候,web2 节点宕掉。具体表象为 web2 服务器 SSH 连不上,阿里云 PTS 监控集也显示为 web2 处于下线状态。

查看 web2 的 /var/log/messages,该时间段日志摘要如下:

Jul 26 08:16:01 CN-LAMP-STG-M-0005-UFS-V3-WEB-02 kernel: [  554.469621] httpd invoked oom-killer: gfp_mask=0x24201ca(GFP_HIGHUSER_MOVABLE|__GFP_COLD), nodemask=0, order=0, oom_score_adj=0
Jul 26 08:16:01 CN-LAMP-STG-M-0005-UFS-V3-WEB-02 kernel: [  554.474732] httpd cpuset=/ mems_allowed=0
...
Jul 26 08:16:01 CN-LAMP-STG-M-0005-UFS-V3-WEB-02 kernel: [  554.619479] 0 pages in swap cache
Jul 26 08:16:01 CN-LAMP-STG-M-0005-UFS-V3-WEB-02 kernel: [  554.620912] Swap cache stats: add 0, delete 0, find 0/0
Jul 26 08:16:01 CN-LAMP-STG-M-0005-UFS-V3-WEB-02 kernel: [  554.623248] Free swap  = 0kB
Jul 26 08:16:01 CN-LAMP-STG-M-0005-UFS-V3-WEB-02 kernel: [  554.624566] Total swap = 0kB
...
Jul 26 08:16:01 CN-LAMP-STG-M-0005-UFS-V3-WEB-02 kernel: [  554.630247] [ pid ]   uid  tgid total_vm      rss nr_ptes nr_pmds swapents oom_score_adj name
Jul 26 08:16:01 CN-LAMP-STG-M-0005-UFS-V3-WEB-02 kernel: [  554.633759] [ 1556]     0  1556     2865      218      11       3        0         -1000 udevd
Jul 26 08:16:01 CN-LAMP-STG-M-0005-UFS-V3-WEB-02 kernel: [  554.796157] [ 3306]     0  3306   193666     6316     291       4        0             0 httpd
Jul 26 08:16:01 CN-LAMP-STG-M-0005-UFS-V3-WEB-02 kernel: [  558.310852] [ 9863]    48  9863   195801     3725     275       4        0             0 httpd
...
Jul 26 08:16:01 CN-LAMP-STG-M-0005-UFS-V3-WEB-02 kernel: [  558.512008] Out of memory: Kill process 3306 (httpd) score 12 or sacrifice child
Jul 26 08:16:01 CN-LAMP-STG-M-0005-UFS-V3-WEB-02 kernel: [  558.515331] Killed process 9863 (httpd) total-vm:783204kB, anon-rss:14768kB, file-rss:4kB, shmem-rss:128kB

日志处理逻辑看上去和 publisher1 干掉 Tomcat 的做法一般无二,区别在于 Apache 为了保证高可用性在 httpd worker 进程故障后会再拉起一个,系统物理内存最终被耗光而 OOME 宕机。于是 Publisher1 的表象为 Tomcat 的 crash,而 web2 的表象为 Linux 系统无响应。

解决办法是,除了像 publisher1 那样给 web2 启用虚拟空间,还可以降低 Apache 的最大连接数 MaxClients、最大内存 ServerLimit,修改后使用命令 service httpd restart 对 apache 进行重启使配置生效。

查看评论

app被kill再次启动时系统会恢复被kill时的activity

当一个应用有activity存在时被kill掉进程,再次启动应用时系统会唤醒之前存在的那个activity。 在Mate8、Mate9上都存在这一现象,当初测试有一个用例就是测试应用被kill后的反...
  • acxingyun
  • acxingyun
  • 2017-07-25 14:43:10
  • 214

如何应对activity被kill

转载:http://www.cnblogs.com/bjzhanghao/archive/2012/11/08/2759948.html 转载:http://blog.csdn.net/cuiran/...
  • err118
  • err118
  • 2015-10-30 10:24:13
  • 494

tomcat端口被占用,如何找出并kill

开始-运行-cmd,输入netstat -ano即可看到所有端口占用情况。 加入要想知道谁占用了我们的端口8080,输入以下命令 C:\Documents and Settings\Adminis...
  • u012959829
  • u012959829
  • 2014-06-16 14:06:36
  • 1647

怎么kill被占用的端口

http://blog.sina.com.cn/s/blog_7e4235d70101q4sm.html
  • Bunny_CDM
  • Bunny_CDM
  • 2016-09-22 10:51:37
  • 415

程序被系统kill——Service进程滥用

问题描述 程序在后台常驻运行过程中被某厂商手机系统kill,发现kill进程的是系统的电量管理相关进程。但是手机已经赋予我们APP所有权限,依然会被kill。 我们通过开启手机工程模式,得...
  • u011578734
  • u011578734
  • 2017-07-13 16:57:52
  • 150

进程如何分辨谁在kill()自己

至少对于Linux、FreeBSD、Solaris、AIX这四种操作系统,有一种办法。不要安装传统sa_handler信号句柄,而是安装sa_sigaction信号句柄。细节请man sigactio...
  • freerock
  • freerock
  • 2007-09-28 11:17:00
  • 922

php守护进程被kill的解决方案

有一个队列服务需要使用php作守护进程,但发现这个守护进程经常被杀掉,查了资料,发现了如下的描述 http://blog.csdn.net/newjueqi/article/details/...
  • newjueqi
  • newjueqi
  • 2013-01-15 10:19:38
  • 2037

Android面试题-service被kill之后怎么让它重启

Android面试题-service被kill之后怎么让它重启
  • mwq384807683
  • mwq384807683
  • 2017-05-20 17:27:02
  • 923

防止Android程序被系统kill掉的处理方法

目前遇到一个问题程序需要一直运行,并显示在最前端,但是运行一段时间发现会被系统Kill掉,这样程序就退出回到了桌面,不能实现一直运行的效果。为了实现此效果,也想了一些办法。...
  • cuiran
  • cuiran
  • 2014-08-26 18:01:12
  • 14708

记一次app主进程被kill的经历

出现问题最近在为河北电信做定制游戏平台开发的时候,遇到了一个很奇怪的问题,在某些盒子上,从平台打开某些游戏,玩上几分钟,然后该退出游戏,回到公司的游戏平台后,便出现了页面数据丢失的问题。 排查了几天...
  • qwe511455842
  • qwe511455842
  • 2017-03-24 14:05:13
  • 477
    个人资料
    持之以恒
    等级:
    访问量: 543万+
    积分: 3万+
    排名: 119
    最新评论
    文章存档