extensive disk writing may cause out of memory error

[Kent Tong]

Binary package hint: linux-image-2.6.15-52-amd64-server

When writing a lot of files (> 1GB) to a USB hard disk, Linux will use up all the memory and start killing processes, making the computer highly unstable. Below is the kern.log. It had no swap by incident. Enabling swap seems to have fixed the problem. However, even without swap, it shouldn't use all the memory just to do I/O, right?

Dec 2 19:05:05 cladms002 kernel: [12339.336035] lowmem_reserve[]: 0 0 0 0
Dec 2 19:05:05 cladms002 kernel: [12339.336038] Node 0 HighMem free:0kB min:128
kB low:128kB high:128kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_
unreclaimable? no
Dec 2 19:05:05 cladms002 kernel: [12339.336043] lowmem_reserve[]: 0 0 0 0
Dec 2 19:05:05 cladms002 kernel: [12339.336046] Node 0 DMA: 2*4kB 2*8kB 0*16kB
1*32kB 1*64kB 0*128kB 1*256kB 1*512kB 1*1024kB 1*2048kB 1*4096kB = 8056kB
Dec 2 19:05:05 cladms002 kernel: [12339.336055] Node 0 DMA32: 186*4kB 8*8kB 10*
16kB 0*32kB 1*64kB 0*128kB 1*256kB 0*512kB 1*1024kB 0*2048kB 1*4096kB = 6408kB
Dec 2 19:05:05 cladms002 kernel: [12339.336063] Node 0 Normal: empty
Dec 2 19:05:05 cladms002 kernel: [12339.336065] Node 0 HighMem: empty
Dec 2 19:05:05 cladms002 kernel: [12339.336068] Swap cache: add 0, delete 0, fi
nd 0/0, race 0+0
Dec 2 19:05:05 cladms002 kernel: [12339.336070] Free swap = 0kB
Dec 2 19:05:05 cladms002 kernel: [12339.336072] Total swap = 0kB
Dec 2 19:05:05 cladms002 kernel: [12339.336074] Free swap: 0kB
Dec 2 19:05:05 cladms002 kernel: [12339.342497] oom-killer: gfp_mask=0x201d2, o
rder=0
Dec 2 19:05:05 cladms002 kernel: [12339.342501] Mem-info:
Dec 2 19:05:05 cladms002 kernel: [12339.342503] Node 0 DMA per-cpu:
Dec 2 19:05:05 cladms002 kernel: [12339.342506] cpu 0 hot: low 0, high 0, batch 1 used:0
Dec 2 19:05:05 cladms002 kernel: [12339.342509] cpu 0 cold: low 0, high 0, batc
h 1 used:0
Dec 2 19:05:05 cladms002 kernel: [12339.342511] cpu 1 hot: low 0, high 0, batch
 1 used:0
Dec 2 19:05:05 cladms002 kernel: [12339.342514] cpu 1 cold: low 0, high 0, batc
h 1 used:0
Dec 2 19:05:05 cladms002 kernel: [12339.342516] Node 0 DMA32 per-cpu:
Dec 2 19:05:05 cladms002 kernel: [12339.342519] cpu 0 hot: low 0, high 186, bat
ch 31 used:147
Dec 2 19:05:05 cladms002 kernel: [12339.342522] cpu 0 cold: low 0, high 62, bat
ch 15 used:13
Dec 2 19:05:05 cladms002 kernel: [12339.342525] cpu 1 hot: low 0, high 186, bat
ch 31 used:24
Dec 2 19:05:05 cladms002 kernel: [12339.342527] cpu 1 cold: low 0, high 62, bat
ch 15 used:7
Dec 2 19:05:05 cladms002 kernel: [12339.342529] Node 0 Normal per-cpu: empty
Dec 2 19:05:05 cladms002 kernel: [12339.342532] Node 0 HighMem per-cpu: empty
Dec 2 19:05:05 cladms002 kernel: [12339.342535] Free pages: 14524kB (0kB
HighMem)
Dec 2 19:05:05 cladms002 kernel: [12339.342540] Active:20582 inactive:448112 di
rty:165685 writeback:281 unstable:0 free:3631 slab:13547 mapped:20328 pagetables
:1313
Dec 2 19:05:05 cladms002 kernel: [12339.342552] Node 0 DMA free:8056kB min:32kB
 low:40kB high:48kB active:56kB inactive:3960kB present:11996kB pages_scanned:10
