[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Why was oom-killer invoked?



Hi,

Please help me understand why oom-killer was invoked?

From the SAR logs we can see that there is lots of memory in use by the system cache, but free is low.  How can we ensure there is more memory available in free to avoid triggering oom-killer?

From Kernel Log:
Mar 16 23:30:06 kernel: [49173666.630999] postgres invoked oom-killer: gfp_mask=0xd0, order=0, oomkilladj=0
Mar 16 23:30:06 kernel: [49173666.631008] Pid: 14865, comm: postgres Not tainted 2.6.26-2-686-bigmem #1
Mar 16 23:30:06 kernel: [49173666.631019]  [<c016004e>] oom_kill_process+0x4f/0x195
Mar 16 23:30:06 kernel: [49173666.631028]  [<c0160478>] out_of_memory+0x14e/0x17f
Mar 16 23:30:06 kernel: [49173666.631032]  [<c01623e0>] __alloc_pages_internal+0x2b8/0x34e
Mar 16 23:30:06 kernel: [49173666.631037]  [<c0162482>] __alloc_pages+0x7/0x9
Mar 16 23:30:06 kernel: [49173666.631041]  [<c028cdd1>] tcp_sendmsg+0x41b/0x8d9
Mar 16 23:30:06 kernel: [49173666.631048]  [<c029468c>] tcp_current_mss+0xaa/0xc8
Mar 16 23:30:06 kernel: [49173666.631052]  [<c025fc13>] sock_sendmsg+0xc7/0xe1
Mar 16 23:30:06 kernel: [49173666.631058]  [<c0138850>] autoremove_wake_function+0x0/0x2d
Mar 16 23:30:06 kernel: [49173666.631062]  [<c029ad8e>] tcp_v4_rcv+0x545/0x597
Mar 16 23:30:06 kernel: [49173666.631066]  [<c028368f>] ip_local_deliver_finish+0xe8/0x183
Mar 16 23:30:06 kernel: [49173666.631069]  [<c028358a>] ip_rcv_finish+0x286/0x2a3
Mar 16 23:30:06 kernel: [49173666.631075]  [<c02604f7>] sys_sendto+0x105/0x130
Mar 16 23:30:06 kernel: [49173666.631077]  [<c013e5e2>] clocksource_get_next+0x39/0x3f
Mar 16 23:30:06 kernel: [49173666.631081]  [<c013d5da>] update_wall_time+0x519/0x68f
Mar 16 23:30:06 kernel: [49173666.631087]  [<c013aaa4>] hrtimer_forward+0xe4/0x100
Mar 16 23:30:06 kernel: [49173666.631090]  [<c013cfc4>] getnstimeofday+0x37/0xbc
Mar 16 23:30:06 kernel: [49173666.631095]  [<c026053b>] sys_send+0x19/0x1d
Mar 16 23:30:06 kernel: [49173666.631098]  [<c0260dd3>] sys_socketcall+0xed/0x19e
Mar 16 23:30:06 kernel: [49173666.631102]  [<c010afdb>] do_IRQ+0x52/0x63
Mar 16 23:30:06 kernel: [49173666.631106]  [<c0108857>] sysenter_past_esp+0x78/0xb1
Mar 16 23:30:06 kernel: [49173666.631111]  =======================
Mar 16 23:30:06 kernel: [49173666.631113] Mem-info:
Mar 16 23:30:06 kernel: [49173666.631114] DMA per-cpu:
Mar 16 23:30:06 kernel: [49173666.631116] CPU    0: hi:    0, btch:   1 usd:   0
Mar 16 23:30:06 kernel: [49173666.631117] CPU    1: hi:    0, btch:   1 usd:   0
Mar 16 23:30:06 kernel: [49173666.631119] CPU    2: hi:    0, btch:   1 usd:   0
Mar 16 23:30:06 kernel: [49173666.631120] CPU    3: hi:    0, btch:   1 usd:   0
Mar 16 23:30:06 kernel: [49173666.631122] Normal per-cpu:
Mar 16 23:30:06 kernel: [49173666.631123] CPU    0: hi:  186, btch:  31 usd: 181
Mar 16 23:30:06 kernel: [49173666.631125] CPU    1: hi:  186, btch:  31 usd: 179
Mar 16 23:30:06 kernel: [49173666.631126] CPU    2: hi:  186, btch:  31 usd: 174
Mar 16 23:30:06 kernel: [49173666.631128] CPU    3: hi:  186, btch:  31 usd: 166
Mar 16 23:30:06 kernel: [49173666.631129] HighMem per-cpu:
Mar 16 23:30:06 kernel: [49173666.631131] CPU    0: hi:  186, btch:  31 usd: 160
Mar 16 23:30:06 kernel: [49173666.631132] CPU    1: hi:  186, btch:  31 usd:  15
Mar 16 23:30:06 kernel: [49173666.631134] CPU    2: hi:  186, btch:  31 usd: 126
Mar 16 23:30:06 kernel: [49173666.631135] CPU    3: hi:  186, btch:  31 usd: 150
Mar 16 23:30:06 kernel: [49173666.631138] Active:1648305 inactive:211079 dirty:222 writeback:0 unstable:0
Mar 16 23:30:06 kernel: [49173666.631139]  free:8709 slab:11962 mapped:539697 pagetables:188949 bounce:0
Mar 16 23:30:06 kernel: [49173666.631142] DMA free:3544kB min:68kB low:84kB high:100kB active:8kB inactive:4kB present:16256k
B pages_scanned:0 all_unreclaimable? no
Mar 16 23:30:06 kernel: [49173666.631144] lowmem_reserve[]: 0 873 9128 9128
Mar 16 23:30:06 kernel: [49173666.631148] Normal free:3652kB min:3744kB low:4680kB high:5616kB active:320kB inactive:184kB pr
esent:894080kB pages_scanned:1012 all_unreclaimable? yes
Mar 16 23:30:06 kernel: [49173666.631151] lowmem_reserve[]: 0 0 66040 66040
Mar 16 23:30:06 kernel: [49173666.631155] HighMem free:27640kB min:512kB low:9368kB high:18228kB active:6592892kB inactive:84
4128kB present:8453120kB pages_scanned:0 all_unreclaimable? no
Mar 16 23:30:06 kernel: [49173666.631157] lowmem_reserve[]: 0 0 0 0
Mar 16 23:30:06 kernel: [49173666.631160] DMA: 387*4kB 1*8kB 1*16kB 1*32kB 1*64kB 1*128kB 1*256kB 1*512kB 1*1024kB 0*2048kB 0
*4096kB = 3588kB
Mar 16 23:30:06 kernel: [49173666.631167] Normal: 21*4kB 6*8kB 2*16kB 3*32kB 1*64kB 1*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB
 0*4096kB = 3780kB
Mar 16 23:30:06 kernel: [49173666.631173] HighMem: 2228*4kB 2061*8kB 1*16kB 1*32kB 1*64kB 1*128kB 1*256kB 1*512kB 1*1024kB 0*
2048kB 0*4096kB = 27432kB
Mar 16 23:30:06 kernel: [49173666.631182] 1086618 total pagecache pages
Mar 16 23:30:06 kernel: [49173666.631184] Swap cache: add 28233, delete 28233, find 12822/15537
Mar 16 23:30:06 kernel: [49173666.631186] Free swap  = 995184kB
Mar 16 23:30:06 kernel: [49173666.631187] Total swap = 995988kB
Mar 16 23:30:06 kernel: [49173666.669460] 2359296 pages of RAM
Mar 16 23:30:06 kernel: [49173666.669463] 2129920 pages of HIGHMEM
Mar 16 23:30:06 kernel: [49173666.669465] 281785 reserved pages
Mar 16 23:30:06 kernel: [49173666.669466] 46131460 pages shared
Mar 16 23:30:06 kernel: [49173666.669467] 0 pages swap cached
Mar 16 23:30:06 kernel: [49173666.669468] 222 pages dirty
Mar 16 23:30:06 kernel: [49173666.669470] 0 pages writeback
Mar 16 23:30:06 kernel: [49173666.669471] 539697 pages mapped
Mar 16 23:30:06 kernel: [49173666.669472] 11962 pages slab
Mar 16 23:30:06 kernel: [49173666.669473] 188949 pages pagetables
Mar 16 23:30:06 kernel: [49173666.669476] Out of memory: kill process 27302 (postgres) score 337392 or a child
Mar 16 23:30:06 kernel: [49173666.669567] Killed process 27304 (postgres)




Mar 16 23:30:06 kernel: [49173666.712469] postgres invoked oom-killer: gfp_mask=0xd0, order=0, oomkilladj=0
Mar 16 23:30:06 kernel: [49173666.712474] Pid: 14865, comm: postgres Not tainted 2.6.26-2-686-bigmem #1
Mar 16 23:30:06 kernel: [49173666.712489]  [<c016004e>] oom_kill_process+0x4f/0x195
Mar 16 23:30:06 kernel: [49173666.712500]  [<c0160478>] out_of_memory+0x14e/0x17f
Mar 16 23:30:06 kernel: [49173666.712505]  [<c01623e0>] __alloc_pages_internal+0x2b8/0x34e
Mar 16 23:30:06 kernel: [49173666.712510]  [<c0162482>] __alloc_pages+0x7/0x9
Mar 16 23:30:06 kernel: [49173666.712513]  [<c028cdd1>] tcp_sendmsg+0x41b/0x8d9
Mar 16 23:30:06 kernel: [49173666.712521]  [<c029468c>] tcp_current_mss+0xaa/0xc8
Mar 16 23:30:06 kernel: [49173666.712525]  [<c025fc13>] sock_sendmsg+0xc7/0xe1
Mar 16 23:30:06 kernel: [49173666.712532]  [<c0138850>] autoremove_wake_function+0x0/0x2d
Mar 16 23:30:06 kernel: [49173666.712537]  [<c029ad8e>] tcp_v4_rcv+0x545/0x597
Mar 16 23:30:06 kernel: [49173666.712541]  [<c028368f>] ip_local_deliver_finish+0xe8/0x183
Mar 16 23:30:06 kernel: [49173666.712544]  [<c028358a>] ip_rcv_finish+0x286/0x2a3
Mar 16 23:30:06 kernel: [49173666.712547]  [<c0268d31>] netif_receive_skb+0x31c/0x349
Mar 16 23:30:06 kernel: [49173666.712553]  [<c02604f7>] sys_sendto+0x105/0x130
Mar 16 23:30:06 kernel: [49173666.712556]  [<c013e5e2>] clocksource_get_next+0x39/0x3f
Mar 16 23:30:06 kernel: [49173666.712561]  [<c013d5da>] update_wall_time+0x519/0x68f
Mar 16 23:30:06 kernel: [49173666.712567]  [<c013aaa4>] hrtimer_forward+0xe4/0x100
Mar 16 23:30:06 kernel: [49173666.712570]  [<c013cfc4>] getnstimeofday+0x37/0xbc
Mar 16 23:30:06 kernel: [49173666.712575]  [<c026053b>] sys_send+0x19/0x1d
Mar 16 23:30:06 kernel: [49173666.712578]  [<c0260dd3>] sys_socketcall+0xed/0x19e
Mar 16 23:30:06 kernel: [49173666.712582]  [<c010afdb>] do_IRQ+0x52/0x63
Mar 16 23:30:06 kernel: [49173666.712586]  [<c0108857>] sysenter_past_esp+0x78/0xb1
Mar 16 23:30:06 kernel: [49173666.712598]  =======================
Mar 16 23:30:06 kernel: [49173666.712600] Mem-info:
Mar 16 23:30:06 kernel: [49173666.712601] DMA per-cpu:
Mar 16 23:30:06 kernel: [49173666.712603] CPU    0: hi:    0, btch:   1 usd:   0
Mar 16 23:30:06 kernel: [49173666.712604] CPU    1: hi:    0, btch:   1 usd:   0
Mar 16 23:30:06 kernel: [49173666.712606] CPU    2: hi:    0, btch:   1 usd:   0
Mar 16 23:30:06 kernel: [49173666.712607] CPU    3: hi:    0, btch:   1 usd:   0
Mar 16 23:30:06 kernel: [49173666.712609] Normal per-cpu:
Mar 16 23:30:06 kernel: [49173666.712610] CPU    0: hi:  186, btch:  31 usd: 156
Mar 16 23:30:06 kernel: [49173666.712612] CPU    1: hi:  186, btch:  31 usd: 155
Mar 16 23:30:06 kernel: [49173666.712614] CPU    2: hi:  186, btch:  31 usd: 177
Mar 16 23:30:06 kernel: [49173666.712615] CPU    3: hi:  186, btch:  31 usd: 180
Mar 16 23:30:06 kernel: [49173666.712616] HighMem per-cpu:
Mar 16 23:30:06 kernel: [49173666.712618] CPU    0: hi:  186, btch:  31 usd: 159
Mar 16 23:30:06 kernel: [49173666.712620] CPU    1: hi:  186, btch:  31 usd:  13
Mar 16 23:30:06 kernel: [49173666.712621] CPU    2: hi:  186, btch:  31 usd: 126
Mar 16 23:30:06 kernel: [49173666.712623] CPU    3: hi:  186, btch:  31 usd: 149
Mar 16 23:30:06 kernel: [49173666.712625] Active:1647934 inactive:211078 dirty:3 writeback:0 unstable:0
Mar 16 23:30:06 kernel: [49173666.712626]  free:9053 slab:11962 mapped:537653 pagetables:188949 bounce:0
Mar 16 23:30:06 kernel: [49173666.712629] DMA free:3544kB min:68kB low:84kB high:100kB active:0kB inactive:44kB present:16256
kB pages_scanned:33 all_unreclaimable? no
Mar 16 23:30:06 kernel: [49173666.712632] lowmem_reserve[]: 0 873 9128 9128
Mar 16 23:30:06 kernel: [49173666.712636] Normal free:3852kB min:3744kB low:4680kB high:5616kB active:332kB inactive:140kB pr
esent:894080kB pages_scanned:917 all_unreclaimable? yes
Mar 16 23:30:06 kernel: [49173666.712638] lowmem_reserve[]: 0 0 66040 66040
Mar 16 23:30:06 kernel: [49173666.712642] HighMem free:28816kB min:512kB low:9368kB high:18228kB active:6591432kB inactive:84
4128kB present:8453120kB pages_scanned:0 all_unreclaimable? no
Mar 16 23:30:06 kernel: [49173666.712644] lowmem_reserve[]: 0 0 0 0
Mar 16 23:30:06 kernel: [49173666.712647] DMA: 388*4kB 1*8kB 1*16kB 1*32kB 1*64kB 1*128kB 1*256kB 1*512kB 1*1024kB 0*2048kB 0
*4096kB = 3592kB
Mar 16 23:30:06 kernel: [49173666.712654] Normal: 83*4kB 6*8kB 2*16kB 3*32kB 1*64kB 1*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB
 0*4096kB = 4028kB
Mar 16 23:30:06 kernel: [49173666.712661] HighMem: 2565*4kB 2063*8kB 1*16kB 1*32kB 1*64kB 1*128kB 1*256kB 1*512kB 1*1024kB 0*
2048kB 0*4096kB = 28796kB
Mar 16 23:30:06 kernel: [49173666.712668] 1086618 total pagecache pages
Mar 16 23:30:06 kernel: [49173666.712670] Swap cache: add 28233, delete 28233, find 12822/15537
Mar 16 23:30:06 kernel: [49173666.712671] Free swap  = 995184kB
Mar 16 23:30:06 kernel: [49173666.712673] Total swap = 995988kB
Mar 16 23:30:06 kernel: [49173666.739537] 2359296 pages of RAM
Mar 16 23:30:06 kernel: [49173666.739537] 2129920 pages of HIGHMEM
Mar 16 23:30:06 kernel: [49173666.739537] 281785 reserved pages
Mar 16 23:30:06 kernel: [49173666.739537] 45818784 pages shared
Mar 16 23:30:06 kernel: [49173666.739537] 0 pages swap cached
Mar 16 23:30:06 kernel: [49173666.739537] 3 pages dirty
Mar 16 23:30:06 kernel: [49173666.739537] 0 pages writeback
Mar 16 23:30:06 kernel: [49173666.739537] 536777 pages mapped
Mar 16 23:30:06 kernel: [49173666.739537] 11962 pages slab
Mar 16 23:30:06 kernel: [49173666.739537] 188949 pages pagetables
Mar 16 23:30:06 kernel: [49173666.739537] Out of memory: kill process 27302 (postgres) score 335971 or a child
Mar 16 23:30:06 kernel: [49173666.739537] Killed process 27305 (postgres)

Output from SAR:
22:05:01        28904   8281140     99.65     10552   4357216    995184       804      0.08         0
22:15:02        27056   8282988     99.67     11428   4357428    995184       804      0.08         0
22:25:01        26740   8283304     99.68     10404   4359928    995184       804      0.08         0
22:35:01        27020   8283024     99.67     11748   4357312    995184       804      0.08         0
22:45:01        29172   8280872     99.65     10872   4355748    995184       804      0.08         0
22:55:02        29092   8280952     99.65      8352   4357176    995184       804      0.08         0
23:05:01        94768   8215276     98.86     13384   4283616    995184       804      0.08         0
23:15:01        23720   8286324     99.71     10372   4360112    995184       804      0.08         0
23:25:01        34256   8275788     99.59      6896   4352652    995184       804      0.08         0
23:35:01      3809472   4500572     54.16      1652   4346532    995184       804      0.08         0
23:45:01      3220276   5089768     61.25     29880   4891584    995184       804      0.08         0
23:55:01      3219504   5090540     61.26     30656   4891720    995184       804      0.08         0
23:59:01      3219276   5090768     61.26     30996   4891776    995184       804      0.08         0
00:00:01      3218864   5091180     61.27     31092   4891808    995184       804      0.08         0
Average:       172503   8137541     97.92     16271   4345654    995204       784      0.08         4


             total       used       free     shared    buffers     cached
Mem:          8115       7968        146          0         23       5575
-/+ buffers/cache:       2369       5745
Swap:          972        127        845


TIA,

Mit


Reply to: