关闭

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

5544人阅读 评论(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 进行重启使配置生效。

2
1
查看评论
发表评论
* 以上用户言论只代表其个人观点,不代表CSDN网站的观点或立场

linux系统tomcat应为被定时任务脚本监控自动部署,服务器重启导致同一个tomcat出现很多进程,kill -9杀死又出现等一系列问题解决。

linux系统tomcat应为被定时任务脚本监控自动部署,服务器重启导致同一个tomcat出现很多进程,kill -9杀死又出现等一系列问题解决。 如图#ps -ef|grep tomcat查看tomcat进程,同一个tomcat有很多一样的进程,kill -9杀完过一会又会出现,且pid随时发...
  • sgl520lxl
  • sgl520lxl
  • 2017-03-08 20:46
  • 1854

linux系统top命令分析CPU和内存详解

op命令是Linux下常用的性能分析工具,能够实时显示系统中各个进程的资源占用状况,默认linux操作系统提供。 在命令行中直接敲入top回车,即可实时显示系统中各个进程的资源占用状况。如下图: 其中各参数含义分别如下: 第一行top:显示了系统当前时间、系统运行了多长时间、当前登...
  • zhaomax
  • zhaomax
  • 2017-07-21 11:56
  • 135

主动kill掉进程获取线程运行时栈信息

通常情况下,通过对运行时log的分析基本上可以定位一些bug,但是在一些特殊的环境下,分析log并不是一个有效的方法。 拿我最近遇见的情况来说,一些跑稳定性的设备在运行多日后三台设备出现了一些异常,粗略估计是因为某个管理资源的状态机出了异常。 但是因为这个状态机触发频率高,所以并未留下足够分析的lo...
  • jinnlxl
  • jinnlxl
  • 2015-01-20 10:31
  • 1062

mysql启动报错(kill后)解决记录

症状: 以上症状是执行完:kill -9  ***** ,强制杀死mysql进程后导致,启动失败, 解决步骤:1.查看mysql 启动日志: 查看log,发现mysql系统表丢失了,因为数据库数据都是测试数据,重建数据库不影响。 2. 执行创建表的初始化脚本: 进入mysqld所在目...
  • youjin
  • youjin
  • 2016-11-25 13:42
  • 522

LoadRunner监控Tomcat性能以及tomcat环境部署

使用LoadRunner做性能测试,监控一些中间件或web服务器的性能时,需要手工来编写脚本。Loadrunner中lr_user_data_point、lr_user_data_point_instance两个函数可以用来记录一条自定义的Vuser运行数据,并将其输出到测试结果中,最后可以通过分析...
  • henni_719
  • henni_719
  • 2016-07-26 09:12
  • 1193

批量kill进程/线程

Step1:背景介绍 今天在进行epoll性能测试时,测试模式为C/S模式, Server:为接收端,每接收一个connSock连接,就fork一个child-process处理这个连接上的数据接收 Client:为发送端,内部建立多个连接到Server的socket-fd,然后注册到epoll,通...
  • u012421852
  • u012421852
  • 2016-04-19 23:51
  • 726

记一次tomcat web应用压测调优

前言 该tomcat web应用承担集团登录注册页面功能,对性能有一定要求,由于先前没有太多相关经验(只压测过一个dubbo服务),这次调得比较艰辛,便做个记录。 调优过程 由于该次部署是两个不同团队的初次合作,起初没有给运维任何tomcat配置要求,同时也没留意去确认tomcat配置,这个导致...
  • zhouyuqwert
  • zhouyuqwert
  • 2015-10-24 22:35
  • 4282

Linux下Tomcat的启动、关闭、杀死进程以及查看日志

Linux下Tomcat的启动、关闭杀死进程 打开终端,我我们先找到Tomcat目录,Tomcat下面一般目录为:
  • qq_36743013
  • qq_36743013
  • 2017-07-16 14:19
  • 643

文件系统编译过程中遇到问题,解决过程Kernel panic - not syncing: Attempted to kill init!

用4.4.3 编译器编译出来的文件系统 Empty flash at 0x0214bf7c ends at 0x0214c000 Empty flash at 0x0214fffc ends at 0x02150000 Empty flash at 0x02153fa0 ends at 0x0...
  • jiangjingsong5
  • jiangjingsong5
  • 2016-06-15 11:25
  • 1398

ORACLE快速彻底Kill掉的会话,防止锁表

万能是sql重启服务,不然,以下之: 在ORACLE数据库当中,有时候会使用ALTER SYSTEM KILL SESSION 'sid,serial#'杀掉一个会话进程,但是使用这个SQL语句杀掉会话后,数据库并不会立即释放掉相关的资源,有时候你会发现锁定的资源很长时间也...
  • English0523
  • English0523
  • 2016-07-11 12:26
  • 1066
    个人资料
    • 访问:5139013次
    • 积分:37741
    • 等级:
    • 排名:第124名
    • 原创:241篇
    • 转载:35篇
    • 译文:163篇
    • 评论:1563条
    个人微博
    最新评论
    文章存档