一、问题描述

某次某云主机访问异常,登录云主机后来发现vnc界面夯死,输入命令无反应,console界面发送重启指令也无反应,只能云平台管理页面强制重启。

二、问题分析:

1>重启后查看syslog日志发现,系统故障时间前后大量出现如下报错:

Linux中,默认日志服务为rsyslog,系统内核和许多程序会产生各种错误信息、警告信息和其他的提示信息都会写入到syslog日志中。

……
kernel: WARNING: [write_iter] inode ifops has restore
systemd-journald: Forwarding to syslog missed 1 messages
……
systemd: getty@tty1.service: Service has no hold-off time, scheduling restart.
systemd: Stopped Getty on tty1.
systemd: Started Getty on tty1.
kernel: WARNING: [write_iter] inode ifops has restore


再往前查看:

Jun  6 21:33:13 video-stream kernel: stream_convert invoked oom-killer: gfp_mask=0x24280ca, order=0, oom_score_adj=0
Jun  6 21:33:13 video-stream systemd-journald: Forwarding to syslog missed 6 messages.
Jun  6 21:33:13 video-stream kernel: stream_convert cpuset=4ebca70fe5bffef91f0e4d355ecceca3b977acdf70f519a9a7ffbc02f38c0613 mems_allowed=0
Jun  6 21:33:13 video-stream kernel: CPU: 7 PID: 11545 Comm: stream_convert Tainted: G           OE   4.4.0-150-generic #176-Ubuntu
Jun  6 21:33:13 video-stream kernel: Hardware name: Fedora Project OpenStack Nova, BIOS seabios-1.7.5-11.el7 04/01/2014
Jun  6 21:33:13 video-stream kernel: 0000000000000286 bc6e93ac5afb4302 ffff8804999cfad0 ffffffff8140b481
Jun  6 21:33:13 video-stream kernel: ffff8804999cfc88 ffff8801d9366200 ffff8804999cfb40 ffffffff8121888e
Jun  6 21:33:13 video-stream kernel: 0000000000000000 ffff880814d62c00 ffff88081351aa00 ffff8804999cfb28
Jun  6 21:33:13 video-stream kernel: Call Trace:
Jun  6 21:33:13 video-stream kernel: [<ffffffff8140b481>] dump_stack+0x63/0x82
Jun  6 21:33:13 video-stream kernel: [<ffffffff8121888e>] dump_header+0x5a/0x1c3
Jun  6 21:33:13 video-stream kernel: [<ffffffff813a2814>] ? apparmor_capable+0xc4/0x1b0
Jun  6 21:33:13 video-stream kernel: [<ffffffff8119c80b>] oom_kill_process+0x20b/0x3d0
Jun  6 21:33:13 video-stream kernel: [<ffffffff8119cc39>] out_of_memory+0x219/0x460
Jun  6 21:33:13 video-stream kernel: [<ffffffff811a2c53>] __alloc_pages_slowpath.constprop.88+0x943/0xaf0
Jun  6 21:33:13 video-stream kernel: [<ffffffff811a3088>] __alloc_pages_nodemask+0x288/0x2a0
Jun  6 21:33:13 video-stream kernel: [<ffffffff8185ebdd>] ? __schedule+0x30d/0x810
Jun  6 21:33:13 video-stream kernel: [<ffffffff811f00aa>] alloc_pages_vma+0xaa/0x270
Jun  6 21:33:13 video-stream kernel: [<ffffffff811ccba9>] handle_mm_fault+0x1439/0x1b80
Jun  6 21:33:13 video-stream kernel: [<ffffffff81419c24>] ? call_rwsem_down_read_failed+0x14/0x30
Jun  6 21:33:13 video-stream kernel: [<ffffffff8106ddf4>] __do_page_fault+0x1a4/0x410
Jun  6 21:33:13 video-stream kernel: [<ffffffff8106e0c7>] trace_do_page_fault+0x37/0xe0
Jun  6 21:33:13 video-stream kernel: [<ffffffff810660a9>] do_async_page_fault+0x19/0x70
Jun  6 21:33:13 video-stream kernel: [<ffffffff81866698>] async_page_fault+0x28/0x30
Jun  6 21:33:13 video-stream kernel: Mem-Info:
Jun  6 21:33:13 video-stream kernel: active_anon:7909729 inactive_anon:28750 isolated_anon:0#012 active_file:10180 inactive_file:9878 isolated_file:474#012 unevictable:1021 dirty:0 writeback:168 unstable:0#012 slab_reclaimable:124746 slab_unreclaimable:16959#012 mapped:8098 shmem:85614 pagetables:23340 bounce:0#012 free:52373 free_pcp:43 free_cma:0
Jun  6 21:33:13 video-stream kernel: Node 0 DMA free:15872kB min:32kB low:40kB high:48kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:32kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
Jun  6 21:33:13 video-stream kernel: lowmem_reserve[]: 0 2935 32117 32117 32117
Jun  6 21:33:13 video-stream kernel: Node 0 DMA32 free:132392kB min:6172kB low:7712kB high:9256kB active_anon:2708808kB inactive_anon:4456kB active_file:3692kB inactive_file:3632kB unevictable:880kB isolated(anon):0kB isolated(file):444kB present:3129212kB managed:3048336kB mlocked:880kB dirty:0kB writeback:0kB mapped:1952kB shmem:15860kB slab_reclaimable:130572kB slab_unreclaimable:7676kB kernel_stack:5328kB pagetables:7840kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:48596 all_unreclaimable? yes
Jun  6 21:33:13 video-stream kernel: lowmem_reserve[]: 0 0 29182 29182 29182
Jun  6 21:33:14 video-stream kernel: Node 0 Normal free:61228kB min:61376kB low:76720kB high:92064kB active_anon:28930108kB inactive_anon:110544kB active_file:37028kB inactive_file:35880kB unevictable:3204kB isolated(anon):0kB isolated(file):1452kB present:30408704kB managed:29882528kB mlocked:3204kB dirty:0kB writeback:672kB mapped:30440kB shmem:326596kB slab_reclaimable:368412kB slab_unreclaimable:60128kB kernel_stack:7264kB pagetables:85520kB unstable:0kB bounce:0kB free_pcp:172kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:528168 all_unreclaimable? yes
Jun  6 21:33:14 video-stream kernel: lowmem_reserve[]: 0 0 0 0 0
Jun  6 21:33:14 video-stream kernel: Node 0 DMA: 0*4kB 0*8kB 0*16kB 0*32kB 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15872kB
Jun  6 21:33:14 video-stream kernel: Node 0 DMA32: 2563*4kB (UMEH) 9038*8kB (UMEH) 3117*16kB (UMEH) 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 132428kB
Jun  6 21:33:14 video-stream kernel: Node 0 Normal: 9485*4kB (UMEH) 2433*8kB (UMEH) 228*16kB (UMEH) 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 61052kB
Jun  6 21:33:14 video-stream kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
Jun  6 21:33:14 video-stream kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
Jun  6 21:33:14 video-stream kernel: 106579 total pagecache pages
Jun  6 21:33:14 video-stream kernel: 0 pages in swap cache
Jun  6 21:33:14 video-stream kernel: Swap cache stats: add 0, delete 0, find 0/0
Jun  6 21:33:14 video-stream kernel: Free swap  = 0kB
Jun  6 21:33:14 video-stream kernel: Total swap = 0kB
Jun  6 21:33:14 video-stream kernel: 8388477 pages RAM
Jun  6 21:33:14 video-stream kernel: 0 pages HighMem/MovableOnly
Jun  6 21:33:14 video-stream kernel: 151785 pages reserved
Jun  6 21:33:14 video-stream kernel: 0 pages cma reserved
Jun  6 21:33:14 video-stream kernel: 0 pages hwpoisoned
Jun  6 21:33:14 video-stream kernel: [ pid ]   uid  tgid total_vm      rss nr_ptes nr_pmds swapents oom_score_adj name
Jun  6 21:33:14 video-stream kernel: [  999]     0   999    20193     9334      41       3        0             0 systemd-journal
Jun  6 21:33:14 video-stream kernel: [ 1047]     0  1047   173206      297      34       4        0             0 lvmetad
Jun  6 21:33:14 video-stream kernel: [ 1071]     0  1071    11363      857      24       3        0         -1000 systemd-udevd
Jun  6 21:33:14 video-stream kernel: [ 1119]   100  1119    25081      199      19       3        0             0 systemd-timesyn
Jun  6 21:33:14 video-stream kernel: [ 1725]     0  1725     4032      215      12       3        0             0 dhclient
Jun  6 21:33:14 video-stream kernel: [ 1839]     0  1839     7156      278      18       3        0             0 systemd-logind
Jun  6 21:33:14 video-stream kernel: [ 1841]   108  1841    10755      317      27       3        0          -900 dbus-daemon
Jun  6 21:33:14 video-stream kernel: [ 1851]     0  1851     6511      377      20       3        0             0 atd
Jun  6 21:33:14 video-stream kernel: [ 1854]     0  1854   130412      906      72       3        0             0 NetworkManager
Jun  6 21:33:14 video-stream kernel: [ 1863]     0  1863     6932      493      18       3        0             0 cron
un  6 21:33:14 video-stream kernel: [ 1867]     0  1867    58693       43      17       3        0             0 lxcfs
Jun  6 21:33:14 video-stream kernel: [ 1881]     0  1881     1099      292       8       3        0             0 acpid
Jun  6 21:33:14 video-stream kernel: [ 1885]     0  1885   138114     8659     135       4        0             0 rsyslogd
Jun  6 21:33:14 video-stream kernel: [ 1897]     0  1897    34398     2016      36       3        0             0 python
Jun  6 21:33:14 video-stream kernel: [ 1912]     0  1912     3343       50      11       3        0             0 mdadm
Jun  6 21:33:14 video-stream kernel: [ 1976]  1001  1976   179237      629      19       4        0             0 node_exporter
Jun  6 21:33:14 video-stream kernel: [ 1982]     0  1982    43333     2450      51       3        0             0 unattended-upgr
Jun  6 21:33:14 video-stream kernel: [ 1994]     0  1994   253929     5042      82       5        0             0 containerd
Jun  6 21:33:14 video-stream kernel: [ 2020]     0  2020    16378      532      36       3        0         -1000 sshd
Jun  6 21:33:14 video-stream kernel: [ 2028]     0  2028    69883      497      38       4        0             0 polkitd
Jun  6 21:33:14 video-stream kernel: [ 2044]     0  2044     4033      619      13       3        0             0 dhclient
Jun  6 21:33:14 video-stream kernel: [ 2072] 65534  2072    12896      485      29       3        0             0 dnsmasq
Jun  6 21:33:14 video-stream kernel: [ 2230]     0  2230     1305       29       9       3        0             0 iscsid
Jun  6 21:33:14 video-stream kernel: [ 2231]     0  2231     1430      882       9       3        0           -17 iscsid
Jun  6 21:33:14 video-stream kernel: [ 2299]     0  2299     3618      395      12       3        0             0 agetty
Jun  6 21:33:14 video-stream kernel: [ 2760]     0  2760     1111      405       8       3        0         -1000 watchdog
Jun  6 21:33:14 video-stream kernel: [ 3337]     0  3337     5884       49      17       3        0             0 rpc.idmapd
Jun  6 21:33:14 video-stream kernel: [ 3342]     0  3342    10862      892      26       3        0             0 rpc.mountd
Jun  6 21:33:14 video-stream kernel: [ 3404]     0  3404    11906      363      27       3        0             0 rpcbind
Jun  6 21:33:14 video-stream kernel: [ 3624]     0  3624   301432     9623     115       5        0          -500 dockerd
Jun  6 21:33:14 video-stream kernel: [ 7875]     0  7875    27277      193      11       4        0          -999 containerd-shim
Jun  6 21:33:14 video-stream kernel: [ 7892]     0  7892     1438      106       8       3        0             0 bash
Jun  6 21:33:14 video-stream kernel: [ 7929]     0  7929     1471      175       6       3        0             0 bash
Jun  6 21:33:14 video-stream kernel: [ 2502]     0  2502    27277      253      10       4        0          -999 containerd-shim
Jun  6 21:33:14 video-stream kernel: [ 2517]     0  2517     1126       17       8       3        0             0 sh
Jun  6 21:33:14 video-stream kernel: [ 2533]     0  2533 5369355814   758099    2247     254        0             0 RapidStor
Jun  6 21:33:14 video-stream kernel: [ 2672]     0  2672    26925      191       9       4        0          -999 containerd-shim
Jun  6 21:33:14 video-stream kernel: [ 2689]     0  2689     1126       18       8       3        0             0 sh
Jun  6 21:33:14 video-stream kernel: [ 2703]     0  2703 5369645817  1040585    3051     255        0             0 RapidStor
Jun  6 21:33:14 video-stream kernel: [19425]     0 19425     1471      180       6       3        0             0 bash
Jun  6 21:33:14 video-stream kernel: [29971]     0 29971    26925      197      10       4        0          -999 containerd-shim
Jun  6 21:33:14 video-stream kernel: [29986]     0 29986     1126       17       8       3        0             0 sh
Jun  6 21:33:14 video-stream kernel: [30002]     0 30002 5369769857  6006959   16123     276        0             0 stream_convert
Jun  6 21:33:14 video-stream kernel: [22234]     0 22234   466558     9673     145       5        0             0 sdatad
Jun  6 21:33:14 video-stream kernel: [22267]     0 22267  1365401     1165     266       8        0             0 srepd
Jun  6 21:33:14 video-stream kernel: [22440]     0 22440   185308     1148      97       4        0             0 rpcserver
Jun  6 21:33:14 video-stream kernel: [22466]     0 22466   249034      436      45       4        0             0 sdatalogd
Jun  6 21:33:14 video-stream kernel: [22478]     0 22478   161010      389      74       3        0             0 I2Availability
Jun  6 21:33:14 video-stream kernel: [22480]     0 22480    22818       50      15       3        0             0 i2monitor
Jun  6 21:33:14 video-stream kernel: [22483]     0 22483    51541      399      63       4        0             0 HaDetector
Jun  6 21:33:14 video-stream kernel: [22498]     0 22498    41655      514      55       3        0             0 collector
Jun  6 21:33:14 video-stream kernel: [22500]     0 22500    41951      377      56       3        0             0 TapeMgr
Jun  6 21:33:14 video-stream kernel: [27820]     0 27820     3664      352      11       3        0             0 agetty
Jun  6 21:33:14 video-stream kernel: Out of memory: Kill process 30002 (stream_convert) score 731 or sacrifice child
Jun  6 21:33:14 video-stream kernel: Killed process 30002 (stream_convert) total-vm:21479079428kB, anon-rss:24027836kB, file-rss:0kB
Jun  6 21:33:17 video-stream containerd: time="2022-06-06T21:33:17.535433701+08:00" level=info msg="shim reaped" id=4ebca70fe5bffef91f0e4d355ecceca3b977acdf70f519a9a7ffbc02f38c0613
Jun  6 21:33:17 video-stream dockerd: time="2022-06-06T21:33:17.620768383+08:00" level=info msg="ignoring event" module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Jun  6 21:33:19 video-stream containerd: time="2022-06-06T21:33:19.234553076+08:00" level=info msg="shim containerd-shim started" address="/containerd-shim/moby/4ebca70fe5bffef91f0e4d355ecceca3b977acdf70f519a9a7ffbc02f38c0613/shim.sock" debug=false pid=11835
Jun  6 21:33:21 video-stream kernel: WARNING: [write_iter] inode ifops has restore.
Jun  6 21:33:21 video-stream kernel: WARNING: [write_iter] inode ifops has restore.
Jun  6 21:33:31 video-stream kernel: WARNING: [write_iter] inode ifops has restore.
Jun  6 21:33:41 video-stream kernel: WARNING: [write_iter] inode ifops has restore.
Jun  6 21:33:51 video-stream kernel: WARNING: [write_iter] inode ifops has restore.

