Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1757044AbZGGNPo (ORCPT ); Tue, 7 Jul 2009 09:15:44 -0400 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1754729AbZGGNPa (ORCPT ); Tue, 7 Jul 2009 09:15:30 -0400 Received: from mail.open.by ([193.232.92.17]:58482 "EHLO post.open.by" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1754445AbZGGNP1 (ORCPT ); Tue, 7 Jul 2009 09:15:27 -0400 X-SpamTest-Envelope-From: sergey.senozhatsky@mail.by X-SpamTest-Group-ID: 00000000 X-SpamTest-Info: Profiles 8958 [Jul 06 2009] X-SpamTest-Info: {relay has no DNS name} X-SpamTest-Method: none X-SpamTest-Rate: 55 X-SpamTest-SPF: softfail X-SpamTest-Status: Not detected X-SpamTest-Status-Extended: not_detected X-SpamTest-Version: SMTP-Filter Version 3.0.0 [0284], KAS30/Release Date: Tue, 7 Jul 2009 16:17:25 +0300 From: Sergey Senozhatsky To: Catalin Marinas Cc: Pekka Enberg , Ingo Molnar , "Paul E. McKenney" , linux-kernel@vger.kernel.org, linux-mm@kvack.org Subject: Re: kmemleak not tainted Message-ID: <20090707131725.GB3238@localdomain.by> References: <20090707115128.GA3238@localdomain.by> <1246970859.9451.34.camel@pc1117.cambridge.arm.com> MIME-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha1; protocol="application/pgp-signature"; boundary="rJwd6BRFiFCcLxzm" Content-Disposition: inline In-Reply-To: <1246970859.9451.34.camel@pc1117.cambridge.arm.com> User-Agent: Mutt/1.5.20 (2009-06-14) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 7784 Lines: 181 --rJwd6BRFiFCcLxzm Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable > On Tue, 2009-07-07 at 14:51 +0300, Sergey Senozhatsky wrote: > > kernel: [ 1917.133154] INFO: RCU detected CPU 0 stall (t=3D485140/3000 = jiffies) >=20 > That's the relevant message. With CONFIG_RCU_CPU_STALL_DETECTOR you may > get these messages. >=20 > > static struct kmemleak_object *find_and_get_object(unsigned long ptr, i= nt alias) > > { > > unsigned long flags; > > struct kmemleak_object *object =3D NULL; > >=20 > > rcu_read_lock(); > > read_lock_irqsave(&kmemleak_lock, flags); > > if (ptr >=3D min_addr && ptr < max_addr) > > object =3D lookup_object(ptr, alias); > > >> read_unlock_irqrestore(&kmemleak_lock, flags); > >=20 > > /* check whether the object is still available */ > > if (object && !get_object(object)) > > object =3D NULL; > > rcu_read_unlock(); > >=20 > > return object; > > } >=20 > It just happened here because that's where the interrupts were enabled > and the timer routine invoked. The rcu-locked region above should be > pretty short (just a tree look-up). >=20 > What I think happens is that the kmemleak thread runs for several > seconds for scanning the memory and there may not be any context > switches. I have a patch to add more cond_resched() calls throughout the > kmemleak_scan() function which I hope will get merged.=20 Cc me please. Thanks. > I don't get any of these messages with CONFIG_PREEMPT enabled. >=20 It started with rc2-git1 (may be). Almost every scan ends with RCU pending. [ 1917.133154] INFO: RCU detected CPU 0 stall (t=3D485140/3000 jiffies) [ 1917.133154] Pid: 511, comm: kmemleak Not tainted 2.6.31-rc2-nv-git1-0025= 4-ga4e2f0a-dirty #2 [ 1917.133154] Call Trace: [ 1917.133154] [] ? printk+0x23/0x36 [ 1917.133154] [] __rcu_pending+0x140/0x210 [ 1917.133154] [] rcu_pending+0x2a/0x70 [ 1917.133154] [] update_process_times+0x3f/0x80 [ 1917.133154] [] tick_sched_timer+0x6f/0xf0 [ 1917.133154] [] __run_hrtimer+0x56/0xe0 [ 1917.133154] [] ? tick_sched_timer+0x0/0xf0 [ 1917.133154] [] ? tick_sched_timer+0x0/0xf0 [ 1917.133154] [] hrtimer_interrupt+0x145/0x270 [ 1917.133154] [] smp_apic_timer_interrupt+0x5c/0xb0 [ 1917.133154] [] ? trace_hardirqs_off_thunk+0xc/0x14 [ 1917.133154] [] apic_timer_interrupt+0x36/0x3c [ 1917.133154] [] ? _read_unlock_irqrestore+0x41/0x70 [ 1917.133154] [] find_and_get_object+0x75/0xe0 [ 1917.133154] [] ? find_and_get_object+0x0/0xe0 [ 1917.133154] [] scan_block+0x87/0x110 [ 1917.133154] [] kmemleak_scan+0x280/0x420 [ 1917.133154] [] ? kmemleak_scan+0x0/0x420 [ 1917.133154] [] ? kmemleak_scan_thread+0x0/0xc0 [ 1917.133154] [] kmemleak_scan_thread+0x50/0xc0 [ 1917.133154] [] kthread+0x84/0x90 [ 1917.133154] [] ? kthread+0x0/0x90 [ 1917.133154] [] kernel_thread_helper+0x7/0x1c [ 1979.742347] kmemleak: 1 new suspected memory leaks (see /sys/kernel/debu= g/kmemleak) [ 2589.860586] INFO: RCU detected CPU 1 stall (t=3D686958/3000 jiffies) [ 2589.860586] Pid: 511, comm: kmemleak Not tainted 2.6.31-rc2-nv-git1-0025= 4-ga4e2f0a-dirty #2 [ 2589.860586] Call Trace: [ 2589.860586] [] ? printk+0x23/0x36 [ 2589.860586] [] __rcu_pending+0x140/0x210 [ 2589.860586] [] rcu_pending+0x2a/0x70 [ 2589.860586] [] update_process_times+0x3f/0x80 [ 2589.860586] [] tick_sched_timer+0x6f/0xf0 [ 2589.860586] [] __run_hrtimer+0x56/0xe0 [ 2589.860586] [] ? tick_sched_timer+0x0/0xf0 [ 2589.860586] [] ? tick_sched_timer+0x0/0xf0 [ 2589.860586] [] hrtimer_interrupt+0x145/0x270 [ 2589.860586] [] ? _local_bh_enable+0x68/0xd0 [ 2589.860586] [] smp_apic_timer_interrupt+0x5c/0xb0 [ 2589.860586] [] ? trace_hardirqs_off_thunk+0xc/0x14 [ 2589.860586] [] apic_timer_interrupt+0x36/0x3c [ 2589.860586] [] ? lock_acquire+0xb5/0x120 [ 2589.860586] [] ? find_and_get_object+0x0/0xe0 [ 2589.860586] [] ? find_and_get_object+0x0/0xe0 [ 2589.860586] [] find_and_get_object+0x4b/0xe0 [ 2589.860586] [] ? find_and_get_object+0x0/0xe0 [ 2589.860586] [] scan_block+0x87/0x110 [ 2589.860586] [] kmemleak_scan+0x280/0x420 [ 2589.860586] [] ? kmemleak_scan+0x0/0x420 [ 2589.860586] [] ? kmemleak_scan_thread+0x0/0xc0 [ 2589.860586] [] kmemleak_scan_thread+0x50/0xc0 [ 2589.860586] [] kthread+0x84/0x90 [ 2589.860586] [] ? kthread+0x0/0x90 [ 2589.860586] [] kernel_thread_helper+0x7/0x1c [ 3089.007168] r8169: eth1: link down [ 3245.897188] INFO: RCU detected CPU 1 stall (t=3D883769/3000 jiffies) [ 3245.897188] Pid: 511, comm: kmemleak Not tainted 2.6.31-rc2-nv-git1-0025= 4-ga4e2f0a-dirty #2 [ 3245.897188] Call Trace: [ 3245.897188] [] ? printk+0x23/0x36 [ 3245.897188] [] __rcu_pending+0x140/0x210 [ 3245.897188] [] rcu_pending+0x2a/0x70 [ 3245.897188] [] update_process_times+0x3f/0x80 [ 3245.897188] [] tick_sched_timer+0x6f/0xf0 [ 3245.897188] [] __run_hrtimer+0x56/0xe0 [ 3245.897188] [] ? tick_sched_timer+0x0/0xf0 [ 3245.897188] [] ? tick_sched_timer+0x0/0xf0 [ 3245.897188] [] hrtimer_interrupt+0x145/0x270 [ 3245.897188] [] smp_apic_timer_interrupt+0x5c/0xb0 [ 3245.897188] [] ? trace_hardirqs_off_thunk+0xc/0x14 [ 3245.897188] [] apic_timer_interrupt+0x36/0x3c [ 3245.897188] [] ? _read_unlock_irqrestore+0x41/0x70 [ 3245.897188] [] find_and_get_object+0xbf/0xe0 [ 3245.897188] [] ? find_and_get_object+0x0/0xe0 [ 3245.897188] [] scan_block+0x87/0x110 [ 3245.897188] [] kmemleak_scan+0x280/0x420 [ 3245.897188] [] ? kmemleak_scan+0x0/0x420 [ 3245.897188] [] ? kmemleak_scan_thread+0x0/0xc0 [ 3245.897188] [] kmemleak_scan_thread+0x50/0xc0 [ 3245.897188] [] kthread+0x84/0x90 [ 3245.897188] [] ? kthread+0x0/0x90 [ 3245.897188] [] kernel_thread_helper+0x7/0x1c [ 3290.435108] kmemleak: 5 new suspected memory leaks (see /sys/kernel/debu= g/kmemleak) Hm.. Something is broken... cat /.../kmemleak [ 7933.537868] =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D [ 7933.537873] [ BUG: lock held when returning to user space! ] [ 7933.537876] ------------------------------------------------ [ 7933.537880] cat/2897 is leaving the kernel with locks still held! [ 7933.537884] 1 lock held by cat/2897: [ 7933.537887] #0: (scan_mutex){+.+.+.}, at: [] kmemleak_open+0= x4c/0x80 > --=20 > Catalin >=20 =09 Sergey --rJwd6BRFiFCcLxzm Content-Type: application/pgp-signature; name="signature.asc" Content-Description: Digital signature Content-Disposition: inline -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.9 (GNU/Linux) iJwEAQECAAYFAkpTSuUACgkQfKHnntdSXjR0OQP/bVH8POBqSYXspc9XtNQ8b++s hS5r1HpgiVYZiGRTBj7EbkJzVsgCYa/nWIIvUMHtOv+BbzDVACsC8U6BwO0iDvr8 PkbBx2n9px16+0Mu+9lGhC4ZBMFNtGl3lP4SKdiXYsQDbf1/327P8GXbAS0+SLhs hEIS+aKjz8zznwoflEY= =YTQW -----END PGP SIGNATURE----- --rJwd6BRFiFCcLxzm-- -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/