Hello,
I'm having out of memory situations with my "low memory" VMs in KVM
under Fedora (Kernel 4.7, 4.8 and also before). They started to get more
and more sensitive to OOM. I recently found the following info:
https://marius.bloggt-in-braunschweig.de/2016/11/17/linuxkernel-4-74-8-und-der-oom-killer/
https://www.spinics.net/lists/linux-mm/msg113661.html
Therefore I tried the latest Fedora kernels: 4.9.0-0.rc6.git2.1.fc26.x86_64
But OOM situation is still very easy to reproduce:
1.) VM with 128-384MB under Fedora 25
2.) Having some processes run without any load (e.g. Apache)
3.) run an update with: dnf clean all; dnf update
4.) dnf python process get's killed
Please make the VM system working again in Kernel 4.9 and to use swap
again correctly.
Thnx.
Ciao,
Gerhard
Hello,
See also:
Bug 1314697 - Kernel 4.4.3-300.fc23.x86_64 is not stable inside a KVM VM
https://bugzilla.redhat.com/show_bug.cgi?id=1314697
Ciao,
Gerhard
On 30.11.2016 08:10, Gerhard Wiesinger wrote:
> Hello,
>
> I'm having out of memory situations with my "low memory" VMs in KVM
> under Fedora (Kernel 4.7, 4.8 and also before). They started to get
> more and more sensitive to OOM. I recently found the following info:
>
> https://marius.bloggt-in-braunschweig.de/2016/11/17/linuxkernel-4-74-8-und-der-oom-killer/
>
> https://www.spinics.net/lists/linux-mm/msg113661.html
>
> Therefore I tried the latest Fedora kernels:
> 4.9.0-0.rc6.git2.1.fc26.x86_64
>
> But OOM situation is still very easy to reproduce:
>
> 1.) VM with 128-384MB under Fedora 25
>
> 2.) Having some processes run without any load (e.g. Apache)
>
> 3.) run an update with: dnf clean all; dnf update
>
> 4.) dnf python process get's killed
>
>
> Please make the VM system working again in Kernel 4.9 and to use swap
> again correctly.
>
> Thnx.
>
> Ciao,
>
> Gerhard
>
>
Hello,
same with latest kernel rc, dnf still killed with OOM (but sometimes
better).
./update.sh: line 40: 1591 Killed ${EXE} update ${PARAMS}
(does dnf clean all;dnf update)
Linux database.intern 4.9.0-0.rc8.git2.1.fc26.x86_64 #1 SMP Wed Dec 7
17:53:29 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
Updated bug report:
https://bugzilla.redhat.com/show_bug.cgi?id=1314697
Any chance to get it fixed in 4.9.0 release?
Ciao,
Gerhard
On 30.11.2016 08:20, Gerhard Wiesinger wrote:
> Hello,
>
> See also:
> Bug 1314697 - Kernel 4.4.3-300.fc23.x86_64 is not stable inside a KVM VM
> https://bugzilla.redhat.com/show_bug.cgi?id=1314697
>
> Ciao,
> Gerhard
>
>
> On 30.11.2016 08:10, Gerhard Wiesinger wrote:
>> Hello,
>>
>> I'm having out of memory situations with my "low memory" VMs in KVM
>> under Fedora (Kernel 4.7, 4.8 and also before). They started to get
>> more and more sensitive to OOM. I recently found the following info:
>>
>> https://marius.bloggt-in-braunschweig.de/2016/11/17/linuxkernel-4-74-8-und-der-oom-killer/
>>
>> https://www.spinics.net/lists/linux-mm/msg113661.html
>>
>> Therefore I tried the latest Fedora kernels:
>> 4.9.0-0.rc6.git2.1.fc26.x86_64
>>
>> But OOM situation is still very easy to reproduce:
>>
>> 1.) VM with 128-384MB under Fedora 25
>>
>> 2.) Having some processes run without any load (e.g. Apache)
>>
>> 3.) run an update with: dnf clean all; dnf update
>>
>> 4.) dnf python process get's killed
>>
>>
>> Please make the VM system working again in Kernel 4.9 and to use swap
>> again correctly.
>>
>> Thnx.
>>
>> Ciao,
>>
>> Gerhard
>>
>>
>
On Fri 09-12-16 08:06:25, Gerhard Wiesinger wrote:
> Hello,
>
> same with latest kernel rc, dnf still killed with OOM (but sometimes
> better).
>
> ./update.sh: line 40: 1591 Killed ${EXE} update ${PARAMS}
> (does dnf clean all;dnf update)
> Linux database.intern 4.9.0-0.rc8.git2.1.fc26.x86_64 #1 SMP Wed Dec 7
> 17:53:29 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
>
> Updated bug report:
> https://bugzilla.redhat.com/show_bug.cgi?id=1314697
Could you post your oom report please?
--
Michal Hocko
SUSE Labs
On 09.12.2016 14:40, Michal Hocko wrote:
> On Fri 09-12-16 08:06:25, Gerhard Wiesinger wrote:
>> Hello,
>>
>> same with latest kernel rc, dnf still killed with OOM (but sometimes
>> better).
>>
>> ./update.sh: line 40: 1591 Killed ${EXE} update ${PARAMS}
>> (does dnf clean all;dnf update)
>> Linux database.intern 4.9.0-0.rc8.git2.1.fc26.x86_64 #1 SMP Wed Dec 7
>> 17:53:29 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
>>
>> Updated bug report:
>> https://bugzilla.redhat.com/show_bug.cgi?id=1314697
> Could you post your oom report please?
E.g. a new one with more than one included, first one after boot ...
Just setup a low mem VM under KVM and it is easily triggerable.
Still enough virtual memory available ...
4.9.0-0.rc8.git2.1.fc26.x86_64
[ 624.862777] ksoftirqd/0: page allocation failure: order:0,
mode:0x2080020(GFP_ATOMIC)
[ 624.863319] CPU: 0 PID: 3 Comm: ksoftirqd/0 Not tainted
4.9.0-0.rc8.git2.1.fc26.x86_64 #1
[ 624.863410] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.9.3
[ 624.863510] ffffaa62c007f958 ffffffff904774e3 ffffffff90c7dd98
0000000000000000
[ 624.863923] ffffaa62c007f9e0 ffffffff9020e6ea 0208002000000246
ffffffff90c7dd98
[ 624.864019] ffffaa62c007f980 ffff96b900000010 ffffaa62c007f9f0
ffffaa62c007f9a0
[ 624.864998] Call Trace:
[ 624.865149] [<ffffffff904774e3>] dump_stack+0x86/0xc3
[ 624.865347] [<ffffffff9020e6ea>] warn_alloc+0x13a/0x170
[ 624.865432] [<ffffffff9020e9e2>] __alloc_pages_slowpath+0x252/0xbb0
[ 624.865563] [<ffffffff9020f74d>] __alloc_pages_nodemask+0x40d/0x4b0
[ 624.865675] [<ffffffff9020f983>] __alloc_page_frag+0x193/0x200
[ 624.866024] [<ffffffff907a1d7e>] __napi_alloc_skb+0x8e/0xf0
[ 624.866113] [<ffffffffc017777d>] page_to_skb.isra.28+0x5d/0x310
[virtio_net]
[ 624.866201] [<ffffffffc01794cb>] virtnet_receive+0x2db/0x9a0
[virtio_net]
[ 624.867378] [<ffffffffc0179bad>] virtnet_poll+0x1d/0x80 [virtio_net]
[ 624.867494] [<ffffffff907b501e>] net_rx_action+0x23e/0x470
[ 624.867612] [<ffffffff9091a8cd>] __do_softirq+0xcd/0x4b9
[ 624.867704] [<ffffffff900dd164>] ? smpboot_thread_fn+0x34/0x1f0
[ 624.867833] [<ffffffff900dd25d>] ? smpboot_thread_fn+0x12d/0x1f0
[ 624.867924] [<ffffffff900b7c95>] run_ksoftirqd+0x25/0x80
[ 624.868109] [<ffffffff900dd258>] smpboot_thread_fn+0x128/0x1f0
[ 624.868197] [<ffffffff900dd130>] ? sort_range+0x30/0x30
[ 624.868596] [<ffffffff900d82c2>] kthread+0x102/0x120
[ 624.868679] [<ffffffff909117a0>] ? wait_for_completion+0x110/0x140
[ 624.868768] [<ffffffff900d81c0>] ? kthread_park+0x60/0x60
[ 624.868850] [<ffffffff90917afa>] ret_from_fork+0x2a/0x40
[ 843.528656] httpd (2490) used greatest stack depth: 10304 bytes left
[ 878.077750] httpd (2976) used greatest stack depth: 10096 bytes left
[93918.861109] netstat (14579) used greatest stack depth: 9488 bytes left
[94050.874669] kworker/dying (6253) used greatest stack depth: 9008
bytes left
[95895.765570] kworker/1:1H: page allocation failure: order:0,
mode:0x2280020(GFP_ATOMIC|__GFP_NOTRACK)
[95895.765819] CPU: 1 PID: 440 Comm: kworker/1:1H Not tainted
4.9.0-0.rc8.git2.1.fc26.x86_64 #1
[95895.765911] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.9.3
[95895.766060] Workqueue: kblockd blk_mq_run_work_fn
[95895.766143] ffffaa62c0257628 ffffffff904774e3 ffffffff90c7dd98
0000000000000000
[95895.766235] ffffaa62c02576b0 ffffffff9020e6ea 0228002000000046
ffffffff90c7dd98
[95895.766325] ffffaa62c0257650 ffff96b900000010 ffffaa62c02576c0
ffffaa62c0257670
[95895.766417] Call Trace:
[95895.766502] [<ffffffff904774e3>] dump_stack+0x86/0xc3
[95895.766596] [<ffffffff9020e6ea>] warn_alloc+0x13a/0x170
[95895.766681] [<ffffffff9020e9e2>] __alloc_pages_slowpath+0x252/0xbb0
[95895.766767] [<ffffffff9020f74d>] __alloc_pages_nodemask+0x40d/0x4b0
[95895.766866] [<ffffffff9026db51>] alloc_pages_current+0xa1/0x1f0
[95895.766971] [<ffffffff90916f17>] ? _raw_spin_unlock+0x27/0x40
[95895.767073] [<ffffffff90278956>] new_slab+0x316/0x7c0
[95895.767160] [<ffffffff9027ae8b>] ___slab_alloc+0x3fb/0x5c0
[95895.772611] [<ffffffff9010b042>] ? cpuacct_charge+0xf2/0x1f0
[95895.773406] [<ffffffffc005850d>] ? alloc_indirect.isra.11+0x1d/0x50
[virtio_ring]
[95895.774327] [<ffffffff901319d5>] ? rcu_read_lock_sched_held+0x45/0x80
[95895.775212] [<ffffffffc005850d>] ? alloc_indirect.isra.11+0x1d/0x50
[virtio_ring]
[95895.776155] [<ffffffff9027b0a1>] __slab_alloc+0x51/0x90
[95895.777090] [<ffffffff9027d141>] __kmalloc+0x251/0x320
[95895.781502] [<ffffffffc005850d>] ? alloc_indirect.isra.11+0x1d/0x50
[virtio_ring]
[95895.782309] [<ffffffffc005850d>] alloc_indirect.isra.11+0x1d/0x50
[virtio_ring]
[95895.783334] [<ffffffffc0059193>] virtqueue_add_sgs+0x1c3/0x4a0
[virtio_ring]
[95895.784059] [<ffffffff90068475>] ? kvm_sched_clock_read+0x25/0x40
[95895.784742] [<ffffffffc006665c>] __virtblk_add_req+0xbc/0x220
[virtio_blk]
[95895.785419] [<ffffffff901312fd>] ? debug_lockdep_rcu_enabled+0x1d/0x20
[95895.786086] [<ffffffffc0066935>] ? virtio_queue_rq+0x105/0x290
[virtio_blk]
[95895.786750] [<ffffffffc006695d>] virtio_queue_rq+0x12d/0x290
[virtio_blk]
[95895.787427] [<ffffffff9045015d>] __blk_mq_run_hw_queue+0x26d/0x3b0
[95895.788106] [<ffffffff904502e2>] blk_mq_run_work_fn+0x12/0x20
[95895.789065] [<ffffffff900d097e>] process_one_work+0x23e/0x6f0
[95895.789741] [<ffffffff900d08fa>] ? process_one_work+0x1ba/0x6f0
[95895.790444] [<ffffffff900d0e7e>] worker_thread+0x4e/0x490
[95895.791178] [<ffffffff900d0e30>] ? process_one_work+0x6f0/0x6f0
[95895.791911] [<ffffffff900d0e30>] ? process_one_work+0x6f0/0x6f0
[95895.792653] [<ffffffff90003eec>] ? do_syscall_64+0x6c/0x1f0
[95895.793397] [<ffffffff900d82c2>] kthread+0x102/0x120
[95895.794212] [<ffffffff90111775>] ? trace_hardirqs_on_caller+0xf5/0x1b0
[95895.794942] [<ffffffff900d81c0>] ? kthread_park+0x60/0x60
[95895.795689] [<ffffffff90917afa>] ret_from_fork+0x2a/0x40
[95895.796408] Mem-Info:
[95895.797110] active_anon:8800 inactive_anon:9030 isolated_anon:32
active_file:263 inactive_file:238 isolated_file:0
unevictable:0 dirty:0 writeback:330 unstable:0
slab_reclaimable:5241 slab_unreclaimable:9538
mapped:470 shmem:9 pagetables:2200 bounce:0
free:690 free_pcp:68 free_cma:0
[95895.801218] Node 0 active_anon:35200kB inactive_anon:36120kB
active_file:1052kB inactive_file:952kB unevictable:0kB
isolated(anon):128kB isolated(file):0kB mapped:1880kB dirty:0kB
writeback:1320kB shmem:0kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp:
36kB writeback_tmp:0kB unstable:0kB pages_scanned:179 all_unreclaimable? no
[95895.803264] Node 0 DMA free:924kB min:172kB low:212kB high:252kB
active_anon:3544kB inactive_anon:3944kB active_file:84kB
inactive_file:140kB unevictable:0kB writepending:4kB present:15992kB
managed:15908kB mlocked:0kB slab_reclaimable:1728kB
slab_unreclaimable:2964kB kernel_stack:84kB pagetables:1396kB bounce:0kB
free_pcp:0kB local_pcp:0kB free_cma:0kB
[95895.805936] lowmem_reserve[]: 0 117 117 117 117
[95895.806751] Node 0 DMA32 free:1836kB min:1296kB low:1620kB
high:1944kB active_anon:31636kB inactive_anon:32164kB active_file:968kB
inactive_file:804kB unevictable:0kB writepending:1288kB present:180080kB
managed:139012kB mlocked:0kB slab_reclaimable:19236kB
slab_unreclaimable:35188kB kernel_stack:1852kB pagetables:7404kB
bounce:0kB free_pcp:272kB local_pcp:156kB free_cma:0kB
[95895.809223] lowmem_reserve[]: 0 0 0 0 0
[95895.810071] Node 0 DMA: 36*4kB (H) 29*8kB (H) 22*16kB (H) 6*32kB (H)
0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 920kB
[95895.812089] Node 0 DMA32: 77*4kB (H) 71*8kB (H) 28*16kB (H) 8*32kB
(H) 4*64kB (H) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 1836kB
[95895.813979] Node 0 hugepages_total=0 hugepages_free=0
hugepages_surp=0 hugepages_size=2048kB
[95895.813981] 1804 total pagecache pages
[95895.814931] 1289 pages in swap cache
[95895.815849] Swap cache stats: add 5288014, delete 5286725, find
11568655/13881082
[95895.816792] Free swap = 1791816kB
[95895.817706] Total swap = 2064380kB
[95895.819222] 49018 pages RAM
[95895.820145] 0 pages HighMem/MovableOnly
[95895.821039] 10288 pages reserved
[95895.823325] 0 pages cma reserved
[95895.824244] 0 pages hwpoisoned
[95895.825237] SLUB: Unable to allocate memory on node -1,
gfp=0x2080020(GFP_ATOMIC)
[95895.826140] cache: kmalloc-256, object size: 256, buffer size: 256,
default order: 0, min order: 0
[95895.827034] node 0: slabs: 113, objs: 1808, free: 0
[97883.838418] httpd invoked oom-killer:
gfp_mask=0x24201ca(GFP_HIGHUSER_MOVABLE|__GFP_COLD), nodemask=0,
order=0, oom_score_adj=0
[97883.843507] httpd cpuset=/ mems_allowed=0
[97883.843601] CPU: 1 PID: 19043 Comm: httpd Not tainted
4.9.0-0.rc8.git2.1.fc26.x86_64 #1
[97883.844628] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.9.3
[97883.845839] ffffaa62c395f958 ffffffff904774e3 ffffaa62c395fb20
ffff96b98b8b3100
[97883.846970] ffffaa62c395f9e0 ffffffff902a8c41 0000000000000000
0000000000000000
[97883.848388] ffffffff90ec6840 ffffaa62c395f990 ffffffff9011183d
ffffaa62c395f9b0
[97883.849945] Call Trace:
[97883.851366] [<ffffffff904774e3>] dump_stack+0x86/0xc3
[97883.852535] [<ffffffff902a8c41>] dump_header+0x7b/0x24f
[97883.853718] [<ffffffff9011183d>] ? trace_hardirqs_on+0xd/0x10
[97883.854857] [<ffffffff902085d3>] oom_kill_process+0x203/0x3e0
[97883.856192] [<ffffffff90208afb>] out_of_memory+0x13b/0x580
[97883.857334] [<ffffffff90208bea>] ? out_of_memory+0x22a/0x580
[97883.858590] [<ffffffff9020f31a>] __alloc_pages_slowpath+0xb8a/0xbb0
[97883.859706] [<ffffffff9020f74d>] __alloc_pages_nodemask+0x40d/0x4b0
[97883.860854] [<ffffffff90037de9>] ? sched_clock+0x9/0x10
[97883.862120] [<ffffffff9026db51>] alloc_pages_current+0xa1/0x1f0
[97883.863251] [<ffffffff90201d96>] __page_cache_alloc+0x146/0x190
[97883.864449] [<ffffffff9020366c>] ? pagecache_get_page+0x2c/0x300
[97883.865602] [<ffffffff90206055>] filemap_fault+0x345/0x790
[97883.866661] [<ffffffff90206238>] ? filemap_fault+0x528/0x790
[97883.867795] [<ffffffff903639d9>] ext4_filemap_fault+0x39/0x50
[97883.869289] [<ffffffff90241ca3>] __do_fault+0x83/0x1d0
[97883.870301] [<ffffffff90246642>] handle_mm_fault+0x11e2/0x17a0
[97883.871304] [<ffffffff902454ba>] ? handle_mm_fault+0x5a/0x17a0
[97883.872491] [<ffffffff9006de16>] __do_page_fault+0x266/0x520
[97883.873406] [<ffffffff9006e1a8>] trace_do_page_fault+0x58/0x2a0
[97883.874262] [<ffffffff90067f3a>] do_async_page_fault+0x1a/0xa0
[97883.875168] [<ffffffff90918e28>] async_page_fault+0x28/0x30
[97883.882611] Mem-Info:
[97883.883747] active_anon:2915 inactive_anon:3376 isolated_anon:0
active_file:3902 inactive_file:3639 isolated_file:0
unevictable:0 dirty:205 writeback:0 unstable:0
slab_reclaimable:9856 slab_unreclaimable:9682
mapped:3722 shmem:59 pagetables:2080 bounce:0
free:748 free_pcp:15 free_cma:0
[97883.890766] Node 0 active_anon:11660kB inactive_anon:13504kB
active_file:15608kB inactive_file:14556kB unevictable:0kB
isolated(anon):0kB isolated(file):0kB mapped:14888kB dirty:820kB
writeback:0kB shmem:0kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp:
236kB writeback_tmp:0kB unstable:0kB pages_scanned:168352
all_unreclaimable? yes
[97883.893210] Node 0 DMA free:1468kB min:172kB low:212kB high:252kB
active_anon:1716kB inactive_anon:912kB active_file:2292kB
inactive_file:876kB unevictable:0kB writepending:24kB present:15992kB
managed:15908kB mlocked:0kB slab_reclaimable:4652kB
slab_unreclaimable:2852kB kernel_stack:76kB pagetables:496kB bounce:0kB
free_pcp:0kB local_pcp:0kB free_cma:0kB
[97883.898799] lowmem_reserve[]: 0 117 117 117 117
[97883.899735] Node 0 DMA32 free:1524kB min:1296kB low:1620kB
high:1944kB active_anon:9944kB inactive_anon:12572kB active_file:13316kB
inactive_file:13680kB unevictable:0kB writepending:768kB
present:180080kB managed:139012kB mlocked:0kB slab_reclaimable:34772kB
slab_unreclaimable:35876kB kernel_stack:1828kB pagetables:7824kB
bounce:0kB free_pcp:60kB local_pcp:52kB free_cma:0kB
[97883.903033] lowmem_reserve[]: 0 0 0 0 0
[97883.904371] Node 0 DMA: 36*4kB (H) 29*8kB (H) 22*16kB (H) 9*32kB (H)
3*64kB (H) 2*128kB (H) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 1464kB
[97883.906442] Node 0 DMA32: 13*4kB (H) 4*8kB (H) 13*16kB (H) 8*32kB (H)
9*64kB (H) 1*128kB (H) 1*256kB (H) 0*512kB 0*1024kB 0*2048kB 0*4096kB =
1508kB
[97883.908598] Node 0 hugepages_total=0 hugepages_free=0
hugepages_surp=0 hugepages_size=2048kB
[97883.908600] 10093 total pagecache pages
[97883.909623] 2486 pages in swap cache
[97883.910981] Swap cache stats: add 5936545, delete 5934059, find
11939248/14560523
[97883.911932] Free swap = 1924040kB
[97883.912844] Total swap = 2064380kB
[97883.913799] 49018 pages RAM
[97883.915101] 0 pages HighMem/MovableOnly
[97883.916149] 10288 pages reserved
[97883.917465] 0 pages cma reserved
[97883.918528] 0 pages hwpoisoned
[97883.919635] [ pid ] uid tgid total_vm rss nr_ptes nr_pmds
swapents oom_score_adj name
[97883.919656] [ 442] 0 442 15414 276 31 3
89 0 systemd-journal
[97883.919661] [ 479] 0 479 11179 0 22 3
323 -1000 systemd-udevd
[97883.919666] [ 535] 0 535 13888 0 28 3
114 -1000 auditd
[97883.919671] [ 559] 81 559 11565 85 26 3
88 -900 dbus-daemon
[97883.919675] [ 562] 70 562 12026 0 28 3
108 0 avahi-daemon
[97883.919680] [ 578] 0 578 182739 11 279 4
263 0 rsyslogd
[97883.919684] [ 579] 0 579 11890 26 27 3
105 0 systemd-logind
[97883.919688] [ 580] 0 580 123902 265 223 3
1889 0 httpd
[97883.919693] [ 581] 70 581 12026 0 26 3
83 0 avahi-daemon
[97883.919697] [ 596] 0 596 1095 0 8 3
35 0 acpid
[97883.919701] [ 614] 0 614 33234 1 18 4
155 0 crond
[97883.919706] [ 630] 0 630 29260 0 9 3
32 0 agetty
[97883.919710] [ 639] 0 639 25089 70 49 3
430 0 sendmail
[97883.919715] [ 643] 0 643 20785 0 43 3
231 -1000 sshd
[97883.919719] [ 674] 51 674 23428 0 46 3
415 0 sendmail
[97883.919724] [ 723] 0 723 44394 148 38 3
2134 0 munin-node
[97883.919728] [ 2513] 38 2513 6971 23 18 3
130 0 ntpd
[97883.919733] [13908] 0 13908 36690 0 74 3
320 0 sshd
[97883.919738] [13910] 0 13910 15956 1 35 3
235 0 systemd
[97883.919742] [13913] 0 13913 60419 0 49 4
463 0 (sd-pam)
[97883.919747] [13918] 0 13918 36690 147 71 3
280 0 sshd
[97883.919751] [13930] 0 13930 30730 1 13 4
285 0 bash
[97883.919756] [13958] 0 13958 29971 0 13 3
55 0 update.sh
[97883.919761] [13985] 0 13985 159639 4589 192 3
26191 0 dnf
[97883.919766] [17393] 48 17393 177835 704 238 3
1711 0 httpd
[97883.919771] [19018] 48 19018 128626 1434 222 3
1342 0 httpd
[97883.919774] [19043] 48 19043 128067 2010 219 3
1492 0 httpd
[97883.919776] Out of memory: Kill process 13985 (dnf) score 54 or
sacrifice child
[97883.920895] Killed process 13985 (dnf) total-vm:638556kB,
anon-rss:12840kB, file-rss:5516kB, shmem-rss:0kB
[97883.986808] oom_reaper: reaped process 13985 (dnf), now anon-rss:0kB,
file-rss:1552kB, shmem-rss:0kB
Thank you.
Ciao,
Gerhard
On 09.12.2016 16:52, Gerhard Wiesinger wrote:
> On 09.12.2016 14:40, Michal Hocko wrote:
>> On Fri 09-12-16 08:06:25, Gerhard Wiesinger wrote:
>>> Hello,
>>>
>>> same with latest kernel rc, dnf still killed with OOM (but sometimes
>>> better).
>>>
>>> ./update.sh: line 40: 1591 Killed ${EXE} update
>>> ${PARAMS}
>>> (does dnf clean all;dnf update)
>>> Linux database.intern 4.9.0-0.rc8.git2.1.fc26.x86_64 #1 SMP Wed Dec 7
>>> 17:53:29 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
>>>
>>> Updated bug report:
>>> https://bugzilla.redhat.com/show_bug.cgi?id=1314697
>> Could you post your oom report please?
>
> E.g. a new one with more than one included, first one after boot ...
>
> Just setup a low mem VM under KVM and it is easily triggerable.
>
> Still enough virtual memory available ...
>
> 4.9.0-0.rc8.git2.1.fc26.x86_64
>
> [ 624.862777] ksoftirqd/0: page allocation failure: order:0,
> mode:0x2080020(GFP_ATOMIC)
> [ 624.863319] CPU: 0 PID: 3 Comm: ksoftirqd/0 Not tainted
> 4.9.0-0.rc8.git2.1.fc26.x86_64 #1
> [ 624.863410] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
> BIOS 1.9.3
> [ 624.863510] ffffaa62c007f958 ffffffff904774e3 ffffffff90c7dd98
> 0000000000000000
> [ 624.863923] ffffaa62c007f9e0 ffffffff9020e6ea 0208002000000246
> ffffffff90c7dd98
> [ 624.864019] ffffaa62c007f980 ffff96b900000010 ffffaa62c007f9f0
> ffffaa62c007f9a0
> [ 624.864998] Call Trace:
> [ 624.865149] [<ffffffff904774e3>] dump_stack+0x86/0xc3
> [ 624.865347] [<ffffffff9020e6ea>] warn_alloc+0x13a/0x170
> [ 624.865432] [<ffffffff9020e9e2>] __alloc_pages_slowpath+0x252/0xbb0
> [ 624.865563] [<ffffffff9020f74d>] __alloc_pages_nodemask+0x40d/0x4b0
> [ 624.865675] [<ffffffff9020f983>] __alloc_page_frag+0x193/0x200
> [ 624.866024] [<ffffffff907a1d7e>] __napi_alloc_skb+0x8e/0xf0
> [ 624.866113] [<ffffffffc017777d>] page_to_skb.isra.28+0x5d/0x310
> [virtio_net]
> [ 624.866201] [<ffffffffc01794cb>] virtnet_receive+0x2db/0x9a0
> [virtio_net]
> [ 624.867378] [<ffffffffc0179bad>] virtnet_poll+0x1d/0x80 [virtio_net]
> [ 624.867494] [<ffffffff907b501e>] net_rx_action+0x23e/0x470
> [ 624.867612] [<ffffffff9091a8cd>] __do_softirq+0xcd/0x4b9
> [ 624.867704] [<ffffffff900dd164>] ? smpboot_thread_fn+0x34/0x1f0
> [ 624.867833] [<ffffffff900dd25d>] ? smpboot_thread_fn+0x12d/0x1f0
> [ 624.867924] [<ffffffff900b7c95>] run_ksoftirqd+0x25/0x80
> [ 624.868109] [<ffffffff900dd258>] smpboot_thread_fn+0x128/0x1f0
> [ 624.868197] [<ffffffff900dd130>] ? sort_range+0x30/0x30
> [ 624.868596] [<ffffffff900d82c2>] kthread+0x102/0x120
> [ 624.868679] [<ffffffff909117a0>] ? wait_for_completion+0x110/0x140
> [ 624.868768] [<ffffffff900d81c0>] ? kthread_park+0x60/0x60
> [ 624.868850] [<ffffffff90917afa>] ret_from_fork+0x2a/0x40
> [ 843.528656] httpd (2490) used greatest stack depth: 10304 bytes left
> [ 878.077750] httpd (2976) used greatest stack depth: 10096 bytes left
> [93918.861109] netstat (14579) used greatest stack depth: 9488 bytes left
> [94050.874669] kworker/dying (6253) used greatest stack depth: 9008
> bytes left
> [95895.765570] kworker/1:1H: page allocation failure: order:0,
> mode:0x2280020(GFP_ATOMIC|__GFP_NOTRACK)
> [95895.765819] CPU: 1 PID: 440 Comm: kworker/1:1H Not tainted
> 4.9.0-0.rc8.git2.1.fc26.x86_64 #1
> [95895.765911] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
> BIOS 1.9.3
> [95895.766060] Workqueue: kblockd blk_mq_run_work_fn
> [95895.766143] ffffaa62c0257628 ffffffff904774e3 ffffffff90c7dd98
> 0000000000000000
> [95895.766235] ffffaa62c02576b0 ffffffff9020e6ea 0228002000000046
> ffffffff90c7dd98
> [95895.766325] ffffaa62c0257650 ffff96b900000010 ffffaa62c02576c0
> ffffaa62c0257670
> [95895.766417] Call Trace:
> [95895.766502] [<ffffffff904774e3>] dump_stack+0x86/0xc3
> [95895.766596] [<ffffffff9020e6ea>] warn_alloc+0x13a/0x170
> [95895.766681] [<ffffffff9020e9e2>] __alloc_pages_slowpath+0x252/0xbb0
> [95895.766767] [<ffffffff9020f74d>] __alloc_pages_nodemask+0x40d/0x4b0
> [95895.766866] [<ffffffff9026db51>] alloc_pages_current+0xa1/0x1f0
> [95895.766971] [<ffffffff90916f17>] ? _raw_spin_unlock+0x27/0x40
> [95895.767073] [<ffffffff90278956>] new_slab+0x316/0x7c0
> [95895.767160] [<ffffffff9027ae8b>] ___slab_alloc+0x3fb/0x5c0
> [95895.772611] [<ffffffff9010b042>] ? cpuacct_charge+0xf2/0x1f0
> [95895.773406] [<ffffffffc005850d>] ?
> alloc_indirect.isra.11+0x1d/0x50 [virtio_ring]
> [95895.774327] [<ffffffff901319d5>] ? rcu_read_lock_sched_held+0x45/0x80
> [95895.775212] [<ffffffffc005850d>] ?
> alloc_indirect.isra.11+0x1d/0x50 [virtio_ring]
> [95895.776155] [<ffffffff9027b0a1>] __slab_alloc+0x51/0x90
> [95895.777090] [<ffffffff9027d141>] __kmalloc+0x251/0x320
> [95895.781502] [<ffffffffc005850d>] ?
> alloc_indirect.isra.11+0x1d/0x50 [virtio_ring]
> [95895.782309] [<ffffffffc005850d>] alloc_indirect.isra.11+0x1d/0x50
> [virtio_ring]
> [95895.783334] [<ffffffffc0059193>] virtqueue_add_sgs+0x1c3/0x4a0
> [virtio_ring]
> [95895.784059] [<ffffffff90068475>] ? kvm_sched_clock_read+0x25/0x40
> [95895.784742] [<ffffffffc006665c>] __virtblk_add_req+0xbc/0x220
> [virtio_blk]
> [95895.785419] [<ffffffff901312fd>] ?
> debug_lockdep_rcu_enabled+0x1d/0x20
> [95895.786086] [<ffffffffc0066935>] ? virtio_queue_rq+0x105/0x290
> [virtio_blk]
> [95895.786750] [<ffffffffc006695d>] virtio_queue_rq+0x12d/0x290
> [virtio_blk]
> [95895.787427] [<ffffffff9045015d>] __blk_mq_run_hw_queue+0x26d/0x3b0
> [95895.788106] [<ffffffff904502e2>] blk_mq_run_work_fn+0x12/0x20
> [95895.789065] [<ffffffff900d097e>] process_one_work+0x23e/0x6f0
> [95895.789741] [<ffffffff900d08fa>] ? process_one_work+0x1ba/0x6f0
> [95895.790444] [<ffffffff900d0e7e>] worker_thread+0x4e/0x490
> [95895.791178] [<ffffffff900d0e30>] ? process_one_work+0x6f0/0x6f0
> [95895.791911] [<ffffffff900d0e30>] ? process_one_work+0x6f0/0x6f0
> [95895.792653] [<ffffffff90003eec>] ? do_syscall_64+0x6c/0x1f0
> [95895.793397] [<ffffffff900d82c2>] kthread+0x102/0x120
> [95895.794212] [<ffffffff90111775>] ?
> trace_hardirqs_on_caller+0xf5/0x1b0
> [95895.794942] [<ffffffff900d81c0>] ? kthread_park+0x60/0x60
> [95895.795689] [<ffffffff90917afa>] ret_from_fork+0x2a/0x40
> [95895.796408] Mem-Info:
> [95895.797110] active_anon:8800 inactive_anon:9030 isolated_anon:32
> active_file:263 inactive_file:238 isolated_file:0
> unevictable:0 dirty:0 writeback:330 unstable:0
> slab_reclaimable:5241 slab_unreclaimable:9538
> mapped:470 shmem:9 pagetables:2200 bounce:0
> free:690 free_pcp:68 free_cma:0
> [95895.801218] Node 0 active_anon:35200kB inactive_anon:36120kB
> active_file:1052kB inactive_file:952kB unevictable:0kB
> isolated(anon):128kB isolated(file):0kB mapped:1880kB dirty:0kB
> writeback:1320kB shmem:0kB shmem_thp: 0kB shmem_pmdmapped: 0kB
> anon_thp: 36kB writeback_tmp:0kB unstable:0kB pages_scanned:179
> all_unreclaimable? no
> [95895.803264] Node 0 DMA free:924kB min:172kB low:212kB high:252kB
> active_anon:3544kB inactive_anon:3944kB active_file:84kB
> inactive_file:140kB unevictable:0kB writepending:4kB present:15992kB
> managed:15908kB mlocked:0kB slab_reclaimable:1728kB
> slab_unreclaimable:2964kB kernel_stack:84kB pagetables:1396kB
> bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
> [95895.805936] lowmem_reserve[]: 0 117 117 117 117
> [95895.806751] Node 0 DMA32 free:1836kB min:1296kB low:1620kB
> high:1944kB active_anon:31636kB inactive_anon:32164kB
> active_file:968kB inactive_file:804kB unevictable:0kB
> writepending:1288kB present:180080kB managed:139012kB mlocked:0kB
> slab_reclaimable:19236kB slab_unreclaimable:35188kB
> kernel_stack:1852kB pagetables:7404kB bounce:0kB free_pcp:272kB
> local_pcp:156kB free_cma:0kB
> [95895.809223] lowmem_reserve[]: 0 0 0 0 0
> [95895.810071] Node 0 DMA: 36*4kB (H) 29*8kB (H) 22*16kB (H) 6*32kB
> (H) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 920kB
> [95895.812089] Node 0 DMA32: 77*4kB (H) 71*8kB (H) 28*16kB (H) 8*32kB
> (H) 4*64kB (H) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB =
> 1836kB
> [95895.813979] Node 0 hugepages_total=0 hugepages_free=0
> hugepages_surp=0 hugepages_size=2048kB
> [95895.813981] 1804 total pagecache pages
> [95895.814931] 1289 pages in swap cache
> [95895.815849] Swap cache stats: add 5288014, delete 5286725, find
> 11568655/13881082
> [95895.816792] Free swap = 1791816kB
> [95895.817706] Total swap = 2064380kB
> [95895.819222] 49018 pages RAM
> [95895.820145] 0 pages HighMem/MovableOnly
> [95895.821039] 10288 pages reserved
> [95895.823325] 0 pages cma reserved
> [95895.824244] 0 pages hwpoisoned
> [95895.825237] SLUB: Unable to allocate memory on node -1,
> gfp=0x2080020(GFP_ATOMIC)
> [95895.826140] cache: kmalloc-256, object size: 256, buffer size:
> 256, default order: 0, min order: 0
> [95895.827034] node 0: slabs: 113, objs: 1808, free: 0
> [97883.838418] httpd invoked oom-killer:
> gfp_mask=0x24201ca(GFP_HIGHUSER_MOVABLE|__GFP_COLD), nodemask=0,
> order=0, oom_score_adj=0
> [97883.843507] httpd cpuset=/ mems_allowed=0
> [97883.843601] CPU: 1 PID: 19043 Comm: httpd Not tainted
> 4.9.0-0.rc8.git2.1.fc26.x86_64 #1
> [97883.844628] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
> BIOS 1.9.3
> [97883.845839] ffffaa62c395f958 ffffffff904774e3 ffffaa62c395fb20
> ffff96b98b8b3100
> [97883.846970] ffffaa62c395f9e0 ffffffff902a8c41 0000000000000000
> 0000000000000000
> [97883.848388] ffffffff90ec6840 ffffaa62c395f990 ffffffff9011183d
> ffffaa62c395f9b0
> [97883.849945] Call Trace:
> [97883.851366] [<ffffffff904774e3>] dump_stack+0x86/0xc3
> [97883.852535] [<ffffffff902a8c41>] dump_header+0x7b/0x24f
> [97883.853718] [<ffffffff9011183d>] ? trace_hardirqs_on+0xd/0x10
> [97883.854857] [<ffffffff902085d3>] oom_kill_process+0x203/0x3e0
> [97883.856192] [<ffffffff90208afb>] out_of_memory+0x13b/0x580
> [97883.857334] [<ffffffff90208bea>] ? out_of_memory+0x22a/0x580
> [97883.858590] [<ffffffff9020f31a>] __alloc_pages_slowpath+0xb8a/0xbb0
> [97883.859706] [<ffffffff9020f74d>] __alloc_pages_nodemask+0x40d/0x4b0
> [97883.860854] [<ffffffff90037de9>] ? sched_clock+0x9/0x10
> [97883.862120] [<ffffffff9026db51>] alloc_pages_current+0xa1/0x1f0
> [97883.863251] [<ffffffff90201d96>] __page_cache_alloc+0x146/0x190
> [97883.864449] [<ffffffff9020366c>] ? pagecache_get_page+0x2c/0x300
> [97883.865602] [<ffffffff90206055>] filemap_fault+0x345/0x790
> [97883.866661] [<ffffffff90206238>] ? filemap_fault+0x528/0x790
> [97883.867795] [<ffffffff903639d9>] ext4_filemap_fault+0x39/0x50
> [97883.869289] [<ffffffff90241ca3>] __do_fault+0x83/0x1d0
> [97883.870301] [<ffffffff90246642>] handle_mm_fault+0x11e2/0x17a0
> [97883.871304] [<ffffffff902454ba>] ? handle_mm_fault+0x5a/0x17a0
> [97883.872491] [<ffffffff9006de16>] __do_page_fault+0x266/0x520
> [97883.873406] [<ffffffff9006e1a8>] trace_do_page_fault+0x58/0x2a0
> [97883.874262] [<ffffffff90067f3a>] do_async_page_fault+0x1a/0xa0
> [97883.875168] [<ffffffff90918e28>] async_page_fault+0x28/0x30
> [97883.882611] Mem-Info:
> [97883.883747] active_anon:2915 inactive_anon:3376 isolated_anon:0
> active_file:3902 inactive_file:3639 isolated_file:0
> unevictable:0 dirty:205 writeback:0 unstable:0
> slab_reclaimable:9856 slab_unreclaimable:9682
> mapped:3722 shmem:59 pagetables:2080 bounce:0
> free:748 free_pcp:15 free_cma:0
> [97883.890766] Node 0 active_anon:11660kB inactive_anon:13504kB
> active_file:15608kB inactive_file:14556kB unevictable:0kB
> isolated(anon):0kB isolated(file):0kB mapped:14888kB dirty:820kB
> writeback:0kB shmem:0kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp:
> 236kB writeback_tmp:0kB unstable:0kB pages_scanned:168352
> all_unreclaimable? yes
> [97883.893210] Node 0 DMA free:1468kB min:172kB low:212kB high:252kB
> active_anon:1716kB inactive_anon:912kB active_file:2292kB
> inactive_file:876kB unevictable:0kB writepending:24kB present:15992kB
> managed:15908kB mlocked:0kB slab_reclaimable:4652kB
> slab_unreclaimable:2852kB kernel_stack:76kB pagetables:496kB
> bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
> [97883.898799] lowmem_reserve[]: 0 117 117 117 117
> [97883.899735] Node 0 DMA32 free:1524kB min:1296kB low:1620kB
> high:1944kB active_anon:9944kB inactive_anon:12572kB
> active_file:13316kB inactive_file:13680kB unevictable:0kB
> writepending:768kB present:180080kB managed:139012kB mlocked:0kB
> slab_reclaimable:34772kB slab_unreclaimable:35876kB
> kernel_stack:1828kB pagetables:7824kB bounce:0kB free_pcp:60kB
> local_pcp:52kB free_cma:0kB
> [97883.903033] lowmem_reserve[]: 0 0 0 0 0
> [97883.904371] Node 0 DMA: 36*4kB (H) 29*8kB (H) 22*16kB (H) 9*32kB
> (H) 3*64kB (H) 2*128kB (H) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB
> = 1464kB
> [97883.906442] Node 0 DMA32: 13*4kB (H) 4*8kB (H) 13*16kB (H) 8*32kB
> (H) 9*64kB (H) 1*128kB (H) 1*256kB (H) 0*512kB 0*1024kB 0*2048kB
> 0*4096kB = 1508kB
> [97883.908598] Node 0 hugepages_total=0 hugepages_free=0
> hugepages_surp=0 hugepages_size=2048kB
> [97883.908600] 10093 total pagecache pages
> [97883.909623] 2486 pages in swap cache
> [97883.910981] Swap cache stats: add 5936545, delete 5934059, find
> 11939248/14560523
> [97883.911932] Free swap = 1924040kB
> [97883.912844] Total swap = 2064380kB
> [97883.913799] 49018 pages RAM
> [97883.915101] 0 pages HighMem/MovableOnly
> [97883.916149] 10288 pages reserved
> [97883.917465] 0 pages cma reserved
> [97883.918528] 0 pages hwpoisoned
> [97883.919635] [ pid ] uid tgid total_vm rss nr_ptes nr_pmds
> swapents oom_score_adj name
> [97883.919656] [ 442] 0 442 15414 276 31 3
> 89 0 systemd-journal
> [97883.919661] [ 479] 0 479 11179 0 22 3
> 323 -1000 systemd-udevd
> [97883.919666] [ 535] 0 535 13888 0 28 3
> 114 -1000 auditd
> [97883.919671] [ 559] 81 559 11565 85 26 3
> 88 -900 dbus-daemon
> [97883.919675] [ 562] 70 562 12026 0 28 3
> 108 0 avahi-daemon
> [97883.919680] [ 578] 0 578 182739 11 279 4
> 263 0 rsyslogd
> [97883.919684] [ 579] 0 579 11890 26 27 3
> 105 0 systemd-logind
> [97883.919688] [ 580] 0 580 123902 265 223 3
> 1889 0 httpd
> [97883.919693] [ 581] 70 581 12026 0 26 3
> 83 0 avahi-daemon
> [97883.919697] [ 596] 0 596 1095 0 8 3
> 35 0 acpid
> [97883.919701] [ 614] 0 614 33234 1 18 4
> 155 0 crond
> [97883.919706] [ 630] 0 630 29260 0 9 3
> 32 0 agetty
> [97883.919710] [ 639] 0 639 25089 70 49 3
> 430 0 sendmail
> [97883.919715] [ 643] 0 643 20785 0 43 3
> 231 -1000 sshd
> [97883.919719] [ 674] 51 674 23428 0 46 3
> 415 0 sendmail
> [97883.919724] [ 723] 0 723 44394 148 38 3
> 2134 0 munin-node
> [97883.919728] [ 2513] 38 2513 6971 23 18 3
> 130 0 ntpd
> [97883.919733] [13908] 0 13908 36690 0 74 3
> 320 0 sshd
> [97883.919738] [13910] 0 13910 15956 1 35 3
> 235 0 systemd
> [97883.919742] [13913] 0 13913 60419 0 49 4
> 463 0 (sd-pam)
> [97883.919747] [13918] 0 13918 36690 147 71 3
> 280 0 sshd
> [97883.919751] [13930] 0 13930 30730 1 13 4
> 285 0 bash
> [97883.919756] [13958] 0 13958 29971 0 13 3
> 55 0 update.sh
> [97883.919761] [13985] 0 13985 159639 4589 192 3
> 26191 0 dnf
> [97883.919766] [17393] 48 17393 177835 704 238 3
> 1711 0 httpd
> [97883.919771] [19018] 48 19018 128626 1434 222 3
> 1342 0 httpd
> [97883.919774] [19043] 48 19043 128067 2010 219 3
> 1492 0 httpd
> [97883.919776] Out of memory: Kill process 13985 (dnf) score 54 or
> sacrifice child
> [97883.920895] Killed process 13985 (dnf) total-vm:638556kB,
> anon-rss:12840kB, file-rss:5516kB, shmem-rss:0kB
> [97883.986808] oom_reaper: reaped process 13985 (dnf), now
> anon-rss:0kB, file-rss:1552kB, shmem-rss:0kB
>
Forgot to mention:
rpm DB is also mostly not usable afterwards, needs reboot:
error: rpmdb: BDB0113 Thread/process 13985/140089649317632 failed:
BDB1507 Thread died in Berkeley DB library
error: db5 error(-30973) from dbenv->failchk: BDB0087 DB_RUNRECOVERY:
Fatal error, run database recovery
error: cannot open Packages index using db5 - (-30973)
error: cannot open Packages database in /var/lib/rpm
Error: Error: rpmdb open failed
Thank you.
Ciao,
Gerhard
On 09.12.2016 14:40, Michal Hocko wrote:
> On Fri 09-12-16 08:06:25, Gerhard Wiesinger wrote:
>> Hello,
>>
>> same with latest kernel rc, dnf still killed with OOM (but sometimes
>> better).
>>
>> ./update.sh: line 40: 1591 Killed ${EXE} update ${PARAMS}
>> (does dnf clean all;dnf update)
>> Linux database.intern 4.9.0-0.rc8.git2.1.fc26.x86_64 #1 SMP Wed Dec 7
>> 17:53:29 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
>>
>> Updated bug report:
>> https://bugzilla.redhat.com/show_bug.cgi?id=1314697
> Could you post your oom report please?
And another one which ended in a native_safe_halt ....
[73366.837826] nmbd: page allocation failure: order:0,
mode:0x2280030(GFP_ATOMIC|__GFP_RECLAIMABLE|__GFP_NOTRACK)
[73366.837985] CPU: 1 PID: 2005 Comm: nmbd Not tainted
4.9.0-0.rc8.git2.1.fc26.x86_64 #1
[73366.838075] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.9.3
[73366.838175] ffffaa4ac059f548 ffffffff8d4774e3 ffffffff8dc7dd98
0000000000000000
[73366.838272] ffffaa4ac059f5d0 ffffffff8d20e6ea 0228003000000046
ffffffff8dc7dd98
[73366.838364] ffffaa4ac059f570 ffff9c3700000010 ffffaa4ac059f5e0
ffffaa4ac059f590
[73366.838458] Call Trace:
[73366.838590] [<ffffffff8d4774e3>] dump_stack+0x86/0xc3
[73366.838680] [<ffffffff8d20e6ea>] warn_alloc+0x13a/0x170
[73366.838762] [<ffffffff8d20e9e2>] __alloc_pages_slowpath+0x252/0xbb0
[73366.838846] [<ffffffff8d0e09a0>] ? finish_task_switch+0xb0/0x260
[73366.838926] [<ffffffff8d20f74d>] __alloc_pages_nodemask+0x40d/0x4b0
[73366.839007] [<ffffffff8d26db51>] alloc_pages_current+0xa1/0x1f0
[73366.839088] [<ffffffff8d068475>] ? kvm_sched_clock_read+0x25/0x40
[73366.839170] [<ffffffff8d278956>] new_slab+0x316/0x7c0
[73366.839245] [<ffffffff8d27ae8b>] ___slab_alloc+0x3fb/0x5c0
[73366.839325] [<ffffffff8d068475>] ? kvm_sched_clock_read+0x25/0x40
[73366.839409] [<ffffffff8d3a4503>] ? __es_insert_extent+0xb3/0x330
[73366.839501] [<ffffffff8d3a4503>] ? __es_insert_extent+0xb3/0x330
[73366.839583] [<ffffffff8d27b0a1>] __slab_alloc+0x51/0x90
[73366.839662] [<ffffffff8d3a4503>] ? __es_insert_extent+0xb3/0x330
[73366.839743] [<ffffffff8d27b326>] kmem_cache_alloc+0x246/0x2d0
[73366.839822] [<ffffffff8d3a5066>] ? __es_remove_extent+0x56/0x2d0
[73366.839906] [<ffffffff8d3a4503>] __es_insert_extent+0xb3/0x330
[73366.839985] [<ffffffff8d3a573e>] ext4_es_insert_extent+0xee/0x280
[73366.840067] [<ffffffff8d35a704>] ? ext4_map_blocks+0x2b4/0x5f0
[73366.840147] [<ffffffff8d35a773>] ext4_map_blocks+0x323/0x5f0
[73366.840225] [<ffffffff8d23dfda>] ? workingset_refault+0x10a/0x220
[73366.840314] [<ffffffff8d3ad7d3>] ext4_mpage_readpages+0x413/0xa60
[73366.840397] [<ffffffff8d201d96>] ? __page_cache_alloc+0x146/0x190
[73366.840487] [<ffffffff8d358235>] ext4_readpages+0x35/0x40
[73366.840569] [<ffffffff8d216d3f>] __do_page_cache_readahead+0x2bf/0x390
[73366.840651] [<ffffffff8d216bea>] ? __do_page_cache_readahead+0x16a/0x390
[73366.840735] [<ffffffff8d20622b>] filemap_fault+0x51b/0x790
[73366.840814] [<ffffffff8d3639ce>] ? ext4_filemap_fault+0x2e/0x50
[73366.840896] [<ffffffff8d3639d9>] ext4_filemap_fault+0x39/0x50
[73366.840976] [<ffffffff8d241ca3>] __do_fault+0x83/0x1d0
[73366.841056] [<ffffffff8d246642>] handle_mm_fault+0x11e2/0x17a0
[73366.841138] [<ffffffff8d2454ba>] ? handle_mm_fault+0x5a/0x17a0
[73366.841220] [<ffffffff8d06de16>] __do_page_fault+0x266/0x520
[73366.841300] [<ffffffff8d06e1a8>] trace_do_page_fault+0x58/0x2a0
[73366.841382] [<ffffffff8d067f3a>] do_async_page_fault+0x1a/0xa0
[73366.841464] [<ffffffff8d918e28>] async_page_fault+0x28/0x30
[73366.842500] Mem-Info:
[73366.843149] active_anon:8677 inactive_anon:8798 isolated_anon:0
active_file:328 inactive_file:317 isolated_file:32
unevictable:0 dirty:0 writeback:2 unstable:0
slab_reclaimable:4968 slab_unreclaimable:9242
mapped:365 shmem:1 pagetables:2690 bounce:0
free:764 free_pcp:41 free_cma:0
[73366.846832] Node 0 active_anon:34708kB inactive_anon:35192kB
active_file:1312kB inactive_file:1268kB unevictable:0kB
isolated(anon):0kB isolated(file):128kB mapped:1460kB dirty:0kB
writeback:8kB shmem:0kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp:
4kB writeback_tmp:0kB unstable:0kB pages_scanned:32 all_unreclaimable? no
[73366.848711] Node 0 DMA free:1468kB min:172kB low:212kB high:252kB
active_anon:3216kB inactive_anon:3448kB active_file:40kB
inactive_file:228kB unevictable:0kB writepending:0kB present:15992kB
managed:15908kB mlocked:0kB slab_reclaimable:2064kB
slab_unreclaimable:2960kB kernel_stack:100kB pagetables:1536kB
bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[73366.850769] lowmem_reserve[]: 0 116 116 116 116
[73366.851479] Node 0 DMA32 free:1588kB min:1296kB low:1620kB
high:1944kB active_anon:31464kB inactive_anon:31740kB active_file:1236kB
inactive_file:1056kB unevictable:0kB writepending:0kB present:180080kB
managed:139012kB mlocked:0kB slab_reclaimable:17808kB
slab_unreclaimable:34008kB kernel_stack:1676kB pagetables:9224kB
bounce:0kB free_pcp:164kB local_pcp:12kB free_cma:0kB
[73366.853757] lowmem_reserve[]: 0 0 0 0 0
[73366.854544] Node 0 DMA: 13*4kB (H) 13*8kB (H) 17*16kB (H) 12*32kB (H)
8*64kB (H) 1*128kB (H) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 1452kB
[73366.856200] Node 0 DMA32: 70*4kB (UMH) 12*8kB (MH) 12*16kB (H) 2*32kB
(H) 5*64kB (H) 5*128kB (H) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB =
1592kB
[73366.857955] Node 0 hugepages_total=0 hugepages_free=0
hugepages_surp=0 hugepages_size=2048kB
[73366.857956] 2401 total pagecache pages
[73366.858829] 1741 pages in swap cache
[73366.859721] Swap cache stats: add 1230889, delete 1229148, find
3509739/3747264
[73366.860616] Free swap = 2059496kB
[73366.861500] Total swap = 2097148kB
[73366.862578] 49018 pages RAM
[73366.863560] 0 pages HighMem/MovableOnly
[73366.864531] 10288 pages reserved
[73366.865436] 0 pages cma reserved
[73366.866395] 0 pages hwpoisoned
[73366.867503] SLUB: Unable to allocate memory on node -1,
gfp=0x2080020(GFP_ATOMIC)
[73366.868507] cache: ext4_extent_status, object size: 40, buffer
size: 40, default order: 0, min order: 0
[73366.869508] node 0: slabs: 13, objs: 1326, free: 0
[96351.012045] dmcrypt_write: page allocation failure: order:0,
mode:0x2280020(GFP_ATOMIC|__GFP_NOTRACK)
[96351.024364] CPU: 0 PID: 1593 Comm: dmcrypt_write Not tainted
4.9.0-0.rc8.git2.1.fc26.x86_64 #1
[96351.027132] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.9.3
[96351.029537] ffffaa4ac025b508 ffffffff8d4774e3 ffffffff8dc7dd98
0000000000000000
[96351.033023] ffffaa4ac025b590 ffffffff8d20e6ea 0228002000000046
ffffffff8dc7dd98
[96351.036214] ffffaa4ac025b530 ffff9c3700000010 ffffaa4ac025b5a0
ffffaa4ac025b550
[96351.039266] Call Trace:
[96351.041426] [<ffffffff8d4774e3>] dump_stack+0x86/0xc3
[96351.044511] [<ffffffff8d20e6ea>] warn_alloc+0x13a/0x170
[96351.046698] [<ffffffff8d20e9e2>] __alloc_pages_slowpath+0x252/0xbb0
[96351.048852] [<ffffffff8d20f74d>] __alloc_pages_nodemask+0x40d/0x4b0
[96351.052025] [<ffffffff8d26db51>] alloc_pages_current+0xa1/0x1f0
[96351.053975] [<ffffffff8d916f17>] ? _raw_spin_unlock+0x27/0x40
[96351.055066] [<ffffffff8d278956>] new_slab+0x316/0x7c0
[96351.056134] [<ffffffff8d0ed4c7>] ? sched_clock_cpu+0xa7/0xc0
[96351.057236] [<ffffffff8d27ae8b>] ___slab_alloc+0x3fb/0x5c0
[96351.058287] [<ffffffff8d10b042>] ? cpuacct_charge+0xf2/0x1f0
[96351.059374] [<ffffffffc03a650d>] ? alloc_indirect.isra.11+0x1d/0x50
[virtio_ring]
[96351.060439] [<ffffffffc03a650d>] ? alloc_indirect.isra.11+0x1d/0x50
[virtio_ring]
[96351.061484] [<ffffffff8d27b0a1>] __slab_alloc+0x51/0x90
[96351.062505] [<ffffffff8d27d141>] __kmalloc+0x251/0x320
[96351.063619] [<ffffffffc03a650d>] ? alloc_indirect.isra.11+0x1d/0x50
[virtio_ring]
[96351.064624] [<ffffffffc03a650d>] alloc_indirect.isra.11+0x1d/0x50
[virtio_ring]
[96351.065631] [<ffffffffc03a7193>] virtqueue_add_sgs+0x1c3/0x4a0
[virtio_ring]
[96351.066564] [<ffffffff8d068475>] ? kvm_sched_clock_read+0x25/0x40
[96351.067504] [<ffffffffc041e65c>] __virtblk_add_req+0xbc/0x220
[virtio_blk]
[96351.068425] [<ffffffff8d1312fd>] ? debug_lockdep_rcu_enabled+0x1d/0x20
[96351.069351] [<ffffffffc041e935>] ? virtio_queue_rq+0x105/0x290
[virtio_blk]
[96351.070229] [<ffffffffc041e95d>] virtio_queue_rq+0x12d/0x290
[virtio_blk]
[96351.071059] [<ffffffff8d45015d>] __blk_mq_run_hw_queue+0x26d/0x3b0
[96351.071904] [<ffffffff8d44fecd>] blk_mq_run_hw_queue+0xad/0xd0
[96351.072727] [<ffffffff8d450fca>] blk_mq_insert_requests+0x24a/0x320
[96351.073607] [<ffffffff8d452419>] blk_mq_flush_plug_list+0x139/0x160
[96351.074397] [<ffffffff8d4451d6>] blk_flush_plug_list+0xb6/0x250
[96351.075111] [<ffffffff8d44586c>] blk_finish_plug+0x2c/0x40
[96351.075869] [<ffffffffc03adef0>] dmcrypt_write+0x210/0x220 [dm_crypt]
[96351.076613] [<ffffffff8d0e6590>] ? wake_up_q+0x80/0x80
[96351.077376] [<ffffffffc03adce0>] ? crypt_iv_essiv_dtr+0x70/0x70
[dm_crypt]
[96351.078086] [<ffffffffc03adce0>] ? crypt_iv_essiv_dtr+0x70/0x70
[dm_crypt]
[96351.078892] [<ffffffff8d0d82c2>] kthread+0x102/0x120
[96351.079635] [<ffffffff8d111775>] ? trace_hardirqs_on_caller+0xf5/0x1b0
[96351.080403] [<ffffffff8d0d81c0>] ? kthread_park+0x60/0x60
[96351.081115] [<ffffffff8d917afa>] ret_from_fork+0x2a/0x40
[96351.081882] Mem-Info:
[96351.082616] active_anon:8390 inactive_anon:8478 isolated_anon:32
active_file:25 inactive_file:30 isolated_file:0
unevictable:0 dirty:0 writeback:151 unstable:0
slab_reclaimable:5304 slab_unreclaimable:9678
mapped:24 shmem:0 pagetables:3012 bounce:0
free:715 free_pcp:77 free_cma:0
[96351.086909] Node 0 active_anon:33560kB inactive_anon:33912kB
active_file:100kB inactive_file:120kB unevictable:0kB
isolated(anon):128kB isolated(file):0kB mapped:96kB dirty:0kB
writeback:604kB shmem:0kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp:
0kB writeback_tmp:0kB unstable:0kB pages_scanned:395 all_unreclaimable? no
[96351.089052] Node 0 DMA free:1452kB min:172kB low:212kB high:252kB
active_anon:3296kB inactive_anon:3768kB active_file:12kB
inactive_file:0kB unevictable:0kB writepending:24kB present:15992kB
managed:15908kB mlocked:0kB slab_reclaimable:2508kB
slab_unreclaimable:3108kB kernel_stack:100kB pagetables:1024kB
bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[96351.091383] lowmem_reserve[]: 0 116 116 116 116
[96351.092155] Node 0 DMA32 free:1408kB min:1296kB low:1620kB
high:1944kB active_anon:30264kB inactive_anon:30140kB active_file:100kB
inactive_file:124kB unevictable:0kB writepending:580kB present:180080kB
managed:139012kB mlocked:0kB slab_reclaimable:18708kB
slab_unreclaimable:35604kB kernel_stack:1820kB pagetables:11024kB
bounce:0kB free_pcp:308kB local_pcp:152kB free_cma:0kB
[96351.094895] lowmem_reserve[]: 0 0 0 0 0
[96351.095803] Node 0 DMA: 13*4kB (H) 13*8kB (H) 17*16kB (H) 12*32kB (H)
8*64kB (H) 1*128kB (H) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 1452kB
[96351.097708] Node 0 DMA32: 16*4kB (H) 6*8kB (H) 5*16kB (H) 8*32kB (H)
5*64kB (H) 5*128kB (H) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 1408kB
[96351.099672] Node 0 hugepages_total=0 hugepages_free=0
hugepages_surp=0 hugepages_size=2048kB
[96351.099673] 5020 total pagecache pages
[96351.100659] 4961 pages in swap cache
[96351.101635] Swap cache stats: add 1422746, delete 1417785, find
4506321/4784232
[96351.102630] Free swap = 1987544kB
[96351.103666] Total swap = 2097148kB
[96351.104730] 49018 pages RAM
[96351.105716] 0 pages HighMem/MovableOnly
[96351.106687] 10288 pages reserved
[96351.107642] 0 pages cma reserved
[96351.108584] 0 pages hwpoisoned
[96351.109523] SLUB: Unable to allocate memory on node -1,
gfp=0x2080020(GFP_ATOMIC)
[96351.110479] cache: kmalloc-256, object size: 256, buffer size: 256,
default order: 0, min order: 0
[96351.111428] node 0: slabs: 102, objs: 1632, free: 0
[96361.915109] swapper/0: page allocation failure: order:0,
mode:0x2280020(GFP_ATOMIC|__GFP_NOTRACK)
[96361.916235] CPU: 0 PID: 0 Comm: swapper/0 Not tainted
4.9.0-0.rc8.git2.1.fc26.x86_64 #1
[96361.917276] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.9.3
[96361.918313] ffff9c3749e03628 ffffffff8d4774e3 ffffffff8dc7dd98
0000000000000000
[96361.919381] ffff9c3749e036b0 ffffffff8d20e6ea 0228002000000046
ffffffff8dc7dd98
[96361.920511] ffff9c3749e03650 ffff9c3700000010 ffff9c3749e036c0
ffff9c3749e03670
[96361.921551] Call Trace:
[96361.922549] <IRQ>
[96361.922566] [<ffffffff8d4774e3>] dump_stack+0x86/0xc3
[96361.923684] [<ffffffff8d20e6ea>] warn_alloc+0x13a/0x170
[96361.924735] [<ffffffff8d20e9e2>] __alloc_pages_slowpath+0x252/0xbb0
[96361.925757] [<ffffffff8d20f74d>] __alloc_pages_nodemask+0x40d/0x4b0
[96361.926772] [<ffffffff8d26db51>] alloc_pages_current+0xa1/0x1f0
[96361.927844] [<ffffffff8d278956>] new_slab+0x316/0x7c0
[96361.928884] [<ffffffff8d27ae8b>] ___slab_alloc+0x3fb/0x5c0
[96361.929874] [<ffffffff8d79b00b>] ? __alloc_skb+0x5b/0x1e0
[96361.930854] [<ffffffff8d037de9>] ? sched_clock+0x9/0x10
[96361.931829] [<ffffffff8d0ed4c7>] ? sched_clock_cpu+0xa7/0xc0
[96361.932796] [<ffffffff8d79b00b>] ? __alloc_skb+0x5b/0x1e0
[96361.933778] [<ffffffff8d27b0a1>] __slab_alloc+0x51/0x90
[96361.934764] [<ffffffff8d27b7c2>] kmem_cache_alloc_node+0xb2/0x310
[96361.935713] [<ffffffff8d79b00b>] ? __alloc_skb+0x5b/0x1e0
[96361.936637] [<ffffffff8d79b00b>] __alloc_skb+0x5b/0x1e0
[96361.937534] [<ffffffff8d7c2a9f>] __neigh_notify+0x3f/0xd0
[96361.938407] [<ffffffff8d7c64b9>] neigh_update+0x379/0x8b0
[96361.939251] [<ffffffff8d0b7000>] ? __local_bh_enable_ip+0x70/0xc0
[96361.940091] [<ffffffff8d844702>] ? udp4_ufo_fragment+0x122/0x1a0
[96361.940915] [<ffffffff8d845ee8>] arp_process+0x2e8/0x9f0
[96361.941708] [<ffffffff8d846745>] arp_rcv+0x135/0x300
[96361.942473] [<ffffffff8d111ed6>] ? __lock_acquire+0x346/0x1290
[96361.943211] [<ffffffff8d7b42cd>] ? netif_receive_skb_internal+0x6d/0x200
[96361.943942] [<ffffffff8d7b36da>] __netif_receive_skb_core+0x23a/0xd60
[96361.944664] [<ffffffff8d7b42d3>] ? netif_receive_skb_internal+0x73/0x200
[96361.945360] [<ffffffff8d7b4218>] __netif_receive_skb+0x18/0x60
[96361.946045] [<ffffffff8d7b4320>] netif_receive_skb_internal+0xc0/0x200
[96361.946693] [<ffffffff8d7b42d3>] ? netif_receive_skb_internal+0x73/0x200
[96361.947329] [<ffffffff8d7b628c>] napi_gro_receive+0x13c/0x200
[96361.948002] [<ffffffffc04cb667>] virtnet_receive+0x477/0x9a0
[virtio_net]
[96361.948690] [<ffffffffc04cbbad>] virtnet_poll+0x1d/0x80 [virtio_net]
[96361.949323] [<ffffffff8d7b501e>] net_rx_action+0x23e/0x470
[96361.949994] [<ffffffff8d91a8cd>] __do_softirq+0xcd/0x4b9
[96361.950639] [<ffffffff8d0b7e98>] irq_exit+0x108/0x110
[96361.951275] [<ffffffff8d91a49a>] do_IRQ+0x6a/0x120
[96361.951925] [<ffffffff8d918256>] common_interrupt+0x96/0x96
[96361.952578] <EOI>
[96361.952589] [<ffffffff8d916676>] ? native_safe_halt+0x6/0x10
[96361.953245] [<ffffffff8d916235>] default_idle+0x25/0x190
[96361.953912] [<ffffffff8d03918f>] arch_cpu_idle+0xf/0x20
[96361.954562] [<ffffffff8d916873>] default_idle_call+0x23/0x40
[96361.955192] [<ffffffff8d104695>] cpu_startup_entry+0x1d5/0x250
[96361.955864] [<ffffffff8d9066b5>] rest_init+0x135/0x140
[96361.956485] [<ffffffff8e1ca01a>] start_kernel+0x48e/0x4af
[96361.957065] [<ffffffff8e1c9120>] ? early_idt_handler_array+0x120/0x120
[96361.957644] [<ffffffff8e1c92ca>] x86_64_start_reservations+0x24/0x26
[96361.958212] [<ffffffff8e1c9419>] x86_64_start_kernel+0x14d/0x170
[96361.958880] SLUB: Unable to allocate memory on node -1,
gfp=0x2080020(GFP_ATOMIC)
[96361.959482] cache: kmalloc-256, object size: 256, buffer size: 256,
default order: 0, min order: 0
[96361.960073] node 0: slabs: 124, objs: 1984, free: 0
[99301.847630] kworker/dying (27373) used greatest stack depth: 8976
bytes left
Ciao,
Gerhard
On Fri 09-12-16 16:52:07, Gerhard Wiesinger wrote:
> On 09.12.2016 14:40, Michal Hocko wrote:
> > On Fri 09-12-16 08:06:25, Gerhard Wiesinger wrote:
> > > Hello,
> > >
> > > same with latest kernel rc, dnf still killed with OOM (but sometimes
> > > better).
> > >
> > > ./update.sh: line 40: 1591 Killed ${EXE} update ${PARAMS}
> > > (does dnf clean all;dnf update)
> > > Linux database.intern 4.9.0-0.rc8.git2.1.fc26.x86_64 #1 SMP Wed Dec 7
> > > 17:53:29 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
> > >
> > > Updated bug report:
> > > https://bugzilla.redhat.com/show_bug.cgi?id=1314697
> > Could you post your oom report please?
>
> E.g. a new one with more than one included, first one after boot ...
>
> Just setup a low mem VM under KVM and it is easily triggerable.
What is the workload?
> Still enough virtual memory available ...
Well, you will always have a lot of virtual memory...
> 4.9.0-0.rc8.git2.1.fc26.x86_64
>
> [ 624.862777] ksoftirqd/0: page allocation failure: order:0, mode:0x2080020(GFP_ATOMIC)
[...]
> [95895.765570] kworker/1:1H: page allocation failure: order:0, mode:0x2280020(GFP_ATOMIC|__GFP_NOTRACK)
These are atomic allocation failures and should be recoverable.
[...]
> [97883.838418] httpd invoked oom-killer: gfp_mask=0x24201ca(GFP_HIGHUSER_MOVABLE|__GFP_COLD), nodemask=0, order=0, oom_score_adj=0
But this is a real OOM killer invocation because a single page allocation
cannot proceed.
[...]
> [97883.882611] Mem-Info:
> [97883.883747] active_anon:2915 inactive_anon:3376 isolated_anon:0
> active_file:3902 inactive_file:3639 isolated_file:0
> unevictable:0 dirty:205 writeback:0 unstable:0
> slab_reclaimable:9856 slab_unreclaimable:9682
> mapped:3722 shmem:59 pagetables:2080 bounce:0
> free:748 free_pcp:15 free_cma:0
there is still some page cache which doesn't seem to be neither dirty
nor under writeback. So it should be theoretically reclaimable but for
some reason we cannot seem to reclaim that memory.
There is still some anonymous memory and free swap so we could reclaim
it as well but it all seems pretty down and the memory pressure is
really large
> [97883.890766] Node 0 active_anon:11660kB inactive_anon:13504kB
> active_file:15608kB inactive_file:14556kB unevictable:0kB isolated(anon):0kB
> isolated(file):0kB mapped:14888kB dirty:820kB writeback:0kB shmem:0kB
> shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 236kB writeback_tmp:0kB
> unstable:0kB pages_scanned:168352 all_unreclaimable? yes
all_unreclaimable also agrees that basically nothing is reclaimable.
That was one of the criterion to hit the OOM killer prior to the rewrite
in 4.6 kernel. So I suspect that older kernels would OOM under your
memory pressure as well.
--
Michal Hocko
SUSE Labs
On 09.12.2016 17:09, Michal Hocko wrote:
> On Fri 09-12-16 16:52:07, Gerhard Wiesinger wrote:
>> On 09.12.2016 14:40, Michal Hocko wrote:
>>> On Fri 09-12-16 08:06:25, Gerhard Wiesinger wrote:
>>>> Hello,
>>>>
>>>> same with latest kernel rc, dnf still killed with OOM (but sometimes
>>>> better).
>>>>
>>>> ./update.sh: line 40: 1591 Killed ${EXE} update ${PARAMS}
>>>> (does dnf clean all;dnf update)
>>>> Linux database.intern 4.9.0-0.rc8.git2.1.fc26.x86_64 #1 SMP Wed Dec 7
>>>> 17:53:29 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
>>>>
>>>> Updated bug report:
>>>> https://bugzilla.redhat.com/show_bug.cgi?id=1314697
>>> Could you post your oom report please?
>> E.g. a new one with more than one included, first one after boot ...
>>
>> Just setup a low mem VM under KVM and it is easily triggerable.
> What is the workload?
just run dnf clean all;dnf update
(and the other tasks running on those machine. The normal load on most
of these machines is pretty VERY LOW, e.g. running just an apache httpd
doing nothing or e.g. running samba domain controller doing nothing)
So my setups are low mem VMs so that KVM host has most of the caching
effects shared.
I'm running this setup since Fedora 17 under kernel-3.3.4-5.fc17.x86_64
and had NO problems.
Problems started with 4.4.3-300.fc23.x86_64 and got worser in each major
kernel versions (for upgrades I had even give the VMs temporarilly more
memory for the upgrade situation).
(from my bug report at
https://bugzilla.redhat.com/show_bug.cgi?id=1314697
Previous kernel version on guest/host was rocket stable. Revert to
kernel-4.3.5-300.fc23.x86_64 also solved it.)
For completeness the actual kernel parameters on all hosts and VMs.
vm.dirty_background_ratio=3
vm.dirty_ratio=15
vm.overcommit_memory=2
vm.overcommit_ratio=80
vm.swappiness=10
With kernel 4.9.0rc7 or rc8 it was getting better. But still not there
where it should be (and was already).
>
>> Still enough virtual memory available ...
> Well, you will always have a lot of virtual memory...
And why is it not used, e.g. swapped and gets into an OOM situation?
>
>> 4.9.0-0.rc8.git2.1.fc26.x86_64
>>
>> [ 624.862777] ksoftirqd/0: page allocation failure: order:0, mode:0x2080020(GFP_ATOMIC)
> [...]
>> [95895.765570] kworker/1:1H: page allocation failure: order:0, mode:0x2280020(GFP_ATOMIC|__GFP_NOTRACK)
> These are atomic allocation failures and should be recoverable.
> [...]
>
>> [97883.838418] httpd invoked oom-killer: gfp_mask=0x24201ca(GFP_HIGHUSER_MOVABLE|__GFP_COLD), nodemask=0, order=0, oom_score_adj=0
> But this is a real OOM killer invocation because a single page allocation
> cannot proceed.
>
> [...]
>> [97883.882611] Mem-Info:
>> [97883.883747] active_anon:2915 inactive_anon:3376 isolated_anon:0
>> active_file:3902 inactive_file:3639 isolated_file:0
>> unevictable:0 dirty:205 writeback:0 unstable:0
>> slab_reclaimable:9856 slab_unreclaimable:9682
>> mapped:3722 shmem:59 pagetables:2080 bounce:0
>> free:748 free_pcp:15 free_cma:0
> there is still some page cache which doesn't seem to be neither dirty
> nor under writeback. So it should be theoretically reclaimable but for
> some reason we cannot seem to reclaim that memory.
> There is still some anonymous memory and free swap so we could reclaim
> it as well but it all seems pretty down and the memory pressure is
> really large
Yes, it might be large on the update situation, but that should be
handled by a virtual memory system by the kernel, right?
>
>> [97883.890766] Node 0 active_anon:11660kB inactive_anon:13504kB
>> active_file:15608kB inactive_file:14556kB unevictable:0kB isolated(anon):0kB
>> isolated(file):0kB mapped:14888kB dirty:820kB writeback:0kB shmem:0kB
>> shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 236kB writeback_tmp:0kB
>> unstable:0kB pages_scanned:168352 all_unreclaimable? yes
> all_unreclaimable also agrees that basically nothing is reclaimable.
> That was one of the criterion to hit the OOM killer prior to the rewrite
> in 4.6 kernel. So I suspect that older kernels would OOM under your
> memory pressure as well.
See comments above.
Thnx.
Ciao,
Gerhard
On Fri 09-12-16 17:58:14, Gerhard Wiesinger wrote:
> On 09.12.2016 17:09, Michal Hocko wrote:
[...]
> > > [97883.882611] Mem-Info:
> > > [97883.883747] active_anon:2915 inactive_anon:3376 isolated_anon:0
> > > active_file:3902 inactive_file:3639 isolated_file:0
> > > unevictable:0 dirty:205 writeback:0 unstable:0
> > > slab_reclaimable:9856 slab_unreclaimable:9682
> > > mapped:3722 shmem:59 pagetables:2080 bounce:0
> > > free:748 free_pcp:15 free_cma:0
> > there is still some page cache which doesn't seem to be neither dirty
> > nor under writeback. So it should be theoretically reclaimable but for
> > some reason we cannot seem to reclaim that memory.
> > There is still some anonymous memory and free swap so we could reclaim
> > it as well but it all seems pretty down and the memory pressure is
> > really large
>
> Yes, it might be large on the update situation, but that should be handled
> by a virtual memory system by the kernel, right?
Well this is what we try and call it memory reclaim. But if we are not
able to reclaim anything then we eventually have to give up and trigger
the OOM killer. Now the information that 4.4 made a difference is
interesting. I do not really see any major differences in the reclaim
between 4.3 and 4.4 kernels. The reason might be somewhere else as well.
E.g. some of the subsystem consumes much more memory than before.
Just curious, what kind of filesystem are you using? Could you try some
additional debugging. Enabling reclaim related tracepoints might tell us
more. The following should tell us more
mount -t tracefs none /trace
echo 1 > /trace/events/vmscan/enable
echo 1 > /trace/events/writeback/writeback_congestion_wait/enable
cat /trace/trace_pipe > trace.log
Collecting /proc/vmstat over time might be helpful as well
mkdir logs
while true
do
cp /proc/vmstat vmstat.$(date +%s)
sleep 1s
done
--
Michal Hocko
SUSE Labs
On 09.12.2016 18:30, Michal Hocko wrote:
> On Fri 09-12-16 17:58:14, Gerhard Wiesinger wrote:
>> On 09.12.2016 17:09, Michal Hocko wrote:
> [...]
>>>> [97883.882611] Mem-Info:
>>>> [97883.883747] active_anon:2915 inactive_anon:3376 isolated_anon:0
>>>> active_file:3902 inactive_file:3639 isolated_file:0
>>>> unevictable:0 dirty:205 writeback:0 unstable:0
>>>> slab_reclaimable:9856 slab_unreclaimable:9682
>>>> mapped:3722 shmem:59 pagetables:2080 bounce:0
>>>> free:748 free_pcp:15 free_cma:0
>>> there is still some page cache which doesn't seem to be neither dirty
>>> nor under writeback. So it should be theoretically reclaimable but for
>>> some reason we cannot seem to reclaim that memory.
>>> There is still some anonymous memory and free swap so we could reclaim
>>> it as well but it all seems pretty down and the memory pressure is
>>> really large
>> Yes, it might be large on the update situation, but that should be handled
>> by a virtual memory system by the kernel, right?
> Well this is what we try and call it memory reclaim. But if we are not
> able to reclaim anything then we eventually have to give up and trigger
> the OOM killer.
I'm not familiar with the Linux implementation of the VM system in
detail. But can't you reserve as much memory for the kernel (non
pageable) at least that you can swap everything out (even without
killing a process at least as long there is enough swap available, which
should be in all of my cases)?
> Now the information that 4.4 made a difference is
> interesting. I do not really see any major differences in the reclaim
> between 4.3 and 4.4 kernels. The reason might be somewhere else as well.
> E.g. some of the subsystem consumes much more memory than before.
>
> Just curious, what kind of filesystem are you using?
I'm using ext4 only with virt-* drivers (storage, network). But it is
definitly a virtual memory allocation/swap usage issue.
> Could you try some
> additional debugging. Enabling reclaim related tracepoints might tell us
> more. The following should tell us more
> mount -t tracefs none /trace
> echo 1 > /trace/events/vmscan/enable
> echo 1 > /trace/events/writeback/writeback_congestion_wait/enable
> cat /trace/trace_pipe > trace.log
>
> Collecting /proc/vmstat over time might be helpful as well
> mkdir logs
> while true
> do
> cp /proc/vmstat vmstat.$(date +%s)
> sleep 1s
> done
Activated it. But I think it should be very easy to trigger also on your
side. A very small configured VM with a program running RAM
allocations/writes (I guess you have some testing programs already)
should be sufficient to trigger it. You can also use the attached
program which I used to trigger such situations some years ago. If it
doesn't help try to reduce the available CPU for the VM and also I/O
(e.g. use all CPU/IO on the host or other VMs).
BTW: Don't know if you have seen also my original message on the kernel
mailinglist only:
Linus had also OOM problems with 1kB RAM requests and a lot of free RAM
(use a translation service for the german page):
https://lkml.org/lkml/2016/11/30/64
https://marius.bloggt-in-braunschweig.de/2016/11/17/linuxkernel-4-74-8-und-der-oom-killer/
https://www.spinics.net/lists/linux-mm/msg113661.html
Thnx.
Ciao,
Gerhard
// mallocsleep.c
#include <stdlib.h>
#include <stdio.h>
#include <unistd.h>
typedef unsigned int BOOL;
typedef char* PCHAR;
typedef unsigned int DWORD;
typedef unsigned long DDWORD;
#define FALSE 0
#define TRUE 1
BOOL getlong(PCHAR s, DDWORD* retvalue)
{
char *eptr;
long value;
value=strtoll(s,&eptr,0);
if ((eptr == s)||(*eptr != '\0')) return FALSE;
if (value < 0) return FALSE;
*retvalue = value;
return TRUE;
}
int main(int argc, char* argv[])
{
unsigned long* p;
unsigned long size = 16*1024*1024;
unsigned long size_of = sizeof(*p);
unsigned long i;
unsigned long sleep_allocated = 3600;
unsigned long sleep_freed = 3600;
if (argc > 1)
{
if (!getlong(argv[1], &size))
{
printf("Wrong memsize!\n");
exit(1);
}
}
if (argc > 2)
{
if (!getlong(argv[2], &sleep_allocated))
{
printf("Wrong sleep_allocated time!\n");
exit(1);
}
}
if (argc > 3)
{
if (!getlong(argv[3], &sleep_freed))
{
printf("Wrong sleep_freed time!\n");
exit(1);
}
}
printf("size=%lu, size_of=%lu\n", size, size_of);
fflush(stdout);
p = malloc(size);
if (!p)
{
printf("Could not allocate memory!\n");
exit(2);
}
printf("malloc done, writing to memory, p=%p ...\n", (void*)p);
fflush(stdout);
for(i = 0;i < (size/size_of);i++) p[i]=i;
printf("writing to memory done, sleeping for %lu seconds ...\n",
sleep_allocated);
fflush(stdout);
sleep(sleep_allocated);
printf("sleeping done, freeing ...\n");
fflush(stdout);
free(p);
printf("freeing done, sleeping for %lu seconds ...\n", sleep_freed);
fflush(stdout);
sleep(sleep_freed);
printf("sleeping done, exitiing ...\n");
fflush(stdout);
exit(0);
return 0;
}
On 12/09/2016 07:01 PM, Gerhard Wiesinger wrote:
> On 09.12.2016 18:30, Michal Hocko wrote:
>> On Fri 09-12-16 17:58:14, Gerhard Wiesinger wrote:
>>> On 09.12.2016 17:09, Michal Hocko wrote:
>> [...]
>>>>> [97883.882611] Mem-Info:
>>>>> [97883.883747] active_anon:2915 inactive_anon:3376 isolated_anon:0
>>>>> active_file:3902 inactive_file:3639 isolated_file:0
>>>>> unevictable:0 dirty:205 writeback:0 unstable:0
>>>>> slab_reclaimable:9856 slab_unreclaimable:9682
>>>>> mapped:3722 shmem:59 pagetables:2080 bounce:0
>>>>> free:748 free_pcp:15 free_cma:0
>>>> there is still some page cache which doesn't seem to be neither dirty
>>>> nor under writeback. So it should be theoretically reclaimable but for
>>>> some reason we cannot seem to reclaim that memory.
>>>> There is still some anonymous memory and free swap so we could reclaim
>>>> it as well but it all seems pretty down and the memory pressure is
>>>> really large
>>> Yes, it might be large on the update situation, but that should be handled
>>> by a virtual memory system by the kernel, right?
>> Well this is what we try and call it memory reclaim. But if we are not
>> able to reclaim anything then we eventually have to give up and trigger
>> the OOM killer.
>
> I'm not familiar with the Linux implementation of the VM system in
> detail. But can't you reserve as much memory for the kernel (non
> pageable) at least that you can swap everything out (even without
> killing a process at least as long there is enough swap available, which
> should be in all of my cases)?
We don't have such bulletproof reserves. In this case the amount of
anonymous memory that can be swapped out is relatively low, and either
something is pinning it in memory, or it's being swapped back in quickly.
>> Now the information that 4.4 made a difference is
>> interesting. I do not really see any major differences in the reclaim
>> between 4.3 and 4.4 kernels. The reason might be somewhere else as well.
>> E.g. some of the subsystem consumes much more memory than before.
>>
>> Just curious, what kind of filesystem are you using?
>
> I'm using ext4 only with virt-* drivers (storage, network). But it is
> definitly a virtual memory allocation/swap usage issue.
>
>> Could you try some
>> additional debugging. Enabling reclaim related tracepoints might tell us
>> more. The following should tell us more
>> mount -t tracefs none /trace
>> echo 1 > /trace/events/vmscan/enable
>> echo 1 > /trace/events/writeback/writeback_congestion_wait/enable
>> cat /trace/trace_pipe > trace.log
>>
>> Collecting /proc/vmstat over time might be helpful as well
>> mkdir logs
>> while true
>> do
>> cp /proc/vmstat vmstat.$(date +%s)
>> sleep 1s
>> done
>
> Activated it. But I think it should be very easy to trigger also on your
> side. A very small configured VM with a program running RAM
> allocations/writes (I guess you have some testing programs already)
> should be sufficient to trigger it. You can also use the attached
> program which I used to trigger such situations some years ago. If it
> doesn't help try to reduce the available CPU for the VM and also I/O
> (e.g. use all CPU/IO on the host or other VMs).
Well it's not really a surprise that if the VM is small enough and
workload large enough, OOM killer will kick in. The exact threshold
might have changed between kernel versions for a number of possible reasons.
>
> BTW: Don't know if you have seen also my original message on the kernel
> mailinglist only:
>
> Linus had also OOM problems with 1kB RAM requests and a lot of free RAM
> (use a translation service for the german page):
> https://lkml.org/lkml/2016/11/30/64
> https://marius.bloggt-in-braunschweig.de/2016/11/17/linuxkernel-4-74-8-und-der-oom-killer/
> https://www.spinics.net/lists/linux-mm/msg113661.html
Yeah we were involved in the last one. The regressions were about
high-order allocations
though (the 1kB premise turned out to be misinterpretation) and there
were regressions
for those in 4.7/4.8. But yours are order-0.
On 09.12.2016 22:42, Vlastimil Babka wrote:
> On 12/09/2016 07:01 PM, Gerhard Wiesinger wrote:
>> On 09.12.2016 18:30, Michal Hocko wrote:
>>> On Fri 09-12-16 17:58:14, Gerhard Wiesinger wrote:
>>>> On 09.12.2016 17:09, Michal Hocko wrote:
>>> [...]
>>>>>> [97883.882611] Mem-Info:
>>>>>> [97883.883747] active_anon:2915 inactive_anon:3376 isolated_anon:0
>>>>>> active_file:3902 inactive_file:3639 isolated_file:0
>>>>>> unevictable:0 dirty:205 writeback:0 unstable:0
>>>>>> slab_reclaimable:9856 slab_unreclaimable:9682
>>>>>> mapped:3722 shmem:59 pagetables:2080 bounce:0
>>>>>> free:748 free_pcp:15 free_cma:0
>>>>> there is still some page cache which doesn't seem to be neither dirty
>>>>> nor under writeback. So it should be theoretically reclaimable but for
>>>>> some reason we cannot seem to reclaim that memory.
>>>>> There is still some anonymous memory and free swap so we could reclaim
>>>>> it as well but it all seems pretty down and the memory pressure is
>>>>> really large
>>>> Yes, it might be large on the update situation, but that should be handled
>>>> by a virtual memory system by the kernel, right?
>>> Well this is what we try and call it memory reclaim. But if we are not
>>> able to reclaim anything then we eventually have to give up and trigger
>>> the OOM killer.
>> I'm not familiar with the Linux implementation of the VM system in
>> detail. But can't you reserve as much memory for the kernel (non
>> pageable) at least that you can swap everything out (even without
>> killing a process at least as long there is enough swap available, which
>> should be in all of my cases)?
> We don't have such bulletproof reserves. In this case the amount of
> anonymous memory that can be swapped out is relatively low, and either
> something is pinning it in memory, or it's being swapped back in quickly.
>
>>> Now the information that 4.4 made a difference is
>>> interesting. I do not really see any major differences in the reclaim
>>> between 4.3 and 4.4 kernels. The reason might be somewhere else as well.
>>> E.g. some of the subsystem consumes much more memory than before.
>>>
>>> Just curious, what kind of filesystem are you using?
>> I'm using ext4 only with virt-* drivers (storage, network). But it is
>> definitly a virtual memory allocation/swap usage issue.
>>
>>> Could you try some
>>> additional debugging. Enabling reclaim related tracepoints might tell us
>>> more. The following should tell us more
>>> mount -t tracefs none /trace
>>> echo 1 > /trace/events/vmscan/enable
>>> echo 1 > /trace/events/writeback/writeback_congestion_wait/enable
>>> cat /trace/trace_pipe > trace.log
>>>
>>> Collecting /proc/vmstat over time might be helpful as well
>>> mkdir logs
>>> while true
>>> do
>>> cp /proc/vmstat vmstat.$(date +%s)
>>> sleep 1s
>>> done
>> Activated it. But I think it should be very easy to trigger also on your
>> side. A very small configured VM with a program running RAM
>> allocations/writes (I guess you have some testing programs already)
>> should be sufficient to trigger it. You can also use the attached
>> program which I used to trigger such situations some years ago. If it
>> doesn't help try to reduce the available CPU for the VM and also I/O
>> (e.g. use all CPU/IO on the host or other VMs).
> Well it's not really a surprise that if the VM is small enough and
> workload large enough, OOM killer will kick in. The exact threshold
> might have changed between kernel versions for a number of possible reasons.
IMHO: The OOM killer should NOT kick in even on the highest workloads if
there is swap available.
https://www.spinics.net/lists/linux-mm/msg113665.html
Yeah, but I do think that "oom when you have 156MB free and 7GB
reclaimable, and haven't even tried swapping" counts as obviously
wrong.
So Linus also thinks that trying swapping is a must have. And there always was enough swap available in my cases. Then it should swap out/swapin all the time (which worked well in kernel 2.4/2.6 times).
Another topic: Why does the kernel prefer to swap in/swap out instead of
use cache pages/buffers (see vmstat 1 output below)?
>
>> BTW: Don't know if you have seen also my original message on the kernel
>> mailinglist only:
>>
>> Linus had also OOM problems with 1kB RAM requests and a lot of free RAM
>> (use a translation service for the german page):
>> https://lkml.org/lkml/2016/11/30/64
>> https://marius.bloggt-in-braunschweig.de/2016/11/17/linuxkernel-4-74-8-und-der-oom-killer/
>> https://www.spinics.net/lists/linux-mm/msg113661.html
> Yeah we were involved in the last one. The regressions were about
> high-order allocations
> though (the 1kB premise turned out to be misinterpretation) and there
> were regressions
> for those in 4.7/4.8. But yours are order-0.
>
With kernel 4.7./4.8 it was really reaproduceable at every dnf update.
With 4.9rc8 it has been much much better. So something must have
changed, too.
As far as I understood it the order is 2^order kB pagesize. I don't
think it makes a difference when swap is not used which order the memory
allocation request is.
BTW: What were the commit that introduced the regression anf fixed it in
4.9?
Thnx.
Ciao,
Gerhard
procs -----------memory---------- ---swap-- -----io---- -system--
------cpu-----
r b swpd free buff cache si so bi bo in cs us sy
id wa st
3 0 45232 9252 1956 109644 428 232 3536 416 4310 4228 38 36
14 7 6
2 0 45124 10524 1960 110192 124 0 528 96 2478 2243 45 29
20 5 1
4 1 45136 3896 1968 114388 84 64 4824 260 2689 2655 38 31
15 12 4
1 1 45484 10648 288 114032 88 356 20028 1132 5078 5122 24
45 4 21 5
2 0 44700 8092 1240 115204 728 0 2624 536 4204 4413 38 38
18 3 4
2 0 44852 10272 1240 111324 52 212 2736 1548 3311 2970 41 36
12 9 2
4 0 44844 10716 1240 111216 8 0 8 72 3067 3287 42 30
18 7 3
3 0 44828 10268 1248 111280 16 0 16 60 2139 1610 43 29
11 1 17
1 0 44828 11644 1248 111192 0 0 0 0 2367 1911 50 32
14 0 3
4 0 44820 9004 1248 111284 8 0 8 0 2207 1867 55 31
14 0 1
7 0 45664 6360 1816 109264 20 868 3076 968 4122 3783 43 37
17 0 3
4 4 46880 6732 1092 101960 244 1332 7968 3352 5836 6431 17
51 1 27 4
10 2 47064 6940 1364 96340 20 196 25708 1720 7346 6447 13 70
0 18 1
15 3 47572 3672 2156 92604 68 580 29244 1692 5640 5102 5 57
0 37 2
12 4 48300 6740 352 87924 80 948 36208 2948 7287 7955 7 73
0 18 2
12 9 50796 4832 584 88372 0 2496 16064 3312 3425 4185 2 30
0 66 1
10 9 52636 3608 2068 90132 56 1840 24552 2836 4123 4099 3 43
0 52 1
7 11 56740 10376 424 86204 184 4152 33116 5628 7949 7952 4
67 0 23 6
10 4 61384 8000 776 86956 644 4784 28380 5484 7965 9935 7 64
0 26 2
11 4 68052 5260 1028 87268 1244 7164 23380 8684 10715 10863 8
71 0 20 1
11 2 72244 3924 1052 85160 980 4264 23756 4940 7231 7930 8 62
0 29 1
6 1 76388 5352 4948 86204 1292 4640 27380 5244 7816 8714 10
63 0 22 5
8 5 77376 4168 1944 86528 3064 3684 19876 4104 9325 9076 9
64 1 22 4
5 4 75464 7272 1240 81684 3912 3188 25656 4100 9973 10515 11
65 0 20 4
5 2 77364 4440 1852 84744 528 2304 28588 3304 6605 6311 7
61 8 18 4
9 2 81648 3760 3188 86012 440 4588 17928 5368 6377 6320 8
48 2 40 4
6 2 82404 6608 668 86092 2016 2084 24396 3564 7440 7510 8
66 1 20 4
4 4 81728 3796 2260 87764 1392 984 18512 1684 5196 4652 6
48 0 42 4
8 4 84700 6436 1428 85744 1188 3708 20256 4364 6405 5998 9
63 0 24 4
3 1 86360 4836 924 87700 1388 2692 19460 3504 5498 6117 8
48 0 34 9
4 4 87916 3768 176 86592 2788 3220 19664 4032 7285 8342 19
63 0 10 9
4 4 89612 4952 180 88076 1516 2988 17560 3936 5737 5794 7
46 0 37 10
7 5 87768 12244 196 87856 3344 2544 22248 3348 6934 7497 8
59 0 22 10
10 1 83436 4768 840 96452 4096 836 20100 1160 6191 6614 21 52
0 13 14
0 6 82868 6972 348 91020 1108 520 4896 568 3274 4214 11 26
29 30 4
On Sat 10-12-16 14:50:34, Gerhard Wiesinger wrote:
[...]
> IMHO: The OOM killer should NOT kick in even on the highest workloads if
> there is swap available.
This is not so simple. Take a heavy swap trashing situation as an
example. You still have a lot of swap space and an anonymous memory
which can be swapped out but if the workload simply keeps refaulting
the swapped out memory all the time then you can barely make any further
progress and end up in the swap IO hell. Invoking the OOM killer in such
a situation would be a relief to make the system usable again.
> https://www.spinics.net/lists/linux-mm/msg113665.html
>
> Yeah, but I do think that "oom when you have 156MB free and 7GB
> reclaimable, and haven't even tried swapping" counts as obviously
> wrong.
No question about this part of course.
> So Linus also thinks that trying swapping is a must have. And there
> always was enough swap available in my cases. Then it should swap
> out/swapin all the time (which worked well in kernel 2.4/2.6 times).
>
> Another topic: Why does the kernel prefer to swap in/swap out instead of use
> cache pages/buffers (see vmstat 1 output below)?
In the vast majority cases it is quite contrary. We heavily bias page
cache reclaim in favor of the anonymous memory. Have a look at
get_scan_count function which determines the balance.
I would need to see /proc/vmstat collected during this time period to
tell you more about why the particular balance was used.
[...]
> With kernel 4.7./4.8 it was really reaproduceable at every dnf update. With
> 4.9rc8 it has been much much better. So something must have changed, too.
that is good to hear but I it would be much better to collect reclaim
related data so that we can analyse what is actually going on here.
> As far as I understood it the order is 2^order kB pagesize. I don't think it
> makes a difference when swap is not used which order the memory allocation
> request is.
>
> BTW: What were the commit that introduced the regression anf fixed it in
> 4.9?
I cannot really answer this without actually understanding what is going
on here and for that I do not have the relevant data.
--
Michal Hocko
SUSE Labs
On Fri, Dec 09, 2016 at 04:52:07PM +0100, Gerhard Wiesinger wrote:
> On 09.12.2016 14:40, Michal Hocko wrote:
> >On Fri 09-12-16 08:06:25, Gerhard Wiesinger wrote:
> >>Hello,
> >>
> >>same with latest kernel rc, dnf still killed with OOM (but sometimes
> >>better).
> >>
> >>./update.sh: line 40: 1591 Killed ${EXE} update ${PARAMS}
> >>(does dnf clean all;dnf update)
> >>Linux database.intern 4.9.0-0.rc8.git2.1.fc26.x86_64 #1 SMP Wed Dec 7
> >>17:53:29 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
> >>
> >>Updated bug report:
> >>https://bugzilla.redhat.com/show_bug.cgi?id=1314697
> >Could you post your oom report please?
>
> E.g. a new one with more than one included, first one after boot ...
>
> Just setup a low mem VM under KVM and it is easily triggerable.
>
> Still enough virtual memory available ...
>
> 4.9.0-0.rc8.git2.1.fc26.x86_64
>
> [ 624.862777] ksoftirqd/0: page allocation failure: order:0,
> mode:0x2080020(GFP_ATOMIC)
> [ 624.863319] CPU: 0 PID: 3 Comm: ksoftirqd/0 Not tainted
> 4.9.0-0.rc8.git2.1.fc26.x86_64 #1
> [ 624.863410] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
> 1.9.3
> [ 624.863510] ffffaa62c007f958 ffffffff904774e3 ffffffff90c7dd98
> 0000000000000000
> [ 624.863923] ffffaa62c007f9e0 ffffffff9020e6ea 0208002000000246
> ffffffff90c7dd98
> [ 624.864019] ffffaa62c007f980 ffff96b900000010 ffffaa62c007f9f0
> ffffaa62c007f9a0
> [ 624.864998] Call Trace:
> [ 624.865149] [<ffffffff904774e3>] dump_stack+0x86/0xc3
> [ 624.865347] [<ffffffff9020e6ea>] warn_alloc+0x13a/0x170
> [ 624.865432] [<ffffffff9020e9e2>] __alloc_pages_slowpath+0x252/0xbb0
> [ 624.865563] [<ffffffff9020f74d>] __alloc_pages_nodemask+0x40d/0x4b0
> [ 624.865675] [<ffffffff9020f983>] __alloc_page_frag+0x193/0x200
> [ 624.866024] [<ffffffff907a1d7e>] __napi_alloc_skb+0x8e/0xf0
> [ 624.866113] [<ffffffffc017777d>] page_to_skb.isra.28+0x5d/0x310
> [virtio_net]
> [ 624.866201] [<ffffffffc01794cb>] virtnet_receive+0x2db/0x9a0
> [virtio_net]
> [ 624.867378] [<ffffffffc0179bad>] virtnet_poll+0x1d/0x80 [virtio_net]
> [ 624.867494] [<ffffffff907b501e>] net_rx_action+0x23e/0x470
> [ 624.867612] [<ffffffff9091a8cd>] __do_softirq+0xcd/0x4b9
> [ 624.867704] [<ffffffff900dd164>] ? smpboot_thread_fn+0x34/0x1f0
> [ 624.867833] [<ffffffff900dd25d>] ? smpboot_thread_fn+0x12d/0x1f0
> [ 624.867924] [<ffffffff900b7c95>] run_ksoftirqd+0x25/0x80
> [ 624.868109] [<ffffffff900dd258>] smpboot_thread_fn+0x128/0x1f0
> [ 624.868197] [<ffffffff900dd130>] ? sort_range+0x30/0x30
> [ 624.868596] [<ffffffff900d82c2>] kthread+0x102/0x120
> [ 624.868679] [<ffffffff909117a0>] ? wait_for_completion+0x110/0x140
> [ 624.868768] [<ffffffff900d81c0>] ? kthread_park+0x60/0x60
> [ 624.868850] [<ffffffff90917afa>] ret_from_fork+0x2a/0x40
> [ 843.528656] httpd (2490) used greatest stack depth: 10304 bytes left
> [ 878.077750] httpd (2976) used greatest stack depth: 10096 bytes left
> [93918.861109] netstat (14579) used greatest stack depth: 9488 bytes left
> [94050.874669] kworker/dying (6253) used greatest stack depth: 9008 bytes
> left
> [95895.765570] kworker/1:1H: page allocation failure: order:0,
> mode:0x2280020(GFP_ATOMIC|__GFP_NOTRACK)
> [95895.765819] CPU: 1 PID: 440 Comm: kworker/1:1H Not tainted
> 4.9.0-0.rc8.git2.1.fc26.x86_64 #1
> [95895.765911] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
> 1.9.3
> [95895.766060] Workqueue: kblockd blk_mq_run_work_fn
> [95895.766143] ffffaa62c0257628 ffffffff904774e3 ffffffff90c7dd98
> 0000000000000000
> [95895.766235] ffffaa62c02576b0 ffffffff9020e6ea 0228002000000046
> ffffffff90c7dd98
> [95895.766325] ffffaa62c0257650 ffff96b900000010 ffffaa62c02576c0
> ffffaa62c0257670
> [95895.766417] Call Trace:
> [95895.766502] [<ffffffff904774e3>] dump_stack+0x86/0xc3
> [95895.766596] [<ffffffff9020e6ea>] warn_alloc+0x13a/0x170
> [95895.766681] [<ffffffff9020e9e2>] __alloc_pages_slowpath+0x252/0xbb0
> [95895.766767] [<ffffffff9020f74d>] __alloc_pages_nodemask+0x40d/0x4b0
> [95895.766866] [<ffffffff9026db51>] alloc_pages_current+0xa1/0x1f0
> [95895.766971] [<ffffffff90916f17>] ? _raw_spin_unlock+0x27/0x40
> [95895.767073] [<ffffffff90278956>] new_slab+0x316/0x7c0
> [95895.767160] [<ffffffff9027ae8b>] ___slab_alloc+0x3fb/0x5c0
> [95895.772611] [<ffffffff9010b042>] ? cpuacct_charge+0xf2/0x1f0
> [95895.773406] [<ffffffffc005850d>] ? alloc_indirect.isra.11+0x1d/0x50
> [virtio_ring]
> [95895.774327] [<ffffffff901319d5>] ? rcu_read_lock_sched_held+0x45/0x80
> [95895.775212] [<ffffffffc005850d>] ? alloc_indirect.isra.11+0x1d/0x50
> [virtio_ring]
> [95895.776155] [<ffffffff9027b0a1>] __slab_alloc+0x51/0x90
> [95895.777090] [<ffffffff9027d141>] __kmalloc+0x251/0x320
> [95895.781502] [<ffffffffc005850d>] ? alloc_indirect.isra.11+0x1d/0x50
> [virtio_ring]
> [95895.782309] [<ffffffffc005850d>] alloc_indirect.isra.11+0x1d/0x50
> [virtio_ring]
> [95895.783334] [<ffffffffc0059193>] virtqueue_add_sgs+0x1c3/0x4a0
> [virtio_ring]
> [95895.784059] [<ffffffff90068475>] ? kvm_sched_clock_read+0x25/0x40
> [95895.784742] [<ffffffffc006665c>] __virtblk_add_req+0xbc/0x220
> [virtio_blk]
> [95895.785419] [<ffffffff901312fd>] ? debug_lockdep_rcu_enabled+0x1d/0x20
> [95895.786086] [<ffffffffc0066935>] ? virtio_queue_rq+0x105/0x290
> [virtio_blk]
> [95895.786750] [<ffffffffc006695d>] virtio_queue_rq+0x12d/0x290
> [virtio_blk]
> [95895.787427] [<ffffffff9045015d>] __blk_mq_run_hw_queue+0x26d/0x3b0
> [95895.788106] [<ffffffff904502e2>] blk_mq_run_work_fn+0x12/0x20
> [95895.789065] [<ffffffff900d097e>] process_one_work+0x23e/0x6f0
> [95895.789741] [<ffffffff900d08fa>] ? process_one_work+0x1ba/0x6f0
> [95895.790444] [<ffffffff900d0e7e>] worker_thread+0x4e/0x490
> [95895.791178] [<ffffffff900d0e30>] ? process_one_work+0x6f0/0x6f0
> [95895.791911] [<ffffffff900d0e30>] ? process_one_work+0x6f0/0x6f0
> [95895.792653] [<ffffffff90003eec>] ? do_syscall_64+0x6c/0x1f0
> [95895.793397] [<ffffffff900d82c2>] kthread+0x102/0x120
> [95895.794212] [<ffffffff90111775>] ? trace_hardirqs_on_caller+0xf5/0x1b0
> [95895.794942] [<ffffffff900d81c0>] ? kthread_park+0x60/0x60
> [95895.795689] [<ffffffff90917afa>] ret_from_fork+0x2a/0x40
> [95895.796408] Mem-Info:
> [95895.797110] active_anon:8800 inactive_anon:9030 isolated_anon:32
> active_file:263 inactive_file:238 isolated_file:0
> unevictable:0 dirty:0 writeback:330 unstable:0
> slab_reclaimable:5241 slab_unreclaimable:9538
> mapped:470 shmem:9 pagetables:2200 bounce:0
> free:690 free_pcp:68 free_cma:0
> [95895.801218] Node 0 active_anon:35200kB inactive_anon:36120kB
> active_file:1052kB inactive_file:952kB unevictable:0kB isolated(anon):128kB
> isolated(file):0kB mapped:1880kB dirty:0kB writeback:1320kB shmem:0kB
> shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 36kB writeback_tmp:0kB
> unstable:0kB pages_scanned:179 all_unreclaimable? no
> [95895.803264] Node 0 DMA free:924kB min:172kB low:212kB high:252kB
> active_anon:3544kB inactive_anon:3944kB active_file:84kB inactive_file:140kB
> unevictable:0kB writepending:4kB present:15992kB managed:15908kB mlocked:0kB
> slab_reclaimable:1728kB slab_unreclaimable:2964kB kernel_stack:84kB
> pagetables:1396kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
> [95895.805936] lowmem_reserve[]: 0 117 117 117 117
> [95895.806751] Node 0 DMA32 free:1836kB min:1296kB low:1620kB high:1944kB
> active_anon:31636kB inactive_anon:32164kB active_file:968kB
> inactive_file:804kB unevictable:0kB writepending:1288kB present:180080kB
> managed:139012kB mlocked:0kB slab_reclaimable:19236kB
> slab_unreclaimable:35188kB kernel_stack:1852kB pagetables:7404kB bounce:0kB
> free_pcp:272kB local_pcp:156kB free_cma:0kB
> [95895.809223] lowmem_reserve[]: 0 0 0 0 0
> [95895.810071] Node 0 DMA: 36*4kB (H) 29*8kB (H) 22*16kB (H) 6*32kB (H)
> 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 920kB
> [95895.812089] Node 0 DMA32: 77*4kB (H) 71*8kB (H) 28*16kB (H) 8*32kB (H)
> 4*64kB (H) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 1836kB
> [95895.813979] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0
> hugepages_size=2048kB
> [95895.813981] 1804 total pagecache pages
> [95895.814931] 1289 pages in swap cache
> [95895.815849] Swap cache stats: add 5288014, delete 5286725, find
> 11568655/13881082
> [95895.816792] Free swap = 1791816kB
> [95895.817706] Total swap = 2064380kB
> [95895.819222] 49018 pages RAM
> [95895.820145] 0 pages HighMem/MovableOnly
> [95895.821039] 10288 pages reserved
> [95895.823325] 0 pages cma reserved
> [95895.824244] 0 pages hwpoisoned
> [95895.825237] SLUB: Unable to allocate memory on node -1,
> gfp=0x2080020(GFP_ATOMIC)
> [95895.826140] cache: kmalloc-256, object size: 256, buffer size: 256,
> default order: 0, min order: 0
> [95895.827034] node 0: slabs: 113, objs: 1808, free: 0
> [97883.838418] httpd invoked oom-killer:
> gfp_mask=0x24201ca(GFP_HIGHUSER_MOVABLE|__GFP_COLD), nodemask=0, order=0,
> oom_score_adj=0
> [97883.843507] httpd cpuset=/ mems_allowed=0
> [97883.843601] CPU: 1 PID: 19043 Comm: httpd Not tainted
> 4.9.0-0.rc8.git2.1.fc26.x86_64 #1
> [97883.844628] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
> 1.9.3
> [97883.845839] ffffaa62c395f958 ffffffff904774e3 ffffaa62c395fb20
> ffff96b98b8b3100
> [97883.846970] ffffaa62c395f9e0 ffffffff902a8c41 0000000000000000
> 0000000000000000
> [97883.848388] ffffffff90ec6840 ffffaa62c395f990 ffffffff9011183d
> ffffaa62c395f9b0
> [97883.849945] Call Trace:
> [97883.851366] [<ffffffff904774e3>] dump_stack+0x86/0xc3
> [97883.852535] [<ffffffff902a8c41>] dump_header+0x7b/0x24f
> [97883.853718] [<ffffffff9011183d>] ? trace_hardirqs_on+0xd/0x10
> [97883.854857] [<ffffffff902085d3>] oom_kill_process+0x203/0x3e0
> [97883.856192] [<ffffffff90208afb>] out_of_memory+0x13b/0x580
> [97883.857334] [<ffffffff90208bea>] ? out_of_memory+0x22a/0x580
> [97883.858590] [<ffffffff9020f31a>] __alloc_pages_slowpath+0xb8a/0xbb0
> [97883.859706] [<ffffffff9020f74d>] __alloc_pages_nodemask+0x40d/0x4b0
> [97883.860854] [<ffffffff90037de9>] ? sched_clock+0x9/0x10
> [97883.862120] [<ffffffff9026db51>] alloc_pages_current+0xa1/0x1f0
> [97883.863251] [<ffffffff90201d96>] __page_cache_alloc+0x146/0x190
> [97883.864449] [<ffffffff9020366c>] ? pagecache_get_page+0x2c/0x300
> [97883.865602] [<ffffffff90206055>] filemap_fault+0x345/0x790
> [97883.866661] [<ffffffff90206238>] ? filemap_fault+0x528/0x790
> [97883.867795] [<ffffffff903639d9>] ext4_filemap_fault+0x39/0x50
> [97883.869289] [<ffffffff90241ca3>] __do_fault+0x83/0x1d0
> [97883.870301] [<ffffffff90246642>] handle_mm_fault+0x11e2/0x17a0
> [97883.871304] [<ffffffff902454ba>] ? handle_mm_fault+0x5a/0x17a0
> [97883.872491] [<ffffffff9006de16>] __do_page_fault+0x266/0x520
> [97883.873406] [<ffffffff9006e1a8>] trace_do_page_fault+0x58/0x2a0
> [97883.874262] [<ffffffff90067f3a>] do_async_page_fault+0x1a/0xa0
> [97883.875168] [<ffffffff90918e28>] async_page_fault+0x28/0x30
> [97883.882611] Mem-Info:
> [97883.883747] active_anon:2915 inactive_anon:3376 isolated_anon:0
> active_file:3902 inactive_file:3639 isolated_file:0
> unevictable:0 dirty:205 writeback:0 unstable:0
> slab_reclaimable:9856 slab_unreclaimable:9682
> mapped:3722 shmem:59 pagetables:2080 bounce:0
> free:748 free_pcp:15 free_cma:0
> [97883.890766] Node 0 active_anon:11660kB inactive_anon:13504kB
> active_file:15608kB inactive_file:14556kB unevictable:0kB isolated(anon):0kB
> isolated(file):0kB mapped:14888kB dirty:820kB writeback:0kB shmem:0kB
> shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 236kB writeback_tmp:0kB
> unstable:0kB pages_scanned:168352 all_unreclaimable? yes
> [97883.893210] Node 0 DMA free:1468kB min:172kB low:212kB high:252kB
> active_anon:1716kB inactive_anon:912kB active_file:2292kB
> inactive_file:876kB unevictable:0kB writepending:24kB present:15992kB
> managed:15908kB mlocked:0kB slab_reclaimable:4652kB
> slab_unreclaimable:2852kB kernel_stack:76kB pagetables:496kB bounce:0kB
> free_pcp:0kB local_pcp:0kB free_cma:0kB
> [97883.898799] lowmem_reserve[]: 0 117 117 117 117
> [97883.899735] Node 0 DMA32 free:1524kB min:1296kB low:1620kB high:1944kB
> active_anon:9944kB inactive_anon:12572kB active_file:13316kB
> inactive_file:13680kB unevictable:0kB writepending:768kB present:180080kB
> managed:139012kB mlocked:0kB slab_reclaimable:34772kB
> slab_unreclaimable:35876kB kernel_stack:1828kB pagetables:7824kB bounce:0kB
> free_pcp:60kB local_pcp:52kB free_cma:0kB
> [97883.903033] lowmem_reserve[]: 0 0 0 0 0
> [97883.904371] Node 0 DMA: 36*4kB (H) 29*8kB (H) 22*16kB (H) 9*32kB (H)
> 3*64kB (H) 2*128kB (H) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 1464kB
> [97883.906442] Node 0 DMA32: 13*4kB (H) 4*8kB (H) 13*16kB (H) 8*32kB (H)
> 9*64kB (H) 1*128kB (H) 1*256kB (H) 0*512kB 0*1024kB 0*2048kB 0*4096kB =
> 1508kB
(H) mean highorder atomic reserved which was introduced since v4.4 and some
patches to use up that reserved memory went to linux-next recently via mmotm
tree.
It doesn't land to 4.9 so it might help to test recent linux-next tree.
It should include [1].
[1] 04c8716f7b00, mm: try to exhaust highatomic reserve before the OOM
Thanks.