...
Dec 2 19:05:05 cladms002 kernel: [12339.342583] lowmem_reserve[]: 0 0 0 0
Dec 2 19:05:05 cladms002 kernel: [12339.342585] Node 0 DMA: 2*4kB 2*8kB 0*16kB
1*32kB 1*64kB 0*128kB 1*256kB 1*512kB 1*1024kB 1*2048kB 1*4096kB = 8056kB
Dec 2 19:05:05 cladms002 kernel: [12339.342594] Node 0 DMA32: 201*4kB 8*8kB 10*
16kB 0*32kB 1*64kB 0*128kB 1*256kB 0*512kB 1*1024kB 0*2048kB 1*4096kB = 6468kB
Dec 2 19:05:05 cladms002 kernel: [12339.342603] Node 0 Normal: empty
Dec 2 19:05:05 cladms002 kernel: [12339.342605] Node 0 HighMem: empty
Dec 2 19:05:05 cladms002 kernel: [12339.342608] Swap cache: add 0, delete 0, find 0/0, race 0+0
Dec 2 19:05:05 cladms002 kernel: [12339.342610] Free swap = 0kB
Dec 2 19:05:05 cladms002 kernel: [12339.342612] Total swap = 0kB
Dec 2 19:05:05 cladms002 kernel: [12339.342614] Free swap: 0kB
Dec 2 19:05:05 cladms002 kernel: [12339.351610] 524280 pages of RAM
Dec 2 19:05:05 cladms002 kernel: [12339.351613] 9047 reserved pages
Dec 2 19:05:05 cladms002 kernel: [12339.351615] 448720 pages shared
Dec 2 19:05:05 cladms002 kernel: [12339.351617] 0 pages swap cached
Dec 2 19:05:05 cladms002 kernel: [12339.351684] Out of Memory: Killed process 4028 (vmware-vmx).
Dec 2 19:05:05 cladms002 kernel: [12339.357467] 524280 pages of RAM
Dec 2 19:05:05 cladms002 kernel: [12339.357470] 9047 reserved pages
Dec 2 19:05:05 cladms002 kernel: [12339.357472] 448718 pages shared
Dec 2 19:05:05 cladms002 kernel: [12339.357473] 0 pages swap cached
Dec 2 19:05:05 cladms002 kernel: [12339.357534] Out of Memory: Killed process 4028 (vmware-vmx).

[Jon Charge (seropith)]

Could you please include some regarding your hardware. Your total configured physical RAM, SWAP, and HD Space. Also the kernal please. And the size of the USB disk and type of disk. Thanks, Jon

[Kent Tong (kent-tong)]

It's an HP Proliant DL385 AMD Opteron™ model 265 1.8GHz - 1MB L2 dual-core (see http://h18004.www1.hp.com/products/servers/proliantdl385/specifications.html). 2G RAM. No swap originally but now has 2.5G swap (since then the problem no longer occurs).

The disk space is ("df -m"):

Filesystem 1M-blocks Used Available Use% Mounted on
/dev/mapper/Ubuntu-root
                         25199 20409 3510 86% /
varrun 1007 1 1007 1% /var/run
varlock 1007 1 1007 1% /var/lock
udev 1007 1 1007 1% /dev
devshm 1007 0 1007 0% /dev/shm
/dev/mapper/Ubuntu-data
                        107849 102825 5025 96% /var/data
/dev/cciss/c0d0p5 228 34 183 16% /boot
/dev/sda1 300453 21823 263369 8% /mnt/ext-disk1
/dev/sdb 112676 31410 81267 28% /mnt/usbdisk

"uname -r" returns 2.6.15-52-amd64-server.

The USB disk (/dev/sda) has about 280G. It's a Buffalo DriveStation Combo HD-CEIU2 (http://www.buffalotech.com/products/external-drives/drivestation/drivestation-combo-hd-ceiu2). However, I don't think it's related to the brand of the USB disk as it happened with our Maxtor OneTouch USB disks too in the past.

[Jon Charge (seropith)]

Have resource limits (ulimits) been altered from the default install?

[Kent Tong (kent-tong)]

No. We're using the default. Running ulimit says "unlimited".

[Jon Charge (seropith)]

I was not able to reproduce. It may still be reproducible however, I could not mirror your system configuration exactly.

[Kent Tong (kent-tong)]

Setting vm.swappiness to 1 seems to have fixed the problem.

[kede (kede)]

I experienced a similar problem with Ubuntu (Desktop) 9.04 and 9.10 (beta) a few times.
The system has 4GB physical memory and 3,9GB swap-space.