从上述日志可看到有OOM报错及相关内存错误,之后便开始大量出现[write_iter] inode ifops has restore。OOM发送在大量使用swap之后,会kill掉内存占用最大的进程。这是操作系统系统自身的一种保护机制,以防更多的进程不能正常工作。


一个进程的异常终止,通常有两种情况,一种是crash,另一种是被kill掉了。crash是指程序出现了自己无法解决的异常情况,只能终止。

kill -l #查看系统所有的信号

	信号    值 处理动作 发出信号的原因 
  ---------------------------------------------------------------------- 
  SIGHUP  1   A   终端挂起或者控制进程终止 
  SIGINT   2   A   键盘中断(如break键被按下) 
  SIGQUIT   3   C   键盘的退出键被按下 
  SIGILL    4   C   非法指令 
  SIGABRT  6   C   由abort(3)发出的退出指令 
  SIGFPE    8   C   浮点异常 
  SIGKILL  9   AEF  Kill信号 
  SIGSEGV   11   C  无效的内存引用 
  SIGPIPE  13   A  管道破裂: 写一个没有读端口的管道 
  SIGALRM 14    A  由alarm(2)发出的信号 
  SIGTERM 15    A  终止信号 
  SIGUSR1  30,10,16 A  用户自定义信号1 
  SIGUSR2  31,12,17 A  用户自定义信号2 
  SIGCHLD  20,17,18 B    子进程结束信号 
  SIGCONT  19,18,25       进程继续(曾被停止的进程) 
  SIGSTOP  17,19,23 DEF 终止进程 
  SIGTSTP  18,20,24 D 控制终端(tty)上按下停止键 
  SIGTTIN   21,21,26 D 后台进程企图从控制终端读 
  SIGTTOU 22,22,27 D 后台进程企图从控制终端写 

