服务器宕机

2020年6月16日 服务器挂了，前两天也挂过一次，重启没几天又挂了。

提供APP后台接口服务的web应用没有响应，查看Tomcat当天日志，发现很奇怪的现象，到2020-06-16 00:24:29日志突然断掉没有了输出，并且附近时间段没有error日志。

clip_image002.png

首先怀疑系统的日志配置的error级别的日志输出到其他文件中，先去查看系统配置的日志

clip_image004.png

发现并没有问题，往上查看日志文件记录，试图寻找蛛丝马迹，并于重启服务器之后的记录作对比，发现当天宕机前半个小时的日志量比较大，应该是业务数据比较多，那么会不会是内存溢出了呢？但是日志中并没有OM的日志记录。试图百度寻找答案，发现有个回答似乎符合，在系统内存不够时，linux会启动oom killer杀死系统进程，按照文章所说，查看linux /var/log/message文件，发现如下记录：

Jun 16 00:24:32 **** kernel: mysqld invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=0
Jun 16 00:24:32 **** kernel: mysqld cpuset=/ mems_allowed=0
Jun 16 00:24:32 **** kernel: CPU: 0 PID: 1411 Comm: mysqld Kdump: loaded Not tainted 3.10.0-1062.9.1.el7.x86_64 #1
Jun 16 00:24:32 **** kernel: Hardware name: Alibaba Cloud Alibaba Cloud ECS, BIOS rel-1.7.5-0-ge51488c-20140602_164612-nilsson.home.kraxel.org 04/01/2014
Jun 16 00:24:32 **** kernel: Call Trace:
Jun 16 00:24:32 **** kernel: [<ffffffff82f7ac23>] dump_stack+0x19/0x1b
Jun 16 00:24:32 **** kernel: [<ffffffff82f75ce9>] dump_header+0x90/0x229
Jun 16 00:24:32 **** kernel: [<ffffffff82906142>] ? ktime_get_ts64+0x52/0xf0
Jun 16 00:24:32 **** kernel: [<ffffffff829c1714>] oom_kill_process+0x254/0x3e0
Jun 16 00:24:32 **** kernel: [<ffffffff82932e71>] ? cpuset_mems_allowed_intersects+0x21/0x30
Jun 16 00:24:32 **** kernel: [<ffffffff829c11bd>] ? oom_unkillable_task+0xcd/0x120
Jun 16 00:24:32 **** kernel: [<ffffffff829c1266>] ? find_lock_task_mm+0x56/0xc0
Jun 16 00:24:32 **** kernel: [<ffffffff829c1f66>] out_of_memory+0x4b6/0x4f0
Jun 16 00:24:32 **** kernel: [<ffffffff829c8a6f>] __alloc_pages_nodemask+0xacf/0xbe0
Jun 16 00:24:32 **** kernel: [<ffffffff82a16b28>] alloc_pages_current+0x98/0x110
Jun 16 00:24:32 **** kernel: [<ffffffff829bd617>] __page_cache_alloc+0x97/0xb0
Jun 16 00:24:32 **** kernel: [<ffffffff829c01d8>] filemap_fault+0x298/0x490
Jun 16 00:24:32 **** kernel: [<ffffffffc05c1346>] ext4_filemap_fault+0x36/0x50 [ext4]
Jun 16 00:24:32 **** kernel: [<ffffffff829ec15a>] __do_fault.isra.61+0x8a/0x100
Jun 16 00:24:32 **** kernel: [<ffffffff82f804b0>] ? __schedule+0x310/0x840
Jun 16 00:24:32 **** kernel: [<ffffffff82f804a4>] ? __schedule+0x304/0x840
Jun 16 00:24:32 **** kernel: [<ffffffff829ec70c>] do_read_fault.isra.63+0x4c/0x1b0
Jun 16 00:24:32 **** kernel: [<ffffffff82f804b0>] ? __schedule+0x310/0x840
Jun 16 00:24:32 **** kernel: [<ffffffff82f804a4>] ? __schedule+0x304/0x840
Jun 16 00:24:32 **** kernel: [<ffffffff829f11ba>] handle_pte_fault+0x22a/0xe20
Jun 16 00:24:32 **** kernel: [<ffffffff8282b621>] ? __switch_to+0x151/0x580
Jun 16 00:24:32 **** kernel: [<ffffffff829f3ecd>] handle_mm_fault+0x39d/0x9b0
Jun 16 00:24:32 **** kernel: [<ffffffff828ca779>] ? hrtimer_try_to_cancel+0x29/0x120
Jun 16 00:24:32 **** kernel: [<ffffffff82f88653>] __do_page_fault+0x213/0x500
Jun 16 00:24:32 **** kernel: [<ffffffff82f88a26>] trace_do_page_fault+0x56/0x150
Jun 16 00:24:32 **** kernel: [<ffffffff82f87fa2>] do_async_page_fault+0x22/0xf0
Jun 16 00:24:32 **** kernel: [<ffffffff82f847a8>] async_page_fault+0x28/0x30
Jun 16 00:24:32 **** kernel: Mem-Info:
Jun 16 00:24:32 **** kernel: active_anon:439551 inactive_anon:35 isolated_anon:0#012 active_file:36 inactive_file:30 isolated_file:0#012 unevictable:0 dirty:0 writeback:0 unstable:0#012 slab_reclaimable:4978 slab_unreclaimable:3308#012 mapped:5 shmem:98 pagetables:1870 bounce:0#012 free:13062 free_pcp:150 free_cma:0
Jun 16 00:24:32 **** kernel: Node 0 DMA free:7664kB min:380kB low:472kB high:568kB active_anon:7720kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB managed:15908kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:124kB slab_unreclaimable:72kB kernel_stack:0kB pagetables:136kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
Jun 16 00:24:32 **** kernel: lowmem_reserve[]: 0 1819 1819 1819
Jun 16 00:24:32 **** kernel: Node 0 DMA32 free:44584kB min:44672kB low:55840kB high:67008kB active_anon:1750484kB inactive_anon:140kB active_file:144kB inactive_file:120kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2080640kB managed:1866164kB mlocked:0kB dirty:0kB writeback:0kB mapped:20kB shmem:392kB slab_reclaimable:19788kB slab_unreclaimable:13160kB kernel_stack:3904kB pagetables:7344kB unstable:0kB bounce:0kB free_pcp:600kB local_pcp:600kB free_cma:0kB writeback_tmp:0kB pages_scanned:420 all_unreclaimable? yes
Jun 16 00:24:32 **** kernel: lowmem_reserve[]: 0 0 0 0
Jun 16 00:24:32 **** kernel: Node 0 DMA: 10*4kB (UEM) 9*8kB (UE) 8*16kB (UEM) 4*32kB (UEM) 2*64kB (UE) 2*128kB (EM) 1*256kB (M) 1*512kB (E) 2*1024kB (UE) 2*2048kB (EM) 0*4096kB = 7664kB
Jun 16 00:24:32 **** kernel: Node 0 DMA32: 388*4kB (UEM) 427*8kB (UEM) 386*16kB (UE) 233*32kB (UEM) 148*64kB (UEM) 51*128kB (UEM) 17*256kB (UEM) 7*512kB (UE) 2*1024kB (UM) 0*2048kB 0*4096kB = 44584kB
Jun 16 00:24:32 **** kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
Jun 16 00:24:32 **** kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
Jun 16 00:24:32 **** kernel: 174 total pagecache pages
Jun 16 00:24:32 **** kernel: 0 pages in swap cache
Jun 16 00:24:32 **** kernel: Swap cache stats: add 0, delete 0, find 0/0
Jun 16 00:24:32 **** kernel: Free swap = 0kB
Jun 16 00:24:32 **** kernel: Total swap = 0kB
Jun 16 00:24:32 **** kernel: 524158 pages RAM
Jun 16 00:24:32 **** kernel: 0 pages HighMem/MovableOnly
Jun 16 00:24:32 **** kernel: 53640 pages reserved
Jun 16 00:24:32 **** kernel: [ pid ]  uid tgid total_vm   rss nr_ptes swapents oom_score_adj name
Jun 16 00:24:32 **** kernel: [ 330]   0  330  11818    78   30    0       0 systemd-journal
Jun 16 00:24:32 **** kernel: [ 354]   0  354  11057   185   23    0     -1000 systemd-udevd
Jun 16 00:24:32 **** kernel: [ 469]   0  469  13875   112   28    0     -1000 auditd
Jun 16 00:24:32 **** kernel: [ 500]   0  500   3305    52   12    0       0 rngd
Jun 16 00:24:32 **** kernel: [ 501]   0  501  180835   271   173    0       0 rsyslogd
Jun 16 00:24:32 **** kernel: [ 502]   0  502   6595    73   19    0       0 systemd-logind
Jun 16 00:24:32 **** kernel: [ 508]  999  508  134641   1677   60    0       0 polkitd
Jun 16 00:24:32 **** kernel: [ 509]  81  509  14519   137   33    0     -900 dbus-daemon
Jun 16 00:24:32 **** kernel: [ 523]   0  523  31572   158   19    0       0 crond
Jun 16 00:24:32 **** kernel: [ 524]   0  524   6476    51   19    0       0 atd
Jun 16 00:24:32 **** kernel: [ 534]   0  534  27524    33   11    0       0 agetty
Jun 16 00:24:32 **** kernel: [ 535]   0  535  27524    33    9    0       0 agetty
Jun 16 00:24:32 **** kernel: [ 883]   0  883  143400   3198   99    0       0 tuned
Jun 16 00:24:32 **** kernel: [ 892]   0  892  10207   158   11    0       0 aliyun-service
Jun 16 00:24:32 **** kernel: [ 911]  38  911   7488   161   20    0       0 ntpd
Jun 16 00:24:32 **** kernel: [ 957]   0  957   8165   393   21    0       0 AliYunDunUpdate
Jun 16 00:24:32 **** kernel: [ 979]  27  979  28329    75   11    0       0 mysqld_safe
Jun 16 00:24:32 **** kernel: [ 1183]   0 1183  34106   3485   68    0       0 AliYunDun
Jun 16 00:24:32 **** kernel: [ 1397]  27 1397  254694  47867   165    0       0 mysqld
Jun 16 00:24:32 **** kernel: [ 1540]   0 1540  27587   247   59    0     -1000 sshd
Jun 16 00:24:32 **** kernel: [ 3340]   0 3340  426605  143352   386    0       0 java
Jun 16 00:24:32 **** kernel: [ 4404]   0 4404  446504  235570   568    0       0 java
Jun 16 00:24:32 **** kernel: Out of memory: Kill process 4404 (java) score 486 or sacrifice child
Jun 16 00:24:32 **** kernel: Killed process 4404 (java), UID 0, total-vm:1786016kB, anon-rss:942280kB, file-rss:0kB, shmem-rss:0kB
Jun 16 00:24:32 **** kernel: mysqld invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=0

