Hi, I received some reports of mkfs.ext4 on an SD card triggering the OOM killer on a swapless system with a low amount of free memory. I have made a reproducible setup of this by using null_blk with a large completion delay. The problem appears to be that we do not throttle to the level of vm_dirty_ratio in throttle_vm_writeout(). I configure null_blk like this: null_blk.irqmode=2 null_blk.completion_nsec=30000000 null_blk.queue_mode=1 and run the test under a qemu-kvm instance. The kernel is 4.2-rc5 along with the patch I posted earlier today which fixes the initial dirty limit after the cgroups changes (https://lkml.org/lkml/2015/8/5/650). The problem is not related to the recent writeback cgroups changes though; earlier kernels show the same behaviour. /proc/meminfo looks like this just before run of mkfs.ext4 MemTotal: 197032 kB MemFree: 4184 kB MemAvailable: 14376 kB Buffers: 332 kB Cached: 64528 kB SwapCached: 0 kB Active: 2840 kB Inactive: 62612 kB Active(anon): 640 kB Inactive(anon): 61448 kB Active(file): 2200 kB Inactive(file): 1164 kB Unevictable: 0 kB Mlocked: 0 kB SwapTotal: 0 kB SwapFree: 0 kB Dirty: 28 kB Writeback: 0 kB AnonPages: 660 kB Mapped: 2776 kB Shmem: 61456 kB Slab: 26580 kB SReclaimable: 12884 kB SUnreclaim: 13696 kB KernelStack: 576 kB PageTables: 220 kB NFS_Unstable: 0 kB Bounce: 0 kB WritebackTmp: 0 kB CommitLimit: 98516 kB Committed_AS: 63424 kB VmallocTotal: 34359738367 kB VmallocUsed: 68532 kB VmallocChunk: 34359667708 kB DirectMap4k: 16256 kB DirectMap2M: 208896 kB DirectMap1G: 0 kB And mkfs.ext4 runs like this: # mkfs.ext4 -F -O ^extent -E lazy_itable_init=0,lazy_journal_init=0 /dev/nullb0: mke2fs 1.42.13 (17-May-2015) Creating filesystem with 65536000 4k blocks and 16384000 inodes Filesystem UUID: 970d9572-67d4-4a1f-a4d0-8376c6235c6a Superblock backups stored on blocks: 32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 2654208, 4096000, 7962624, 11239424, 20480000, 23887872 Allocating group tables: done Writing inode tables: [ 4.557641] mkfs.ext4 invoked oom-killer: gfp_mask=0x10200d0, order=0, oom_score_adj=0 [ 4.558395] mkfs.ext4 cpuset=/ mems_allowed=0 [ 4.558814] CPU: 0 PID: 667 Comm: mkfs.ext4 Not tainted 4.2.0-rc5+ #292 [ 4.559391] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014 [ 4.562285] Call Trace: [ 4.562509] [<ffffffff81515c64>] dump_stack+0x4f/0x7b [ 4.562957] [<ffffffff81513eb8>] dump_header.isra.9+0x76/0x38f [ 4.563474] [<ffffffff8109d95d>] ? trace_hardirqs_on+0xd/0x10 [ 4.564023] [<ffffffff8151ca2a>] ? _raw_spin_unlock_irqrestore+0x4a/0x80 [ 4.564614] [<ffffffff81123cac>] oom_kill_process+0x38c/0x470 [ 4.565190] [<ffffffff81057cb5>] ? has_ns_capability_noaudit+0x5/0x160 [ 4.573104] [<ffffffff8107bc51>] ? get_parent_ip+0x11/0x50 [ 4.573608] [<ffffffff81124145>] ? out_of_memory+0x355/0x420 [ 4.574143] [<ffffffff811241a7>] out_of_memory+0x3b7/0x420 [ 4.574634] [<ffffffff81128dc0>] ? __alloc_pages_nodemask+0x810/0xb10 [ 4.575203] [<ffffffff81128fc6>] __alloc_pages_nodemask+0xa16/0xb10 [ 4.575755] [<ffffffff8111fd91>] pagecache_get_page+0x101/0x1c0 [ 4.576287] [<ffffffff811a2cf0>] ? I_BDEV+0x20/0x20 [ 4.576722] [<ffffffff8112092d>] grab_cache_page_write_begin+0x2d/0x50 [ 4.577298] [<ffffffff811a114d>] block_write_begin+0x2d/0x80 [ 4.577809] [<ffffffff811a34f5>] ? blkdev_write_begin+0x5/0x30 [ 4.578325] [<ffffffff811a3513>] blkdev_write_begin+0x23/0x30 [ 4.578830] [<ffffffff81120abf>] generic_perform_write+0xaf/0x1b0 [ 4.579368] [<ffffffff81121c60>] __generic_file_write_iter+0x190/0x1f0 [ 4.579975] [<ffffffff811a3b28>] blkdev_write_iter+0x78/0x100 [ 4.580497] [<ffffffff81167daa>] __vfs_write+0xaa/0xe0 [ 4.580984] [<ffffffff811681a7>] vfs_write+0x97/0x100 [ 4.581434] [<ffffffff811689a7>] SyS_pwrite64+0x77/0x90 [ 4.581923] [<ffffffff8151d3ae>] entry_SYSCALL_64_fastpath+0x12/0x76 [ 4.585984] Mem-Info: [ 4.586558] active_anon:207 inactive_anon:15363 isolated_anon:0 [ 4.586558] active_file:295 inactive_file:347 isolated_file:0 [ 4.586558] unevictable:0 dirty:0 writeback:0 unstable:0 [ 4.586558] slab_reclaimable:3260 slab_unreclaimable:3452 [ 4.586558] mapped:288 shmem:15363 pagetables:56 bounce:0 [ 4.586558] free:1112 free_pcp:32 free_cma:0 [ 4.589928] DMA free:1032kB min:144kB low:180kB high:216kB active_anon:52kB inactive_anon:5920kB active_file:48kB inactive_file:128kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB managed:15908kB mlocked:0kB dirty:4kB writeback:0kB mapped:88kB shmem:5920kB slab_reclaimable:164kB slab_unreclaimable:648kB kernel_stack:16kB pagetables:28kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no [ 4.594056] lowmem_reserve[]: 0 173 173 173 [ 4.596036] DMA32 free:3136kB min:1608kB low:2008kB high:2412kB active_anon:776kB inactive_anon:55532kB active_file:1132kB inactive_file:1380kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:208768kB managed:181124kB mlocked:0kB dirty:0kB writeback:0kB mapped:1176kB shmem:55532kB slab_reclaimable:12876kB slab_unreclaimable:13160kB kernel_stack:592kB pagetables:196kB unstable:0kB bounce:0kB free_pcp:140kB local_pcp:140kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no [ 4.600369] lowmem_reserve[]: 0 0 0 0 [ 4.601393] DMA: 14*4kB (UM) 20*8kB (UM) 20*16kB (UM) 13*32kB (UM) 1*64kB (M) 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 1016kB [ 4.602710] DMA32: 44*4kB (UEM) 128*8kB (UEM) 44*16kB (UEM) 24*32kB (UEM) 3*64kB (M) 2*128kB (M) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 3120kB [ 4.604158] 16088 total pagecache pages [ 4.604509] 56190 pages RAM [ 4.604768] 0 pages HighMem/MovableOnly [ 4.605148] 6932 pages reserved [ 4.605437] [ pid ] uid tgid total_vm rss nr_ptes nr_pmds swapents oom_score_adj name [ 4.606238] [ 75] 0 75 1134 16 8 3 0 0 klogd [ 4.607012] [ 140] 0 140 2667 140 10 3 0 0 dropbear [ 4.607809] [ 141] 0 141 1660 176 8 3 0 0 sh [ 4.608737] [ 661] 0 661 1134 167 8 3 0 0 exe [ 4.611211] [ 667] 0 667 4271 321 14 3 0 0 mkfs.ext4 [ 4.612198] Out of memory: Kill process 667 (mkfs.ext4) score 6 or sacrifice child [ 4.614630] Killed process 667 (mkfs.ext4) total-vm:17084kB, anon-rss:184kB, file-rss:1100kB Killed The last balance_dirty_pages shows that the task is within its ratelimit and so is not paused there: mkfs.ext4-664 [000] 4.773565: balance_dirty_pages: bdi 253:0: limit=9233 setpoint=4685 dirty=576 bdi_setpoint=4532 bdi_dirty=576 dirty_ratelimit=102400 task_ratelimit=181400 dirtied=58 dirtied_pause=512 paused=0 pause=-32 period=0 think=32 Then the page allocator gets called and starts direct reclaim: mkfs.ext4-664 [000] 4.773565: function: blkdev_write_begin <-- generic_perform_write mkfs.ext4-664 [000] 4.773566: function: __alloc_pages_nodemask <-- pagecache_get_page mkfs.ext4-664 [000] 4.773566: function: __alloc_pages_direct_compact <-- __alloc_pages_nodemask mkfs.ext4-664 [000] 4.773566: function: try_to_free_pages <-- __alloc_pages_nodemask mkfs.ext4-664 [000] 4.773567: mm_vmscan_direct_reclaim_begin: order=0 may_writepage=1 gfp_flags=GFP_USER However, even though NR_WRITEBACK is much larger than thresh, confgestion_wait() is not called because throttle_vm_writeout() uses the much higher domain->dirty_limit (limit) rather that vm_dirty_ratio (thresh): mkfs.ext4-664 [000] 4.773567: function: throttle_vm_writeout <-- shrink_lruvec.isra.59 mkfs.ext4-664 [000] 4.773567: global_dirty_state: dirty=3 writeback=573 unstable=0 bg_thresh=91 thresh=183 limit=9233 dirtied=3465 written=2889 None of the wait_iff_congested() calls have any effect since the bdi is not detected as being congested (queue/nr_request is the default of 128 and fewer than 30 requests are currently on it): mkfs.ext4-664 [000] 4.773583: function: wait_iff_congested <-- shrink_inactive_list mkfs.ext4-664 [000] 4.773583: writeback_wait_iff_congested: usec_timeout=100000 usec_delayed=0 try_to_free_pages() also keeps on waking up the flusher threads: mkfs.ext4-664 [000] 4.776026: kmalloc: (wb_start_writeback+0x42) call_site=ffffffff811970d2 ptr=0xffff88000d748498 bytes_req=64 bytes_alloc=392 gfp_flags=GFP_ATOMIC|GFP_ZERO mkfs.ext4-664 [000] 4.776026: writeback_queue: bdi 254:0: sb_dev 0:0 nr_pages=1105 sync_mode=0 kupdate=0 range_cyclic=0 background=0 reason=try_to_free_pages mkfs.ext4-664 [000] 4.776032: kmalloc: (wb_start_writeback+0x42) call_site=ffffffff811970d2 ptr=0xffff88000d749188 bytes_req=64 bytes_alloc=392 gfp_flags=GFP_ATOMIC|GFP_ZERO mkfs.ext4-664 [000] 4.776033: writeback_queue: bdi 253:0: sb_dev 0:0 nr_pages=1105 sync_mode=0 kupdate=0 range_cyclic=0 background=0 reason=try_to_free_pages mkfs.ext4-664 [000] 4.776040: kmalloc: (wb_start_writeback+0x42) call_site=ffffffff811970d2 ptr=0xffff88000d749620 bytes_req=64 bytes_alloc=392 gfp_flags=GFP_ATOMIC|GFP_ZERO mkfs.ext4-664 [000] 4.776040: writeback_queue: bdi 254:0: sb_dev 0:0 nr_pages=1105 sync_mode=0 kupdate=0 range_cyclic=0 background=0 reason=try_to_free_pages mkfs.ext4-664 [000] 4.776047: kmalloc: (wb_start_writeback+0x42) call_site=ffffffff811970d2 ptr=0xffff88000d74a498 bytes_req=64 bytes_alloc=392 gfp_flags=GFP_ATOMIC|GFP_ZERO mkfs.ext4-664 [000] 4.776047: writeback_queue: bdi 253:0: sb_dev 0:0 nr_pages=1105 sync_mode=0 kupdate=0 range_cyclic=0 background=0 reason=try_to_free_pages mkfs.ext4-664 [000] 4.776054: kmalloc: (wb_start_writeback+0x42) call_site=ffffffff811970d2 ptr=0xffff88000d74a620 bytes_req=64 bytes_alloc=392 gfp_flags=GFP_ATOMIC|GFP_ZERO mkfs.ext4-664 [000] 4.776054: writeback_queue: bdi 254:0: sb_dev 0:0 nr_pages=1105 sync_mode=0 kupdate=0 range_cyclic=0 background=0 reason=try_to_free_pages mkfs.ext4-664 [000] 4.776061: kmalloc: (wb_start_writeback+0x42) call_site=ffffffff811970d2 ptr=0xffff88000d74b310 bytes_req=64 bytes_alloc=392 gfp_flags=GFP_ATOMIC|GFP_ZERO mkfs.ext4-664 [000] 4.776061: writeback_queue: bdi 253:0: sb_dev 0:0 nr_pages=1105 sync_mode=0 kupdate=0 range_cyclic=0 background=0 reason=try_to_free_pages mkfs.ext4-664 [000] 4.776068: kmalloc: (wb_start_writeback+0x42) call_site=ffffffff811970d2 ptr=0xffff88000d74b620 bytes_req=64 bytes_alloc=392 gfp_flags=GFP_ATOMIC|GFP_ZERO All to no avail since we never wait for any writes and end up OOMing after some rounds of direct reclaim: mkfs.ext4-664 [000] 4.776174: mm_vmscan_direct_reclaim_end: nr_reclaimed=0 mkfs.ext4-664 [000] 4.776192: function: out_of_memory <-- __alloc_pages_nodemask (A full ftrace is available at https://drive.google.com/file/d/0B4tMLbMvJ-l6MndXbG5wQmZrTm8/view) The problem seems to be that throttle_vm_writeout() does not respect the set vm_dirty_ratio values. With the following change, mkfs.ext4 is able to complete successfully every time in this scenario without triggering OOM: diff --git a/mm/page-writeback.c b/mm/page-writeback.c index 5cccc12..47f1d09 100644 --- a/mm/page-writeback.c +++ b/mm/page-writeback.c @@ -1916,7 +1920,6 @@ void throttle_vm_writeout(gfp_t gfp_mask) for ( ; ; ) { global_dirty_limits(&background_thresh, &dirty_thresh); - dirty_thresh = hard_dirty_limit(&global_wb_domain, dirty_thresh); /* * Boost the allowable dirty threshold a bit for page But this is a revert of the following commit and presumably reintroduces the problem for the use case described there: commit 47a133339c332f9f8e155c70f5da401aded69948 Author: Fengguang Wu <fengguang.wu@xxxxxxxxx> Date: Wed Mar 21 16:34:09 2012 -0700 mm: use global_dirty_limit in throttle_vm_writeout() When starting a memory hog task, a desktop box w/o swap is found to go unresponsive for a long time. It's solely caused by lots of congestion waits in throttle_vm_writeout(): ... The root cause is, the dirty threshold is knocked down a lot by the memory hog task. Fixed by using global_dirty_limit which decreases gradually on such events and can guarantee we stay above (the also decreasing) nr_dirty in the progress of following down to the new dirty threshold. Comments? Thanks, /Rabin -- To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to majordomo@xxxxxxxxx. For more info on Linux MM, see: http://www.linux-mm.org/ . Don't email: <a href=mailto:"dont@xxxxxxxxx";> email@xxxxxxxxx </a>