#信号动作说明
   A  缺省的动作是终止进程
  B  缺省的动作是忽略此信号
  C  缺省的动作是终止进程并进行内核映像转储(dump core)
  D  缺省的动作是停止进程
  E  信号不能被捕获
  F  信号不能被忽略


strace -T -tt -e trace=all -p pid  #来跟踪分析程序

一般机器僵死,通常是Kernel出现了死锁,而Kernel不会知道自己死锁了,所以也不会在屏幕上显示相关信息。这时,可尝试使用Kernel的Debug工具来对vmcore进行分析,可以参考如下文章:http://people.redhat/anderson/crash_whitepaper/;另外可参看pstore 实现自动“抓捕”内核崩溃日志来分析。也可在/var/crash目录找到了当天生成的vmcore文件,使用crash工具分析vmcore文件。

2>查看上次重启时间

last | grep reboot  #输出如下,上次重启为4月份

reboot   system boot  4.4.0-150-generi Wed Jun  8 10:10   still running
reboot   system boot  4.4.0-150-generi Wed Apr  6 20:21   still running
reboot   system boot  4.4.0-150-generi Tue Mar 29 17:46   still running
reboot   system boot  4.4.0-150-generi Tue Oct 26 20:44   still running
reboot   system boot  4.4.0-150-generi Mon Oct 26 19:38   still running

