Re: Trying to understand OOM killer

2017-02-19 Thread Michal Hocko 
On Sun 12-02-17 14:47:13, Paul Menzel wrote:
> Dear Linux folks,
> 
> 
> since some time, at Linux 4.8, 4.9, and 4.10-rc6, the OOM kicks in on a
> 8 GB machine.
> 
> ```
> Feb 12 08:21:50 asrocke350m1 kernel: updatedb.mlocat invoked oom-killer: 
> gfp_mask=0x16040d0(GFP_TEMPORARY|__GFP_COMP|__GFP_NOTRACK), nodemask=

The output is truncated. Could you send the full oom report? But this
smells like an example of the lowmem exhaustion. This is a lowmem
request on 32b system
[...]
> Feb 12 08:21:53 asrocke350m1 kernel: Node 0 active_anon:479572kB 
> inactive_anon:70712kB active_file:125844kB inactive_file:876364kB unevictable
> Feb 12 08:21:53 asrocke350m1 kernel: DMA free:3840kB min:788kB low:984kB 
> high:1180kB active_anon:0kB inactive_anon:0kB active_file:0kB inactiv
> Feb 12 08:21:53 asrocke350m1 kernel: lowmem_reserve[]: 0 763 7663 7663
> Feb 12 08:21:53 asrocke350m1 kernel: Normal free:38764kB min:38828kB 
> low:48532kB high:58236kB active_anon:0kB inactive_anon:0kB active_file:16
> Feb 12 08:21:53 asrocke350m1 kernel: lowmem_reserve[]: 0 0 55201 55201

lowmem is on the min watermark while there is no anonymous memory to be
reclaimed and we cannot really tell how much of the page cache as it is
truncated. We also do not know how large is the request because the
order part is missing. __GFP_COMP would suggest higher order request.

In short it is very likely that the OOM killer is genuine because the
given allocation request cannot be satisfied because the low mem
(~896MB) is depleted. This is an inherent problem of 32b kernels
unfortunately. Maybe there is a larger memory consumer in newer
kernels which changed the picture for you.
-- 
Michal Hocko
SUSE Labs

Re: Trying to understand OOM killer

2017-02-19 Thread Michal Hocko 
On Sun 12-02-17 14:47:13, Paul Menzel wrote:
> Dear Linux folks,
> 
> 
> since some time, at Linux 4.8, 4.9, and 4.10-rc6, the OOM kicks in on a
> 8 GB machine.
> 
> ```
> Feb 12 08:21:50 asrocke350m1 kernel: updatedb.mlocat invoked oom-killer: 
> gfp_mask=0x16040d0(GFP_TEMPORARY|__GFP_COMP|__GFP_NOTRACK), nodemask=

The output is truncated. Could you send the full oom report? But this
smells like an example of the lowmem exhaustion. This is a lowmem
request on 32b system
[...]
> Feb 12 08:21:53 asrocke350m1 kernel: Node 0 active_anon:479572kB 
> inactive_anon:70712kB active_file:125844kB inactive_file:876364kB unevictable
> Feb 12 08:21:53 asrocke350m1 kernel: DMA free:3840kB min:788kB low:984kB 
> high:1180kB active_anon:0kB inactive_anon:0kB active_file:0kB inactiv
> Feb 12 08:21:53 asrocke350m1 kernel: lowmem_reserve[]: 0 763 7663 7663
> Feb 12 08:21:53 asrocke350m1 kernel: Normal free:38764kB min:38828kB 
> low:48532kB high:58236kB active_anon:0kB inactive_anon:0kB active_file:16
> Feb 12 08:21:53 asrocke350m1 kernel: lowmem_reserve[]: 0 0 55201 55201

lowmem is on the min watermark while there is no anonymous memory to be
reclaimed and we cannot really tell how much of the page cache as it is
truncated. We also do not know how large is the request because the
order part is missing. __GFP_COMP would suggest higher order request.

