kern.log out of memory 好手才能解决

kern.log out of memory 高手才能解决
运行着的机器，突然某一天死机，查看日志后看到这些信息。

Sep  8 18:12:02 administrior-desktop kernel: [201869.997698] __ratelimit: 27 callbacks suppressed
Sep  8 18:12:07 administrior-desktop kernel: [201869.997702] ZR_HVRCE_WATCH invoked oom-killer: gfp_mask=0xd0, order=1, oom_adj=0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997705] ZR_HVRCE_WATCH cpuset=/ mems_allowed=0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997708] Pid: 2933, comm: ZR_HVRCE_WATCH Not tainted 2.6.32-28-generic #55-Ubuntu
Sep  8 18:12:07 administrior-desktop kernel: [201869.997710] Call Trace:
Sep  8 18:12:07 administrior-desktop kernel: [201869.997717]  [<c01cdcc4>] oom_kill_process+0xa4/0x2b0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997721]  [<c01ce339>] ? select_bad_process+0xa9/0xe0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997724]  [<c01ce3c1>] __out_of_memory+0x51/0xa0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997727]  [<c01ce468>] out_of_memory+0x58/0xb0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997731]  [<c01d0d47>] __alloc_pages_slowpath+0x487/0x4a0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997734]  [<c01d0e9a>] __alloc_pages_nodemask+0x13a/0x170
Sep  8 18:12:07 administrior-desktop kernel: [201869.997737]  [<c01d0eec>] __get_free_pages+0x1c/0x30
Sep  8 18:12:07 administrior-desktop kernel: [201869.997741]  [<c014a1bd>] dup_task_struct+0x3d/0x120
Sep  8 18:12:07 administrior-desktop kernel: [201869.997743]  [<c014b108>] copy_process+0x88/0xc20
Sep  8 18:12:07 administrior-desktop kernel: [201869.997747]  [<c02115e5>] ? alloc_pipe_info+0x25/0xb0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997749]  [<c020a8ff>] ? get_empty_filp+0xcf/0x1c0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997752]  [<c014bd23>] do_fork+0x83/0x3a0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997756]  [<c021189f>] ? do_pipe_flags+0xaf/0x110
Sep  8 18:12:07 administrior-desktop kernel: [201869.997759]  [<c0355309>] ? copy_to_user+0x39/0x130
Sep  8 18:12:07 administrior-desktop kernel: [201869.997762]  [<c0101a89>] sys_clone+0x39/0x50
Sep  8 18:12:07 administrior-desktop kernel: [201869.997764]  [<c01033ec>] syscall_call+0x7/0xb
Sep  8 18:12:07 administrior-desktop kernel: [201869.997766] Mem-Info:
Sep  8 18:12:07 administrior-desktop kernel: [201869.997767] DMA per-cpu:
Sep  8 18:12:07 administrior-desktop kernel: [201869.997769] CPU    0: hi:    0, btch:   1 usd:   0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997771] CPU    1: hi:    0, btch:   1 usd:   0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997772] CPU    2: hi:    0, btch:   1 usd:   0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997774] CPU    3: hi:    0, btch:   1 usd:   0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997775] Normal per-cpu:
Sep  8 18:12:07 administrior-desktop kernel: [201869.997777] CPU    0: hi:  186, btch:  31 usd:  30
Sep  8 18:12:07 administrior-desktop kernel: [201869.997778] CPU    1: hi:  186, btch:  31 usd:   0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997780] CPU    2: hi:  186, btch:  31 usd:   0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997781] CPU    3: hi:  186, btch:  31 usd:   0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997783] HighMem per-cpu:
Sep  8 18:12:07 administrior-desktop kernel: [201869.997784] CPU    0: hi:  186, btch:  31 usd:  28
Sep  8 18:12:07 administrior-desktop kernel: [201869.997786] CPU    1: hi:  186, btch:  31 usd:   0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997787] CPU    2: hi:  186, btch:  31 usd:   0 
 