last reboot | head -1 #查看最近一条Linux操作系统重启记录
last -x|grep shutdown | head -1  #查看上一次关机日期和时间,但可能并不能找出系统Linux操作系统非正常关机的情形
last -F |grep carsh #查看上一次宕机记录

3> 内核core信息查看

程序异常退出时,内核会生成一个core文件(内存映像以及一些调试信息);可以通过使用gdb来查看core文件,从而知道指示出导致程序出错的代码所在的文件和行数。我们可利用coredump技术追查进程崩溃原因;

ulimit -c  #查看core文件的生成开关,若结果为0,则便是关闭了此功能,不会生成core文件
ulimit -c unlimited #标识此core文件的大小不受限制,程序异常宕的是啥会生产一个core文件
ulimit -c filesize  #指定filesize,如果生成的信息超过此大小,将会被裁剪,最终生成一个不完整的core文件,在调试此core文件时,gdb会提示错误
ulimit -c 1024  #设置core文件的大小为1024K,只在当前shell下生效,永久生效在/etc下profile文件末尾加 ulimit -c 1024
#全局生效
vi /root/.bash_profile  #加入ulitmit -S -c unlimited
source /root/.bash_profile

cat /proc/sys/kernel/core_uses_pid
echo "1" > /proc/sys/kernel/core_uses_pid

