2、诡异的第二天还是4:03分,又发作了!排除了新sar的原因,就百思不和其解了,发现-XX:+CMSClassUnloadingEnabled开着,关掉。第二天还是一样!各种看代码都没有问题,在一个无穷循环的线程里打日志,各种招都用上还是老样子,连Servlet消失了,突然对哥掌握的Java知识产生了莫名其妙的怀疑…
3、这个应用改过名字,上边2个应用的目录都存在的。发现老目录的log文件修改时间居然是当前时间,再PS一看,发现启的进程是老应用的!新老2个war变化非常大,之前验证的点在老war里都木有的,好,觉得终于找着原因了。删老目录,找PE查脚本,果然查到启老应用的脚本!停掉脚本。甚至把老的应用目录link到新应用,即使脚本改不干净也不致于把我应用杀掉,免受接口调用方骚扰啊。
4、奇迹再一次发生了。应用在4:03准时消失了,老的确实也不起来了。
因为是预发环境,线上完全无问题,怀疑是环境问题所以也就一直没花太多时间去查。PE也觉不再有脚本在跑了,好吧,决定好好查一下。
首先,看系统日志,希望能找到SSH登录日志、命令执行日志或进程启动/终止日志,搜4点这个时间,wtmp/secure都没有发现。
然后,找messages这个时间点,找到:
Jun 20 04:05:14 ***.pre.cm3 kernel: : java invoked oom-killer: gfp_mask=0x201d2, order=0, oomkilladj=0
Jun 20 04:05:14 ***.pre.cm3 kernel: :
Jun 20 04:05:14 ***.pre.cm3 kernel: : Call Trace:
Jun 20 04:05:14 ***.pre.cm3 kernel: : [] out_of_memory+0x8b/0x203
...
Jun 20 04:05:18 ***.pre.cm3 kernel: : Mem-info:
...
oom-killer,之前不知道有这个东西,想想JVM自己不可能发生OOM,因为即没OOM日志也没Crash Core日志,而且还每次都是同一时间点!应用中也木有这种定时任务。
关于Linux OOM-killer机制——
linux oom-killer是一种自我保护机制,当系统分配不出内存时(触发条件)会触发这个机制,由操作系统在己有进程中挑选一个占用内存较多,回收内存收益最大的进程kill掉来释放内存。
系统为每个进程做评估(/proc/<pid>/oom_score中数值最大的进程被kill掉),参考这里。
前面的问题,Java进程占用内存足够多,进程生存又比较短,正是OOM-killer的首选啊,所以中招。
- /**
- * badness - calculate a numeric value for how bad this task has been
- * @p: task struct of which task we should calculate
- * @uptime: current uptime in seconds
- *
- * The formula used is relatively simple and documented inline in the
- * function. The main rationale is that we want to select a good task
- * to kill when we run out of memory.
- *
- * Good in this context means that:
- * 1) we lose the minimum amount of work done
- * 2) we recover a large amount of memory
- * 3) we don't kill anything innocent of eating tons of memory
- * 4) we want to kill the minimum amount of processes (one)
- * 5) we try to kill the process the user expects us to kill, this
- * algorithm has been meticulously tuned to meet the principle
- * of least surprise ... (be careful when you change it)
- */
另外,Linux的malloc分配内存,也不是一次到位的真分配了指定大小的物理内存(Overcommit机制,另一篇也不错,这里Fenny一篇),而是先承诺你,实际用到的时候才去系统分配,如果刚好那个时候内存不够了,就会触发oom-killer。
Linux下有3种Overcommit的策略(参考内核文档:vm/overcommit-accounting),可以在/proc/sys/vm/overcommit_memory配置。取0,1和2三个值,默认是0。
0:启发式策略,比较严重的Overcommit将不能得逞,比如你突然申请了128TB的内存。而轻微的Overcommit将被允许。另外,root能Overcommit的值比普通用户要稍微多些。
1:永远允许Overcommit,这种策略适合那些不能承受内存分配失败的应用,比如某些科学计算应用。
2:永远禁止Overcommit,在这个情况下,系统所能分配的内存不会超过swap+RAM*系数(/proc/sys/vm/overcmmit_ratio,默认50%,你可以调整),如果这么多资源已经用光,那么后面任何尝试申请内存的行为都会返回错误,这通常意味着此时没法运行任何新程序。
我的机器为什么会触发OOM-killer——
先查了下sar的日志:
- 12:00:01 AM CPU %user %nice %system %iowait %steal %idle
- 04:00:01 AM all 0.01 0.00 0.00 0.00 0.01 99.98
- 04:10:02 AM all 0.55 0.00 20.71 37.97 0.06 40.71
- 04:20:01 AM all 0.01 0.00 0.04 0.24 0.01 99.71
system cpu占的比较多,应该是kernel OOM-killer执行所占掉的。再看没有启java进程情况下这个时间点的日志,CPU是正常的。
cat /proc/sys/vm/overcommit_memory 值0,即启发式策略,允许Overcommit。
总可用内存才2G(更换机器之前为4G,后面的配置是按4G来配的),JVM就申请了2G+,再加上nginx所占申请内存,远超实际物理内存2G+Swap 1G范围了,应用之所以正常是应用启动不久,实际用的内存并没用那么多,到晚上达到临界值,其实一个不相干的定时任务申请内存,刚好就触发了OOM-killer了。
nginx和java应用线上长时间验证是稳定的,不存在内存泄露,至于机器上4:03启动了什么任务,其实都不那么重要了。