In short it is very likely that the OOM killer is genuine because the
given allocation request cannot be satisfied because the low mem
(~896MB) is depleted. This is an inherent problem of 32b kernels
unfortunately. Maybe there is a larger memory consumer in newer
kernels which changed the picture for you.
-- 
Michal Hocko
SUSE Labs

Trying to understand OOM killer

2017-02-12 Thread Paul Menzel 
Dear Linux folks,


since some time, at Linux 4.8, 4.9, and 4.10-rc6, the OOM kicks in on a
8 GB machine.

```
Feb 12 08:21:50 asrocke350m1 kernel: updatedb.mlocat invoked oom-killer: 
gfp_mask=0x16040d0(GFP_TEMPORARY|__GFP_COMP|__GFP_NOTRACK), nodemask=
Feb 12 08:21:50 asrocke350m1 kernel: updatedb.mlocat cpuset=/ mems_allowed=0
Feb 12 08:21:50 asrocke350m1 kernel: CPU: 1 PID: 2314 Comm: updatedb.mlocat 
Tainted: G C  4.10.0-rc6-686-pae #1 Debian 4.10~rc6-1~
Feb 12 08:21:50 asrocke350m1 kernel: Hardware name: ASROCK E350M1/E350M1, BIOS 
4.5-964-gd96669e9db 02/11/2017
Feb 12 08:21:51 asrocke350m1 kernel: Call Trace:
Feb 12 08:21:51 asrocke350m1 kernel:  ? dump_stack+0x55/0x73
Feb 12 08:21:51 asrocke350m1 kernel:  ? dump_header+0x64/0x1ab
Feb 12 08:21:52 asrocke350m1 kernel:  ? ___ratelimit+0x9f/0x100
Feb 12 08:21:52 asrocke350m1 kernel:  ? oom_kill_process+0x221/0x3e0
Feb 12 08:21:52 asrocke350m1 kernel:  ? has_capability_noaudit+0x1a/0x30
Feb 12 08:21:52 asrocke350m1 kernel:  ? oom_badness.part.13+0xd7/0x150
Feb 12 08:21:52 asrocke350m1 kernel:  ? out_of_memory+0xe4/0x290
Feb 12 08:21:52 asrocke350m1 kernel:  ? __alloc_pages_nodemask+0xab8/0xbc0
Feb 12 08:21:52 asrocke350m1 kernel:  ? xfs_init_local_fork+0x8a/0xd0 [xfs]
Feb 12 08:21:52 asrocke350m1 kernel:  ? cache_grow_begin.isra.60+0x75/0x510
Feb 12 08:21:52 asrocke350m1 kernel:  ? xfs_buf_rele+0x43/0x2e0 [xfs]
Feb 12 08:21:52 asrocke350m1 kernel:  ? kmem_cache_alloc+0x1fa/0x530
Feb 12 08:21:52 asrocke350m1 kernel:  ? __d_alloc+0x23/0x180
Feb 12 08:21:52 asrocke350m1 kernel:  ? d_alloc+0x18/0x80
Feb 12 08:21:52 asrocke350m1 kernel:  ? d_alloc_parallel+0x47/0x450
Feb 12 08:21:52 asrocke350m1 kernel:  ? d_splice_alias+0x10d/0x3a0
Feb 12 08:21:53 asrocke350m1 kernel:  ? lockref_get_not_dead+0x8/0x40
Feb 12 08:21:53 asrocke350m1 kernel:  ? unlazy_walk+0xf9/0x1a0
Feb 12 08:21:53 asrocke350m1 kernel:  ? lookup_slow+0x5e/0x140
Feb 12 08:21:53 asrocke350m1 kernel:  ? walk_component+0x1b4/0x350
Feb 12 08:21:53 asrocke350m1 kernel:  ? path_lookupat+0x49/0xe0
Feb 12 08:21:53 asrocke350m1 kernel:  ? filename_lookup+0x99/0x190
Feb 12 08:21:53 asrocke350m1 kernel:  ? __check_object_size+0x9e/0x11c
Feb 12 08:21:53 asrocke350m1 kernel:  ? strncpy_from_user+0x39/0x140
Feb 12 08:21:53 asrocke350m1 kernel:  ? getname_flags+0x55/0x1a0
Feb 12 08:21:53 asrocke350m1 kernel:  ? vfs_fstatat+0x60/0xb0
Feb 12 08:21:53 asrocke350m1 kernel:  ? SyS_lstat64+0x2d/0x50
Feb 12 08:21:53 asrocke350m1 kernel:  ? sys_sync+0x9d/0xa0
Feb 12 08:21:53 asrocke350m1 kernel:  ? SyS_poll+0x6b/0x110
Feb 12 08:21:53 asrocke350m1 kernel:  ? do_fast_syscall_32+0x8a/0x150
Feb 12 08:21:53 asrocke350m1 kernel:  ? entry_SYSENTER_32+0x4e/0x7c
Feb 12 08:21:53 asrocke350m1 kernel: Mem-Info:
Feb 12 08:21:53 asrocke350m1 kernel: active_anon:119893 inactive_anon:17678 
isolated_anon:0
active_file:31461 inactive_file:219091 
isolated_file:0
unevictable:21 dirty:0 writeback:0 
unstable:0
slab_reclaimable:127609 
slab_unreclaimable:9519
mapped:63113 shmem:6177 pagetables:1601 
bounce:0
free:1381579 free_pcp:583 free_cma:0
Feb 12 08:21:53 asrocke350m1 kernel: Node 0 active_anon:479572kB 
inactive_anon:70712kB active_file:125844kB inactive_file:876364kB unevictable
Feb 12 08:21:53 asrocke350m1 kernel: DMA free:3840kB min:788kB low:984kB 
high:1180kB active_anon:0kB inactive_anon:0kB active_file:0kB inactiv
Feb 12 08:21:53 asrocke350m1 kernel: lowmem_reserve[]: 0 763 7663 7663
Feb 12 08:21:53 asrocke350m1 kernel: Normal free:38764kB min:38828kB 
low:48532kB high:58236kB active_anon:0kB inactive_anon:0kB active_file:16
Feb 12 08:21:53 asrocke350m1 kernel: lowmem_reserve[]: 0 0 55201 55201
Feb 12 08:21:53 asrocke350m1 kernel: HighMem free:5483712kB min:512kB 
low:88240kB high:175968kB active_anon:479572kB inactive_anon:70712kB act
Feb 12 08:21:54 asrocke350m1 kernel: lowmem_reserve[]: 0 0 0 0
Feb 12 08:21:54 asrocke350m1 kernel: DMA: 0*4kB 42*8kB (UE) 69*16kB (UE) 7*32kB 
(UE) 10*64kB (UE) 2*128kB (U) 1*256kB (U) 2*512kB (U) 0*1024kB
Feb 12 08:21:54 asrocke350m1 kernel: Normal: 17*4kB (UME) 583*8kB (UME) 
1983*16kB (UE) 72*32kB (ME) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*
Feb 12 08:21:54 asrocke350m1 kernel: HighMem: 2156*4kB (UM) 1334*8kB (UM) 
2760*16kB (UM) 2087*32kB (UM) 1274*64kB (UM) 491*128kB (UM) 234*256k
Feb 12 08:21:54 asrocke350m1 kernel: Node 0 hugepages_total=0 hugepages_free=0 
hugepages_surp=0 hugepages_size=2048kB
Feb 12 08:21:54 asrocke350m1 kernel: 256720 total pagecache pages
Feb 12 08:21:54 asrocke350m1 kernel: 0 pages in swap cache
Feb 12 08:21:54 asrocke350m1 kernel: Swap cache stats: add 0, delete 0, find 0/0
Feb 12 08:21:54 asrocke350m1 kernel: Free swap  = 4194300kB
Feb 12 08:21:54 asrocke350m1 kernel: Total swap = 4194300kB
Feb 12 08:21:54 asrocke350m1 kernel: 1994197 pages RAM
Feb 12 08:21:54

Trying to understand OOM killer

2017-02-12 Thread Paul Menzel 
Dear Linux folks,


since some time, at Linux 4.8, 4.9, and 4.10-rc6, the OOM kicks in on a
8 GB machine.

```
Feb 12 08:21:50 asrocke350m1 kernel: updatedb.mlocat invoked oom-killer: 
gfp_mask=0x16040d0(GFP_TEMPORARY|__GFP_COMP|__GFP_NOTRACK), nodemask=
Feb 12 08:21:50 asrocke350m1 kernel: updatedb.mlocat cpuset=/ mems_allowed=0
Feb 12 08:21:50 asrocke350m1 kernel: CPU: 1 PID: 2314 Comm: updatedb.mlocat 
Tainted: G C  4.10.0-rc6-686-pae #1 Debian 4.10~rc6-1~
Feb 12 08:21:50 asrocke350m1 kernel: Hardware name: ASROCK E350M1/E350M1, BIOS 
4.5-964-gd96669e9db 02/11/2017
Feb 12 08:21:51 asrocke350m1 kernel: Call Trace:
Feb 12 08:21:51 asrocke350m1 kernel:  ? dump_stack+0x55/0x73
Feb 12 08:21:51 asrocke350m1 kernel:  ? dump_header+0x64/0x1ab
Feb 12 08:21:52 asrocke350m1 kernel:  ? ___ratelimit+0x9f/0x100
Feb 12 08:21:52 asrocke350m1 kernel:  ? oom_kill_process+0x221/0x3e0
Feb 12 08:21:52 asrocke350m1 kernel:  ? has_capability_noaudit+0x1a/0x30
Feb 12 08:21:52 asrocke350m1 kernel:  ? oom_badness.part.13+0xd7/0x150
Feb 12 08:21:52 asrocke350m1 kernel:  ? out_of_memory+0xe4/0x290
Feb 12 08:21:52 asrocke350m1 kernel:  ? __alloc_pages_nodemask+0xab8/0xbc0
Feb 12 08:21:52 asrocke350m1 kernel:  ? xfs_init_local_fork+0x8a/0xd0 [xfs]
Feb 12 08:21:52 asrocke350m1 kernel:  ? cache_grow_begin.isra.60+0x75/0x510
Feb 12 08:21:52 asrocke350m1 kernel:  ? xfs_buf_rele+0x43/0x2e0 [xfs]
Feb 12 08:21:52 asrocke350m1 kernel:  ? kmem_cache_alloc+0x1fa/0x530
Feb 12 08:21:52 asrocke350m1 kernel:  ? __d_alloc+0x23/0x180
Feb 12 08:21:52 asrocke350m1 kernel:  ? d_alloc+0x18/0x80
Feb 12 08:21:52 asrocke350m1 kernel:  ? d_alloc_parallel+0x47/0x450
Feb 12 08:21:52 asrocke350m1 kernel:  ? d_splice_alias+0x10d/0x3a0
Feb 12 08:21:53 asrocke350m1 kernel:  ? lockref_get_not_dead+0x8/0x40
Feb 12 08:21:53 asrocke350m1 kernel:  ? unlazy_walk+0xf9/0x1a0
Feb 12 08:21:53 asrocke350m1 kernel:  ? lookup_slow+0x5e/0x140
Feb 12 08:21:53 asrocke350m1 kernel:  ? walk_component+0x1b4/0x350
Feb 12 08:21:53 asrocke350m1 kernel:  ? path_lookupat+0x49/0xe0
Feb 12 08:21:53 asrocke350m1 kernel:  ? filename_lookup+0x99/0x190
Feb 12 08:21:53 asrocke350m1 kernel:  ? __check_object_size+0x9e/0x11c
Feb 12 08:21:53 asrocke350m1 kernel:  ? strncpy_from_user+0x39/0x140
Feb 12 08:21:53 asrocke350m1 kernel:  ? getname_flags+0x55/0x1a0
Feb 12 08:21:53 asrocke350m1 kernel:  ? vfs_fstatat+0x60/0xb0
Feb 12 08:21:53 asrocke350m1 kernel:  ? SyS_lstat64+0x2d/0x50
Feb 12 08:21:53 asrocke350m1 kernel:  ? sys_sync+0x9d/0xa0
Feb 12 08:21:53 asrocke350m1 kernel:  ? SyS_poll+0x6b/0x110
Feb 12 08:21:53 asrocke350m1 kernel:  ? do_fast_syscall_32+0x8a/0x150
Feb 12 08:21:53 asrocke350m1 kernel:  ? entry_SYSENTER_32+0x4e/0x7c
Feb 12 08:21:53 asrocke350m1 kernel: Mem-Info:
Feb 12 08:21:53 asrocke350m1 kernel: active_anon:119893 inactive_anon:17678 
isolated_anon:0
active_file:31461 inactive_file:219091 
isolated_file:0
unevictable:21 dirty:0 writeback:0 
unstable:0
slab_reclaimable:127609 
slab_unreclaimable:9519
mapped:63113 shmem:6177 pagetables:1601 
bounce:0
free:1381579 free_pcp:583 free_cma:0
Feb 12 08:21:53 asrocke350m1 kernel: Node 0 active_anon:479572kB 
inactive_anon:70712kB active_file:125844kB inactive_file:876364kB unevictable
Feb 12 08:21:53 asrocke350m1 kernel: DMA free:3840kB min:788kB low:984kB 
high:1180kB active_anon:0kB inactive_anon:0kB active_file:0kB inactiv
Feb 12 08:21:53 asrocke350m1 kernel: lowmem_reserve[]: 0 763 7663 7663
Feb 12 08:21:53 asrocke350m1 kernel: Normal free:38764kB min:38828kB 
low:48532kB high:58236kB active_anon:0kB inactive_anon:0kB active_file:16
Feb 12 08:21:53 asrocke350m1 kernel: lowmem_reserve[]: 0 0 55201 55201
Feb 12 08:21:53 asrocke350m1 kernel: HighMem free:5483712kB min:512kB 
low:88240kB high:175968kB active_anon:479572kB inactive_anon:70712kB act
Feb 12 08:21:54 asrocke350m1 kernel: lowmem_reserve[]: 0 0 0 0
Feb 12 08:21:54 asrocke350m1 kernel: DMA: 0*4kB 42*8kB (UE) 69*16kB (UE) 7*32kB 
(UE) 10*64kB (UE) 2*128kB (U) 1*256kB (U) 2*512kB (U) 0*1024kB
Feb 12 08:21:54 asrocke350m1 kernel: Normal: 17*4kB (UME) 583*8kB (UME) 
1983*16kB (UE) 72*32kB (ME) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*
Feb 12 08:21:54 asrocke350m1 kernel: HighMem: 2156*4kB (UM) 1334*8kB (UM) 
2760*16kB (UM) 2087*32kB (UM) 1274*64kB (UM) 491*128kB (UM) 234*256k
Feb 12 08:21:54 asrocke350m1 kernel: Node 0 hugepages_total=0 hugepages_free=0 
hugepages_surp=0 hugepages_size=2048kB
Feb 12 08:21:54 asrocke350m1 kernel: 256720 total pagecache pages
Feb 12 08:21:54 asrocke350m1 kernel: 0 pages in swap cache
Feb 12 08:21:54 asrocke350m1 kernel: Swap cache stats: add 0, delete 0, find 0/0
Feb 12 08:21:54 asrocke350m1 kernel: Free swap  = 4194300kB
Feb 12 08:21:54 asrocke350m1 kernel: Total swap = 4194300kB
Feb 12 08:21:54 asrocke350m1 kernel: 1994197 pages RAM
Feb 12 08:21:54