echo "/var/corefile/core-%e-%p-%t" > core_pattern #将core文件统一生成到/var/corefile目录,以下为参数说明:
%p - insert pid into filename 添加pid
%u - insert current uid into filename 添加当前uid
%g - insert current gid into filename 添加当前gid
%s - insert signal that caused the coredump into the filename 添加导致产生core的 信号
%t - insert  UNIX time that the coredump occurred into filename 添加core文件生成 的unix时间
%h - insert hostname where the coredump happened into filename 添加主机名
%e - insert coredumping executable name into filename 添加命令名

echo "./dump-%t-%e-%s-%p-%g-%u" > /proc/sys/kernel/core_pattern
#core文件查看
gdb -core=core.xxxx
file ./a.out
bt
#或通过gdb 程序名 core文件名,然后通过bt或者where查看程序崩溃时的堆栈信息
gdb test core.8482
  
#启用打开core dump,默认不开启;core dump文件的默认位置与可执行程序在同一目录下
vi ~/.bash_profile		#加入ulimit -S -c unlimited > /dev/null 2>&1
vi /etc/security/limits.conf  #增加
* soft core 0  #对所有用户打开core dump
user soft core 0或@group soft core 0  #只对某些用户或用户组打开core dump
#ulimit -S -c 0 > /dev/null 2>&1 #注释掉
#core dump文件名的模式保存在/proc/sys/kernel/core_pattern中,缺省值是core;以更改core dump文件的位置
echo "/tmp/cores/core" > /proc/sys/kernel/core_pattern #更改位置到/tmp/cores下