也就是在当天的宕机的时间，mysql进程唤醒了linux的oom killer，杀死了java进程

百度相关知识，oom killer

Linux 内核有个机制叫OOM killer(Out Of Memory killer)，该机制会监控那些占用内存过大，尤其是瞬间占用内存很快的进程，然后防止内存耗尽而自动把该进程杀掉。内核检测到系统内存不足、挑选并杀掉某个进程的过程可以参考内核源代码linux/mm/oom_kill.c，当系统内存不足的时候，out_of_memory()被触发，然后调用select_bad_process()选择一个”bad”进程杀掉。如何判断和选择一个”bad进程呢？linux选择”bad”进程是通过调用oom_badness()，挑选的算法和想法都很简单很朴实：最bad的那个进程就是那个最占用内存的进程。

相关解决办法，将java进程添加到oom killer的保护进程中去，但似乎并不是解决之道，因为这条服务器上有两个tomcat web服务和一个Mysql，不杀这个杀那个，就算不杀死这三个进程，剩下的进程似乎没有多余的，都是些系统服务进程，如果那些进程被杀死了可能会导致更严重的后果，而且查看内存占用，内存大户就两个tomcat和mysql，杀死其他进程也解决不了问题，总之，这个办法治标不治本。

那还能咋办？好像到了绕不过去的问题，JVM调优。咋调？