Sep  8 18:12:07 administrior-desktop kernel: [201869.997789] CPU    3: hi:  186, btch:  31 usd:   0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997792] active_anon:173859 inactive_anon:48532 isolated_anon:0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997793]  active_file:7751 inactive_file:105247 isolated_file:0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997794]  unevictable:0 dirty:0 writeback:67 unstable:0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997795]  free:332753 slab_reclaimable:3016 slab_unreclaimable:198786
Sep  8 18:12:07 administrior-desktop kernel: [201869.997795]  mapped:2157 shmem:12 pagetables:1693 bounce:0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997801] DMA free:3508kB min:64kB low:80kB high:96kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15784kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:4960kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Sep  8 18:12:07 administrior-desktop kernel: [201869.997804] lowmem_reserve[]: 0 863 3449 3449
Sep  8 18:12:07 administrior-desktop kernel: [201869.997811] Normal free:9196kB min:3724kB low:4652kB high:5584kB active_anon:0kB inactive_anon:0kB active_file:112kB inactive_file:48kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:883896kB mlocked:0kB dirty:0kB writeback:0kB mapped:4kB shmem:0kB slab_reclaimable:12064kB slab_unreclaimable:790184kB kernel_stack:2504kB pagetables:52kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:111 all_unreclaimable? no
Sep  8 18:12:07 administrior-desktop kernel: [201869.997815] lowmem_reserve[]: 0 0 20692 20692
Sep  8 18:12:07 administrior-desktop kernel: [201869.997821] HighMem free:1318308kB min:512kB low:3300kB high:6092kB active_anon:695436kB inactive_anon:194128kB active_file:30892kB inactive_file:420940kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2648580kB mlocked:0kB dirty:0kB writeback:268kB mapped:8624kB shmem:48kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:6720kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Sep  8 18:12:07 administrior-desktop kernel: [201869.997825] lowmem_reserve[]: 0 0 0 0
Sep  8 18:12:07 administrior-desktop kernel: [201869.997828] DMA: 3*4kB 3*8kB 3*16kB 3*32kB 4*64kB 2*128kB 3*256kB 0*512kB 0*1024kB 1*2048kB 0*4096kB = 3508kB
Sep  8 18:12:07 administrior-desktop kernel: [201869.997837] Normal: 1843*4kB 138*8kB 1*16kB 12*32kB 3*64kB 1*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 9196kB
Sep  8 18:12:07 administrior-desktop kernel: [201869.997844] HighMem: 201*4kB 1463*8kB 14222*16kB 19706*32kB 5823*64kB 547*128kB 14*256kB 3*512kB 0*1024kB 0*2048kB 0*4096kB = 1318460kB
Sep  8 18:12:07 administrior-desktop kernel: [201869.997853] 113434 total pagecache pages
Sep  8 18:12:07 administrior-desktop kernel: [201869.997854] 376 pages in swap cache
Sep  8 18:12:07 administrior-desktop kernel: [201869.997856] Swap cache stats: add 92374, delete 91998, find 28664/30939
Sep  8 18:12:07 administrior-desktop kernel: [201869.997858] Free swap  = 1738696kB
Sep  8 18:12:07 administrior-desktop kernel: [201869.997859] Total swap = 1951736kB
Sep  8 18:12:07 administrior-desktop kernel: [201870.005558] 895657 pages RAM
Sep  8 18:12:07 administrior-desktop kernel: [201870.005560] 668347 pages HighMem
Sep  8 18:12:07 administrior-desktop kernel: [201870.005561] 15102 pages reserved
Sep  8 18:12:07 administrior-desktop kernel: [201870.005562] 132621 pages shared
Sep  8 18:12:07 administrior-desktop kernel: [201870.005563] 452971 pages non-shared
Sep  8 18:12:07 administrior-desktop kernel: [201870.005566] Out of memory: kill process 2933 (ZR_HVRCE_WATCH) score 18366 or a child
Sep  8 18:12:07 administrior-desktop kernel: [201870.005569] Killed process 16702 (ZR_HVRCE_MAIN) 
 
Sep  8 18:12:07 administrior-desktop kernel: [201870.132295] rsyslogd invoked oom-killer: gfp_mask=0xd0, order=1, oom_adj=0
Sep  8 18:12:07 administrior-desktop kernel: [201870.132305] rsyslogd cpuset=/ mems_allowed=0
Sep  8 18:12:07 administrior-desktop kernel: [201870.132312] Pid: 947, comm: rsyslogd Not tainted 2.6.32-28-generic #55-Ubuntu
Sep  8 18:12:07 administrior-desktop kernel: [201870.132317] Call Trace:

不太清楚OOM_killer杀死进程的机制是什么，我看了一些资料，/proc/[pid]/oom_score中记录着优先级别，score越大的，在系统资源临近枯竭时首先被杀死。
本人有几个疑点：
1. 从日志分析来看，出现Out of memory: kill process 2933 (ZR_HVRCE_WATCH) score 18366 or a child这句话后，进程并没有被杀死。是否直到出现Killed process 2933才表示该进程被杀死。
2. HighMem free:1318308kB present:2648580kB还有1G多的内存可用，为什么会out of memory呢？
最后我的系统是ubuntu10.04
还请高手帮忙！！！
不胜感激！
就剩这么点分了，全送出去了，有点对不起大家 linux memory
[解决办法]
通过调用栈可以看出系统中的确没有空闲页，所以导致内核oom_kill_process被调用。

[201869.997710] Call Trace:
[201869.997717]  [<c01cdcc4>] oom_kill_process+0xa4/0x2b0   
[201869.997721]  [<c01ce339>] ? select_bad_process+0xa9/0xe0         内核认为需要杀死进程获取空闲页
[201869.997724]  [<c01ce3c1>] __out_of_memory+0x51/0xa0
[201869.997727]  [<c01ce468>] out_of_memory+0x58/0xb0                 走到这里说明内核认为此时已经out_of_memory
[201869.997731]  [<c01d0d47>] __alloc_pages_slowpath+0x487/0x4a0        走到这里说明内核中的从freelist里没有分配到free page
[201869.997734]  [<c01d0e9a>] __alloc_pages_nodemask+0x13a/0x170          
[201869.997737]  [<c01d0eec>] __get_free_pages+0x1c/0x30       从这里看出正在分配空闲页
[201869.997741]  [<c014a1bd>] dup_task_struct+0x3d/0x120      复制task_struct时需要分配空间
...
[201869.997752]  [<c014bd23>] do_fork+0x83/0x3a0       创建进程
...
[201869.997764]  [<c01033ec>] syscall_call+0x7/0xb

[201870.005566] Out of memory: kill process 2933 (ZR_HVRCE_WATCH) score 18366 or a child
表示开始杀进程

[201870.005569] Killed process 16702 (ZR_HVRCE_MAIN)
进程被杀死
[解决办法]
2.6的内核oom是杀占用内存最大的进程

查看更多 下一篇