在stack trace的信息里,可借助nm、addr2line分析,查看函数地址的指令,用法如下:

nm -C [appName] | grep [functionName]

nm -C [libName] | grep [functionName]

#查看异常所在的代码行数:

addr2line -e [appName] [address]

addr2line -e [libName] [address]

#反汇编出现死机的内核模块
objdump -D -l raid456.ko > /home/md.txt #查看/home/md.txt 并查找raid5d_second函数的地址,定位到如下带有<>符号的位置
000000000000bae0 <raid5d_second>:  ##前面的地址即该函数的地址

注意:/proc/sys/kernel/core_uses_pid可以控制core文件的文件名是否添加PID作为扩展,如果值为0,表示未启用,生成的core文件统一命名为core,否则生成的core文件格式为core.XXXX;

4>通过dmesg(display message)命令显示内核环形缓冲区的消息,从而可查看进程崩溃的相关信,主要有:

在内核中列出所有加载的驱动程序

列出所有检测到的设备

在操作级别获得大量系统信息,如系统架构、CPU、安装的硬件、ram等

显示开机信息,系统在引导过程中的各种事件信息;kernel 会将开机信息存储在 ring buffer 中

运行dmesg时,它会显示大量信息。dmesg的输出通常配合less或grep查看;执行:dmesg -c 清除dmesg缓冲区日志

dmesg -d -T |grep -i Memory #便于阅读的方式显示日志日期和时间
dmesg -l warn  #查看指定级别日志,有:
emerg - 系统无法使用
alert - 操作必须立即执行
crit - 紧急条件
err - 错误条件
warn - 警告条件
notice - 正常但重要的条件
info - 信息
debug - 调试级别的消息

5>检查message日志

/var/log/messages该日志文件是许多进程日志文件的汇总,系统启动后的信息和错误日志, 它是linux的公共日志文件,记录Linux内核消息及各种应用程序的公共日志信息,包括启动、IO错误、网络错误、程序故障等。对于未使用独立日志文件的应用程序或服务,一般都可以从该文件获得相关的事件记录信息。

cat /var/log/messages |grep "oom" -C 20





其中,上图中的RSS(Resident Set Size)是某进程实际使用物理内存,不仅仅是自己程序使用的物理内存,也包含共享库占用的内存。linux下允许程序申请比系统可用内存更多的内存,这个特性叫Overcommit。这样做是出于优化系统考虑,因为不是所有的程序申请了内存就立刻使用的,当你使用的时候说不定系统已经回收了一些资源了。不幸的是,当你用到这个Overcommit给你的内存的时候,系统还没有资源的话,OOM killer就跳出来了。

综上,本次Linux系统僵死可能还是出现在内核层面,且跟应用程序的内存有关。这种情况可能是因系统配置不合理,出现类似小马拉大车情况,linux kernel运行非常缓慢并且在某个时间点分配page frame的时候遇到内存耗尽、无法分配的状况,系统就会夯死。当kernel遇到OOM的时候,可以有两种选择:

(1)产生kernel panic(死给你看)。