首先看一下内存占用吧

clip_image006.png

实际物理内存占用一个0.7G 一个0.6G，似乎也不大啊。但我似乎忽略了一个问题，如上图所示，给出了总物理内存大小1882072kiB..嗯~大概2G吧。**，两个G的机子部署了两个web和mysql，就算业务量不大，好像也有点难顶啊，还有啊，这个截图事后截图，其实之前swap分区也没有，这系统挂掉似乎就不是什么优化的问题，最起码短板不在代码优化。

---

经调查服务器配置如下

服务器1:
IP:...
cup:2核
内存:8G 带宽:5Mbps(峰值）
硬盘:50G
应用: 后台管理应用 MYSQL数据库(有没有跑数据还不清楚，交接文档中没有这台数据库的账号密码，不过代码中没有这台数据库的连接）
监控数据: CPU:14天在0.4%之下 内存:2020/6/17 11:15-2020/6/17 11:45 15.63%

服务器2:
IP:...(www.XXXXX.com与www.XXXX.com域名解析都指向此IP)
CPU:1核
内存:2G
带宽:100Mbps（峰值）
硬盘:200G（需要大量文件存储）
应用: APP后台接口服务应用 PC端以及官网访问应用
主力MYSQL数据库
监控数据: cpu:14天峰值12% 内存:2020/6/16 17:00-2020/6/17 12:00 86%-95%

存在问题与解决方法的些想法：

想法一：
服务器1资源浪费，建议降配内存cpu，1核2G（还得先调查清楚此服务器上MYSQL） 服务器2内存资源紧张，建议将内存升配到8G，考虑到主力数据库（业务量大的时候需要高运算和高IO），CPU是否需要升级需要继续监控观察

想法二：
在将服务器2的两个应用迁移到2核8G的服务器上，将服务器1的后台管理应用迁移到服务器2，并在服务器2架设文件服务。不过这样后期业务量上来了数据库压力会比较大，可以考虑将数据库也迁移到服务器1。