From mboxrd@z Thu Jan 1 00:00:00 1970 From: Bruno =?UTF-8?B?UHLDqW1vbnQ=?= Subject: Re: 2.6.39-rc4+: Kernel leaking memory during FS scanning, regression? Date: Mon, 25 Apr 2011 12:34:44 +0200 Message-ID: <20110425123444.639aad34@neptune.home> References: <20110424202158.45578f31@neptune.home> <20110424235928.71af51e0@neptune.home> <20110425114429.266A.A69D9226@jp.fujitsu.com> <20110425111705.786ef0c5@neptune.home> Mime-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: QUOTED-PRINTABLE Cc: Mike Frysinger , KOSAKI Motohiro , linux-kernel@vger.kernel.org, linux-mm@kvack.org, linux-fsdevel@vger.kernel.org, Catalin Marinas To: Pekka Enberg Return-path: In-Reply-To: Sender: linux-kernel-owner@vger.kernel.org List-Id: linux-fsdevel.vger.kernel.org On Mon, 25 April 2011 Pekka Enberg wrote: > On Mon, Apr 25, 2011 at 12:17 PM, Bruno Pr=C3=A9mont > wrote: > > On Mon, 25 April 2011 Mike Frysinger wrote: > >> On Sun, Apr 24, 2011 at 22:42, KOSAKI Motohiro wrote: > >> >> On Sun, 24 April 2011 Bruno Pr=C3=A9mont wrote: > >> >> > On an older system I've been running Gentoo's revdep-rebuild = to check > >> >> > for system linking/*.la consistency and after doing most of t= he work the > >> >> > system starved more or less, just complaining about stuck tas= ks now and > >> >> > then. > >> >> > Memory usage graph as seen from userspace showed sudden quick= increase of > >> >> > memory usage though only a very few MB were swapped out (c.f.= attached RRD > >> >> > graph). > >> >> > >> >> Seems I've hit it once again (though detected before system was= fully > >> >> stalled by trying to reclaim memory without success). > >> >> > >> >> This time it was during simple compiling... > >> >> Gathered info below: > >> >> > >> >> /proc/meminfo: > >> >> MemTotal: =C2=A0 =C2=A0 =C2=A0 =C2=A0 480660 kB > >> >> MemFree: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 64948 kB > >> >> Buffers: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 10304 kB > >> >> Cached: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 6924 kB > >> >> SwapCached: =C2=A0 =C2=A0 =C2=A0 =C2=A0 4220 kB > >> >> Active: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A011100 kB > >> >> Inactive: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A015732 kB > >> >> Active(anon): =C2=A0 =C2=A0 =C2=A0 4732 kB > >> >> Inactive(anon): =C2=A0 =C2=A0 4876 kB > >> >> Active(file): =C2=A0 =C2=A0 =C2=A0 6368 kB > >> >> Inactive(file): =C2=A0 =C2=A010856 kB > >> >> Unevictable: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A032 kB > >> >> Mlocked: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A032 kB > >> >> SwapTotal: =C2=A0 =C2=A0 =C2=A0 =C2=A0524284 kB > >> >> SwapFree: =C2=A0 =C2=A0 =C2=A0 =C2=A0 456432 kB > >> >> Dirty: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A08= 0 kB > >> >> Writeback: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 0 kB > >> >> AnonPages: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A06268 kB > >> >> Mapped: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 2604 kB > >> >> Shmem: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = 4 kB > >> >> Slab: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 250632 kB > >> >> SReclaimable: =C2=A0 =C2=A0 =C2=A051144 kB > >> >> SUnreclaim: =C2=A0 =C2=A0 =C2=A0 199488 kB =C2=A0 <--- look big= as well... > >> >> KernelStack: =C2=A0 =C2=A0 =C2=A0131032 kB =C2=A0 <--- what??? > >> > > >> > KernelStack is used 8K bytes per thread. then, your system shoul= d have > >> > 16000 threads. but your ps only showed about 80 processes. > >> > Hmm... stack leak? > >> > >> i might have a similar report for 2.6.39-rc4 (seems to be working = fine > >> in 2.6.38.4), but for embedded Blackfin systems running gdbserver > >> processes over and over (so lots of short lived forks) > >> > >> i wonder if you have a lot of zombies or otherwise unclaimed resou= rces > >> ? =C2=A0does `ps aux` show anything unusual ? > > > > I've not seen anything special (no big amount of threads behind my = about 80 > > processes, even after kernel oom-killed nearly all processes the ho= gged > > memory has not been freed. And no, there are no zombies around). > > > > Here it seems to happened when I run 2 intensive tasks in parallel,= e.g. > > (re)emerging gimp and running revdep-rebuild -pi in another termina= l. > > This produces a fork rate of about 100-300 per second. > > > > Suddenly kmalloc-128 slabs stop being freed and things degrade. > > > > Trying to trace some of the kmalloc-128 slab allocations I end up s= eeing > > lots of allocations like this: > > > > [ 1338.554429] TRACE kmalloc-128 alloc 0xc294ff00 inuse=3D30 fp=3D0= xc294ff00 > > [ 1338.554434] Pid: 1573, comm: collectd Tainted: G =C2=A0 =C2=A0 =C2= =A0 =C2=A0W =C2=A0 2.6.39-rc4-jupiter-00187-g686c4cb #1 > > [ 1338.554437] Call Trace: > > [ 1338.554442] =C2=A0[] trace+0x57/0xa0 > > [ 1338.554447] =C2=A0[] alloc_debug_processing+0xf3/0x140 > > [ 1338.554452] =C2=A0[] T.999+0x172/0x1a0 > > [ 1338.554455] =C2=A0[] ? get_empty_filp+0x58/0xc0 > > [ 1338.554459] =C2=A0[] ? get_empty_filp+0x58/0xc0 > > [ 1338.554464] =C2=A0[] kmem_cache_alloc+0xb2/0x100 > > [ 1338.554468] =C2=A0[] ? path_put+0x15/0x20 > > [ 1338.554472] =C2=A0[] ? get_empty_filp+0x58/0xc0 > > [ 1338.554476] =C2=A0[] get_empty_filp+0x58/0xc0 > > [ 1338.554481] =C2=A0[] path_openat+0x1f/0x320 > > [ 1338.554485] =C2=A0[] ? __access_remote_vm+0x19e/0x1d0 > > [ 1338.554490] =C2=A0[] do_filp_open+0x30/0x80 > > [ 1338.554495] =C2=A0[] ? kmem_cache_alloc+0x90/0x100 > > [ 1338.554500] =C2=A0[] ? getname_flags+0x28/0xe0 > > [ 1338.554505] =C2=A0[] ? alloc_fd+0x62/0xe0 > > [ 1338.554509] =C2=A0[] ? getname_flags+0x61/0xe0 > > [ 1338.554514] =C2=A0[] do_sys_open+0xed/0x1e0 > > [ 1338.554519] =C2=A0[] sys_open+0x29/0x40 > > [ 1338.554524] =C2=A0[] sysenter_do_call+0x12/0x26 > > [ 1338.556764] TRACE kmalloc-128 alloc 0xc294ff80 inuse=3D31 fp=3D0= xc294ff80 > > [ 1338.556774] Pid: 1332, comm: bash Tainted: G =C2=A0 =C2=A0 =C2=A0= =C2=A0W =C2=A0 2.6.39-rc4-jupiter-00187-g686c4cb #1 > > [ 1338.556779] Call Trace: > > [ 1338.556794] =C2=A0[] trace+0x57/0xa0 > > [ 1338.556802] =C2=A0[] alloc_debug_processing+0xf3/0x140 > > [ 1338.556807] =C2=A0[] T.999+0x172/0x1a0 > > [ 1338.556812] =C2=A0[] ? get_empty_filp+0x58/0xc0 > > [ 1338.556817] =C2=A0[] ? get_empty_filp+0x58/0xc0 > > [ 1338.556821] =C2=A0[] kmem_cache_alloc+0xb2/0x100 > > [ 1338.556826] =C2=A0[] ? get_empty_filp+0x58/0xc0 > > [ 1338.556830] =C2=A0[] get_empty_filp+0x58/0xc0 > > [ 1338.556841] =C2=A0[] ? tty_ldisc_deref+0x8/0x10 > > [ 1338.556849] =C2=A0[] path_openat+0x1f/0x320 > > [ 1338.556857] =C2=A0[] ? fbcon_cursor+0xfe/0x180 > > [ 1338.556863] =C2=A0[] do_filp_open+0x30/0x80 > > [ 1338.556868] =C2=A0[] ? kmem_cache_alloc+0x90/0x100 > > [ 1338.556873] =C2=A0[] ? do_vfs_ioctl+0x7e/0x580 > > [ 1338.556878] =C2=A0[] ? getname_flags+0x28/0xe0 > > [ 1338.556886] =C2=A0[] ? alloc_fd+0x62/0xe0 > > [ 1338.556891] =C2=A0[] ? getname_flags+0x61/0xe0 > > [ 1338.556898] =C2=A0[] do_sys_open+0xed/0x1e0 > > [ 1338.556903] =C2=A0[] sys_open+0x29/0x40 > > [ 1338.556913] =C2=A0[] sysenter_do_call+0x12/0x26 > > > > Collectd is system monitoring daemon that counts processes, memory > > usage an much more, reading lots of files under /proc every 10 > > seconds. > > Maybe it opens a process related file at a racy moment and thus > > prevents the 128 slabs and kernel stacks from being released? > > > > Replaying the scenario I'm at: > > Slab: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A043112 kB > > SReclaimable: =C2=A0 =C2=A0 =C2=A025396 kB > > SUnreclaim: =C2=A0 =C2=A0 =C2=A0 =C2=A017716 kB > > KernelStack: =C2=A0 =C2=A0 =C2=A0 16432 kB > > PageTables: =C2=A0 =C2=A0 =C2=A0 =C2=A0 1320 kB > > > > with > > kmalloc-256 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 55 =C2=A0 =C2=A0 64 = =C2=A0 =C2=A0256 =C2=A0 16 =C2=A0 =C2=A01 : tunables =C2=A0 =C2=A00 =C2= =A0 =C2=A00 =C2=A0 =C2=A00 : slabdata =C2=A0 =C2=A0 =C2=A04 =C2=A0 =C2=A0= =C2=A04 =C2=A0 =C2=A0 =C2=A00 > > kmalloc-128 =C2=A0 =C2=A0 =C2=A0 =C2=A066656 =C2=A066656 =C2=A0 =C2= =A0128 =C2=A0 32 =C2=A0 =C2=A01 : tunables =C2=A0 =C2=A00 =C2=A0 =C2=A0= 0 =C2=A0 =C2=A00 : slabdata =C2=A0 2083 =C2=A0 2083 =C2=A0 =C2=A0 =C2=A0= 0 > > kmalloc-64 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A03902 =C2=A0 3904 =C2=A0= =C2=A0 64 =C2=A0 64 =C2=A0 =C2=A01 : tunables =C2=A0 =C2=A00 =C2=A0 =C2= =A00 =C2=A0 =C2=A00 : slabdata =C2=A0 =C2=A0 61 =C2=A0 =C2=A0 61 =C2=A0= =C2=A0 =C2=A00 > > > > (and compiling process tree now SIGSTOPped in order to have system > > not starve immediately so I can look around for information) > > > > If I resume one of the compiling process trees both KernelStack and > > slab (kmalloc-128) usage increase quite quickly (and seems to never > > get down anymore) - probably at same rate as processes get born (no > > matter when they end). >=20 > Looks like it might be a leak in VFS. You could try kmemleak to narro= w > it down some more. See Documentation/kmemleak.txt for details. Hm, seems not to be willing to let me run kmemleak... each time I put on my load scenario I get "BUG: unable to handle kernel " on console as a last breath from the system. (the rest of the trace never shows up= ) Going to try harder to get at least a complete trace... Bruno > Pekka