(2)积极面对,选择一个或者几个最“适合”的进程,主动调用OOM killer,干掉那些选中的进程,释放内存,让系统勇继续活下去。现场实际,panic_on_oom是启用主动发起OOM killer的

cat /proc/sys/vm/panic_on_oom #panic_on_oom这个参数就是控制遇到OOM的时候,系统如何反应的。当该参数等于0的时候,表示选择积极面对人生,启动OOM killer。当该参数等于2的时候,表示无论是哪一种情况,都强制进入kernel panic。其他值时,看情况;

cat /proc/sys/vm/overcommit_memory  #控制进程对内存过量使用的应对策略
1.当overcommit_memory=0 允许进程轻微过量使用内存,但对于大量过载请求则不允许,也就是当内存消耗过大就是触发OOM killer。
2.当overcommit_memory=1 永远允许进程overcommit,不会触发OOM killer。
3.当overcommit_memory=2 永远禁止overcommit,不会触发OOM killer。

/proc/[pid]/oom_adj,该pid进程被oom killer杀掉的权重,介于 [-17,15](具体具体权重的范围需要查看内核确认)之间,越高的权重,意味着更可能被oom killer选中,-17表示禁止被kill掉。ubuntu的执行如下命令查看具体的权重范围

cat /usr/src/linux-headers-4.4.0-150-generic/include/linux/oom.h

./proc/[pid]/oom_score,当前该pid进程的被kill的分数,越高的分数意味着越可能被kill,这个数值是根据oom_adj运算(2ⁿ,n就是oom_adj的值)后的结果。当OOM Killer被启动时,通过观察进程自动计算得出各当前进程的得分 /proc//oom_score,分值越高越容易被kill掉。

echo -17 > /proc/PID/oom_score_adj #输入-17,禁止被OOM机制处理
#关闭OOM机制(不推荐,如果不启动OOM机制,内存使用过大,会让系统产生很多异常数据),等于0时,表示当内存耗尽时,内核会触发OOM killer杀掉最耗内存的进程。
echo "vm.panic_on_oom=1" >> /etc/sysctl.conf
systcl -p

附录

也可以借助如Webalizer、Awstats(图形化)等专用日志分析工具来分析。

1、oom_adj、oom_score和oom_score

这几个参数都是和具体进程相关的,因此它们位于/proc/xxx/目录下(xxx是进程ID)。假设我们选择在出现OOM状况的时候杀死进程,那么一个很自然的问题就浮现出来:到底干掉哪一个呢?内核的算法倒是非常简单,那就是打分(oom_score,注意,该参数是read only的),找到分数最高的就OK了。大致过程如下:

(1)对某一个task进行打分(oom_score)主要有两部分组成,一部分是系统打分,主要是根据该task的内存使用情况。另外一部分是用户打分,也就是oom_score_adj了,该task的实际得分需要综合考虑两方面的打分。如果用户将该task的 oom_score_adj设定成OOM_SCORE_ADJ_MIN(-1000)的话,那么实际上就是禁止了OOM killer杀死该进程。

(2)oom_score返回了0也就是告知OOM killer,该进程是“good process”,不要干掉它。实际计算分数的时候最低分是1分。

(3)系统打分就是看物理内存消耗量,主要是三部分,RSS部分,swap file或者swap device上占用的内存情况以及页表占用的内存情况。

(4)root进程有3%的内存使用特权,因此这里要减去那些内存使用量。

(5)用户可以调整oom_score,具体如何操作呢?oom_score_adj的取值范围是-1000~1000,0表示用户不调整oom_score,负值表示要在实际打分值上减去一个折扣,正值表示要惩罚该task,也就是增加该进程的oom_score。在实际操作中,需要根据本次内存分配时候可分配内存来计算(如果没有内存分配约束,那么就是系统中的所有可用内存,如果系统支持cpuset,那么这里的可分配内存就是该cpuset的实际额度值)。oom_badness函数有一个传入参数totalpages,该参数就是当时的可分配的内存上限值。实际的分数值(points)要根据oom_score_adj进行调整,例如如果oom_score_adj设定-500,那么表示实际分数要打五折(基数是totalpages),也就是说该任务实际使用的内存要减去可分配的内存上限值的一半。

更多推荐

Linux系统异常夯死或宕机分析