1.) I copied some large files (maybe 20GB each) by gigabit network. After some time, the transfer rate went to near zero, hdd-led stays on with a slight flickering. I klicked to open a konsole window but it did not open. I switched to tty2, typed root, hit enter. It showed a blinking cursor but no password promt appeared. I ssh'd from another computer with same result.
After about 30 minutes, system went back normal.

2.) While watching a video with vlc, i copied a large file from one parition to another (same physical disk). After a few minutes, system becomes unresponsive, stuttering sound, cursor sticks. After some minutes, vlc is terminated. Ten minutes later system becomes normal. I was able to see the memory usage with top. 100% used, both pysical and swap. Apart from vlc and the file copy, there were no other activities.

Here is what the logfiles show:
[12725.291450] padevchooser invoked oom-killer: gfp_mask=0x201da, order=0, oomkilladj=0
[12725.291454] padevchooser cpuset=/ mems_allowed=0
[12725.291457] Pid: 3146, comm: padevchooser Tainted: P W 2.6.31-14-generic #48-Ubuntu
[12725.291459] Call Trace:
[12725.291466] [<ffffffff810a2798>] ? cpuset_print_task_mems_allowed+0x98/0xa0
[12725.291471] [<ffffffff810dd7ce>] oom_kill_process+0xce/0x290
[12725.291474] [<ffffffff810ddd3a>] ? select_bad_process+0xea/0x120
[12725.291476] [<ffffffff810dddc0>] __out_of_memory+0x50/0xb0
[12725.291479] [<ffffffff810ddf46>] out_of_memory+0x126/0x1a0
[12725.291483] [<ffffffff815293a9>] ? _spin_lock+0x9/0x10
[12725.291486] [<ffffffff810e0808>] __alloc_pages_slowpath+0x498/0x4e0
[12725.291489] [<ffffffff810e099e>] __alloc_pages_nodemask+0x14e/0x150
[12725.291493] [<ffffffff8110cea2>] alloc_pages_current+0x82/0xd0
[12725.291496] [<ffffffff810da92f>] __page_cache_alloc+0x5f/0x70
[12725.291498] [<ffffffff810da710>] ? sync_page+0x0/0x50
[12725.291502] [<ffffffff810e4601>] __do_page_cache_readahead+0xc1/0x160
[12725.291505] [<ffffffff810e46bc>] ra_submit+0x1c/0x20
[12725.291507] [<ffffffff810da42b>] do_sync_mmap_readahead+0x9b/0xd0
[12725.291510] [<ffffffff810dc594>] filemap_fault+0x314/0x3c0
[12725.291513] [<ffffffff810f423f>] __do_fault+0x4f/0x4e0
[12725.291516] [<ffffffff810f89d7>] handle_mm_fault+0x1a7/0x3c0
[12725.291520] [<ffffffff81036419>] ? default_spin_lock_flags+0x9/0x10
[12725.291523] [<ffffffff8152bf4a>] do_page_fault+0x16a/0x370
[12725.291526] [<ffffffff815298c5>] page_fault+0x25/0x30
[12725.291528] Mem-Info:
[12725.291530] Node 0 DMA per-cpu:
[12725.291532] CPU 0: hi: 0, btch: 1 usd: 0
[12725.291534] CPU 1: hi: 0, btch: 1 usd: 0
[12725.291536] Node 0 DMA32 per-cpu:
[12725.291538] CPU 0: hi: 186, btch: 31 usd: 146
[12725.291540] CPU 1: hi: 186, btch: 31 usd: 175
[12725.291541] Node 0 Normal per-cpu:
[12725.291544] CPU 0: hi: 186, btch: 31 usd: 83
[12725.291546] CPU 1: hi: 186, btch: 31 usd: 160
[12725.291549] Active_anon:765930 active_file:160 inactive_anon:190722
[12725.291550] inactive_file:281 unevictable:4 dirty:0 writeback:927 unst...

[Kent Tong (kent-tong)]

A patch is referenced by http://bugs.centos.org/view.php?id=1391

[Przemek K. (azrael)]

Also see Bug #330806

[Sergio Zanchetta (primes2h)]

Thank you for reporting this bug to Ubuntu. Dapper reached EOL, please see this document for currently supported Ubuntu releases:
https://wiki.ubuntu.com/Releases

Please upgrade and test, I'll leave the linux task open for that.

Feel free to report any other bugs you may find.