这是学习笔记的第 1759篇文章
今天收到一封系统的报警邮件，内容大体如下：
Metric:os.df.bytes.percentused Tags:fstype=ext4,mount=/ all(#3): 80.03837>=80 Note:【GP】[根目录磁盘空间使用超过80%] Max:3, Current:3 Timestamp:2018-09-29 07:43:00
通过信息明显看到是磁盘空间不够了，但是任何事物都有表面和本质。表面现象是磁盘空间问题，我们需要引出更深层次的问题。
首先通过报警信息可以看到，这是基于根分区的提示信息，阈值为80%，看起来在正常不过的方式了。
经过排查发现是/var/log/messages，这个文件的日志量很大，距离上一次的问题修复其实时间也不长，messages文件有两个，累计有16G左右。
最开始我还抱怨说，是什么进程在监控，怎么这么频繁，按照日志量我做了下统计，每天有差不多1000万行记录。每一分钟都有大量的记录产生。
仔细看了下，发现系统在不断的吐苦水。
Sep 29 12:02:38 test-dat-data kernel: lowmem_reserve[]: 0 0 0 0
Sep 29 12:02:38 test-dat-data kernel: Node 0 DMA: 1*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 1*256kB 1*512kB 1*1024kB 1*2048kB 2*4096kB = 12036kB
Sep 29 12:02:38 test-dat-data kernel: Node 0 DMA32: 560*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 2*2048kB 0*4096kB = 6336kB
Sep 29 12:02:38 test-dat-data kernel: Node 0 Normal: 942*4kB 1379*8kB 11420*16kB 6826*32kB 299*64kB 235*128kB 85*256kB 21*512kB 572*1024kB 2*2048kB 3*4096kB = 1099792kB
Sep 29 12:02:38 test-dat-data kernel: 1864177 total pagecache pages
Sep 29 12:02:38 test-dat-data kernel: 1088 pages in swap cache
Sep 29 12:02:38 test-dat-data kernel: Swap cache stats: add 73237, delete 72149, find 1348537/1355576
Sep 29 12:02:38 test-dat-data kernel: Free swap = 5152076kB
Sep 29 12:02:38 test-dat-data kernel: Total swap = 5242876kB
Sep 29 12:02:38 test-dat-data kernel: 3145712 pages RAM
Sep 29 12:02:38 test-dat-data kernel: 96381 pages reserved
Sep 29 12:02:38 test-dat-data kernel: 190354 pages shared
Sep 29 12:02:38 test-dat-data kernel: 2641894 pages non-shared
Sep 29 12:02:38 test-dat-data kernel: events/7: page allocation failure. order:0, mode:0x24
Sep 29 12:02:38 test-dat-data kernel: Pid: 42, comm: events/7 Not tainted 2.6.32-642.11.1.el6.x86_64 #1
Sep 29 12:02:38 test-dat-data kernel: Call Trace:
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff8113e55c>] ? __alloc_pages_nodemask+0x7dc/0x950
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff8113e57f>] ? __alloc_pages_nodemask+0x7ff/0x950
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff8117794a>] ? alloc_pages_current+0xaa/0x110
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff8113ba1e>] ? __get_free_pages+0xe/0x50
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff812b2fdd>] ? swiotlb_alloc_coherent+0x5d/0x130
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff81047091>] ? x86_swiotlb_alloc_coherent+0x61/0x70
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff8116fe4c>] ? dma_pool_alloc+0xfc/0x2a0
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff8106c500>] ? default_wake_function+0x0/0x20
Sep 29 12:02:38 test-dat-data kernel: [<ffffffffa012f480>] ? vmw_cmdbuf_alloc+0x80/0x290 [vmwgfx]
Sep 29 12:02:38 test-dat-data kernel: [<ffffffffa012f7b6>] ? vmw_cmdbuf_reserve+0x126/0x150 [vmwgfx]
Sep 29 12:02:38 test-dat-data kernel: [<ffffffffa012282e>] ? vmw_fifo_reserve_dx+0x3e/0x250 [vmwgfx]
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff810640d4>] ? find_busiest_group+0x254/0xa50
Sep 29 12:02:38 test-dat-data kernel: [<ffffffffa0122a53>] ? vmw_fifo_reserve+0x13/0x20 [vmwgfx]
Sep 29 12:02:38 test-dat-data kernel: [<ffffffffa0127b38>] ? do_dmabuf_define_gmrfb+0x48/0xc0 [vmwgfx]
Sep 29 12:02:38 test-dat-data kernel: [<ffffffffa0127d3b>] ? vmw_kms_sou_do_dmabuf_dirty+0x7b/0x110 [vmwgfx]
Sep 29 12:02:38 test-dat-data kernel: [<ffffffffa0069a37>] ? drm_modeset_lock+0x77/0x100 [drm]
Sep 29 12:02:38 test-dat-data kernel: [<ffffffffa00f9705>] ? __ttm_read_lock+0x25/0x90 [ttm]
Sep 29 12:02:38 test-dat-data kernel: [<ffffffffa00f9795>] ? ttm_read_lock+0x25/0x160 [ttm]
Sep 29 12:02:38 test-dat-data kernel: [<ffffffffa0118979>] ? vmw_framebuffer_dmabuf_dirty+0x149/0x1f0 [vmwgfx]
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff815489ce>] ? schedule+0x3ee/0xb70
Sep 29 12:02:38 test-dat-data kernel: [<ffffffffa011e340>] ? vmw_fb_dirty_flush+0x230/0x290 [vmwgfx]
Sep 29 12:02:38 test-dat-data kernel: [<ffffffffa011e110>] ? vmw_fb_dirty_flush+0x0/0x290 [vmwgfx]
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff8109fba0>] ? worker_thread+0x170/0x2a0
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff810a68a0>] ? autoremove_wake_function+0x0/0x40
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff8109fa30>] ? worker_thread+0x0/0x2a0
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff810a640e>] ? kthread+0x9e/0xc0
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff8100c28a>] ? child_rip+0xa/0x20
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff810a6370>] ? kthread+0x0/0xc0
Sep 29 12:02:38 test-dat-data kernel: [<ffffffff8100c280>] ? child_rip+0x0/0x20
其中page allocation failure这一句引起了我的注意，按照这个日志量我做了下分析，每分钟会产生上百条的提示信息，看起来似乎是内存层面有些紧张。 但是看下面的这个监控会发现，内存相对比较充足。
在我的印象中，我看到的很多OOM的日志基本就是这样的输出格式了，而且从实际的操作来看，会话操作时不时会卡住，完全不在状态，所以我打开了监控开始做初步udev分析。
系统层面的状态如下，可以看到内存使用率不到50%，而且这个服务器上也确实没有什么高负载的业务。可以看到在报警的时间段里，系统的负载开始瞬间提升了几个数量级，而实际上这个时间段里，这台服务器上没有什么外的擦偶作。
内存层面也没有看到有明显的异常，包括swap
经过排查，查到了一个相似的错误，说可能是kernel占用的缓存出现问题导致的bug,官方给出的一个WA方案如下，即修改两个内核参数。
Workaround
The following tunables can be used in an attempt to alleviate or prevent the reported condition:
-
Increase vm.min_free_kbytes value, for example to a higher value than a single allocation request.
-
Change vm.zone_reclaim_mode to 1 if it's set to zero, so the system can reclaim back memory from cached memory.
Both settings can be set in /etc/sysctl.conf, and loaded using sysctl -p /etc/sysctl.conf.
本来我还指望自己能像变魔法一样的修改参数让问题瞬间解决，但是按照这个步骤测试后，发现没有任何改进迹象。
因为这是测试环境，所以和业务同学做了初步确认之后，找系统的同学来看，还是建议使用保守的方案，升级内核来做。
升级内核的过程速度很快，使用yum update即可，因为提前做了快照，升级之后初步验证问题就瞬间解决了。
所以一个看起来极其简单的报警，可能在某种程度上会是一个潜在问题，一个潜在的问题也会有很多相关的潜在问题，而不断的积累处理问题的经验，也是逐步走向技术专家的一个必须之路。
