From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1757294AbZC0MwN (ORCPT ); Fri, 27 Mar 2009 08:52:13 -0400 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1753242AbZC0Mv4 (ORCPT ); Fri, 27 Mar 2009 08:51:56 -0400 Received: from mail-fx0-f158.google.com ([209.85.220.158]:55778 "EHLO mail-fx0-f158.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753803AbZC0Mvy (ORCPT ); Fri, 27 Mar 2009 08:51:54 -0400 DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=from:to:subject:date:user-agent:cc:references:in-reply-to :mime-version:content-disposition:message-id:content-type :content-transfer-encoding; b=RifGmyTLmrtPMLaNdT2nNe/YZgX2vMsy/q3FkTqGpI+6e3axvtE290sKHts6KNwSM/ OCxqtlOPFDb4kDnp3z3vP3kzS3kgYMn20IqtZvlLhyWVNtuEoasNF1R6rrZmnMGRnror X5SlJ731ku92VFO0yQwIR4OxWxw0tizq5djHk= From: Bartlomiej Zolnierkiewicz To: Larry Finger Subject: Re: Possible IRQ lock inversion from 2.6.29-Linus-03321-gbe0ea69 (2.6.29-git) Date: Fri, 27 Mar 2009 13:54:35 +0100 User-Agent: KMail/1.11.1 (Linux/2.6.29-rc8-next-20090320; KDE/4.2.1; i686; ; ) Cc: LKML , Jonathan Corbet , Christoph Hellwig , Al Viro , Li Zefan , Wu Fengguang , Ingo Molnar References: <49CC5F15.4020404@lwfinger.net> In-Reply-To: <49CC5F15.4020404@lwfinger.net> MIME-Version: 1.0 Content-Disposition: inline Message-Id: <200903271354.45480.bzolnier@gmail.com> Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Hi, I've seen this reported before against linux-next: http://lkml.org/lkml/2009/3/2/399 and I also experienced it myself (since at least next-20090213). I haven't verified it but I believe that the warning is triggered by "Move FASYNC bit handling to f_op->fasync()" change (which is commit 76398425bb06b07cc3a3b1ce169c67dc9d6874ed in Linus' tree). I remember looking a bit more closely into the issue and not seeing the problem with the locking (though I could have missed something): file->f_lock is never taken in hard-irq or soft-irq context and in the only place where file->f_lock is taken with fasync_lock hold we're protected against IRQs by write_lock_irq(). [ Despite not being a problem now I think that changing spin_[un]lock() to *_irq() variants for file->f_lock could be (given that it really fixes the warning) more viable long-term solution than adding special lockdep handling (well, it could be that one day file->f_lock is used in soft-irq context and then the irq lock inversion issue will become a real one) and shouldn't incurr performance penalty since we hold it only for a very brief time. ] On Friday 27 March 2009, Larry Finger wrote: > On my x86_64 dual core system, I get the following messages logged. > > > ========================================================= > [ INFO: possible irq lock inversion dependency detected ] > 2.6.29-Linus-03321-gbe0ea69 #55 > --------------------------------------------------------- > swapper/0 just changed the state of lock: > (fasync_lock){..+.}, at: [] kill_fasync+0x2c/0x4e > but this lock took another, hard-irq-unsafe lock in the past: > (&f->f_lock){--..} > > and interrupts could create inverse lock ordering between them. > > > other info that might help us debug this: > 4 locks held by swapper/0: > #0: (&serio->lock){+...}, at: [] serio_interrupt+0x2b/0x83 > #1: (&dev->event_lock){+...}, at: [] input_event+0x40/0x7d > #2: (rcu_read_lock){..--}, at: [] input_pass_event+0x0/0xcc > #3: (rcu_read_lock){..--}, at: [] evdev_event+0x0/0xfd > > the first lock's dependencies: > -> (fasync_lock){..+.} ops: 0 { > initial-use at: > [] __lock_acquire+0x79e/0x1697 > [] lock_acquire+0x55/0x71 > [] _write_lock_irq+0x37/0x43 > [] fasync_helper+0x57/0x110 > [] locks_delete_lock+0x50/0x9f > [] __posix_lock_file+0x326/0x549 > [] vfs_lock_file+0x38/0x3a > [] locks_remove_posix+0x91/0xb2 > [] filp_close+0x56/0x68 > [] sys_close+0xaa/0xe9 > [] system_call_fastpath+0x16/0x1b > [] 0xffffffffffffffff > in-hardirq-R at: > [] 0xffffffffffffffff > } > ... key at: [] fasync_lock+0x18/0x30 > -> (&f->f_lock){--..} ops: 0 { > initial-use at: > [] __lock_acquire+0x79e/0x1697 > [] lock_acquire+0x55/0x71 > [] _spin_lock+0x31/0x3d > [] fasync_helper+0xd6/0x110 > [] locks_delete_lock+0x50/0x9f > [] __posix_lock_file+0x326/0x549 > [] vfs_lock_file+0x38/0x3a > [] locks_remove_posix+0x91/0xb2 > [] filp_close+0x56/0x68 > [] sys_close+0xaa/0xe9 > [] system_call_fastpath+0x16/0x1b > [] 0xffffffffffffffff > softirq-on-W at: > [] __lock_acquire+0x785/0x1697 > [] lock_acquire+0x55/0x71 > [] _spin_lock+0x31/0x3d > [] sys_fcntl+0x2aa/0x36c > [] system_call_fastpath+0x16/0x1b > [] 0xffffffffffffffff > hardirq-on-W at: > [] __lock_acquire+0x75c/0x1697 > [] lock_acquire+0x55/0x71 > [] _spin_lock+0x31/0x3d > [] sys_fcntl+0x2aa/0x36c > [] system_call_fastpath+0x16/0x1b > [] 0xffffffffffffffff > } > ... key at: [] __key.20386+0x0/0x8 > ... acquired at: > [] __lock_acquire+0x1332/0x1697 > [] lock_acquire+0x55/0x71 > [] _spin_lock+0x31/0x3d > [] fasync_helper+0xd6/0x110 > [] locks_delete_lock+0x50/0x9f > [] __posix_lock_file+0x326/0x549 > [] vfs_lock_file+0x38/0x3a > [] locks_remove_posix+0x91/0xb2 > [] filp_close+0x56/0x68 > [] sys_close+0xaa/0xe9 > [] system_call_fastpath+0x16/0x1b > [] 0xffffffffffffffff > > > the second lock's dependencies: > -> (&f->f_lock){--..} ops: 0 { > initial-use at: > [] __lock_acquire+0x79e/0x1697 > [] lock_acquire+0x55/0x71 > [] _spin_lock+0x31/0x3d > [] fasync_helper+0xd6/0x110 > [] locks_delete_lock+0x50/0x9f > [] __posix_lock_file+0x326/0x549 > [] vfs_lock_file+0x38/0x3a > [] locks_remove_posix+0x91/0xb2 > [] filp_close+0x56/0x68 > [] sys_close+0xaa/0xe9 > [] system_call_fastpath+0x16/0x1b > [] 0xffffffffffffffff > softirq-on-W at: > [] __lock_acquire+0x785/0x1697 > [] lock_acquire+0x55/0x71 > [] _spin_lock+0x31/0x3d > [] sys_fcntl+0x2aa/0x36c > [] system_call_fastpath+0x16/0x1b > [] 0xffffffffffffffff > hardirq-on-W at: > [] __lock_acquire+0x75c/0x1697 > [] lock_acquire+0x55/0x71 > [] _spin_lock+0x31/0x3d > [] sys_fcntl+0x2aa/0x36c > [] system_call_fastpath+0x16/0x1b > [] 0xffffffffffffffff > } > ... key at: [] __key.20386+0x0/0x8 > > stack backtrace: > Pid: 0, comm: swapper Not tainted 2.6.29-Linus-03321-gbe0ea69 #55 > Call Trace: > [] print_irq_inversion_bug+0x175/0x184 > [] check_usage_forwards+0x98/0xa1 > [] mark_lock+0x5dd/0xa2b > [] __lock_acquire+0x676/0x1697 > [] ? __lock_acquire+0x79e/0x1697 > [] lock_acquire+0x55/0x71 > [] ? kill_fasync+0x2c/0x4e > [] _read_lock+0x34/0x41 > [] ? kill_fasync+0x2c/0x4e > [] kill_fasync+0x2c/0x4e > [] evdev_pass_event+0x6e/0x77 > [] evdev_event+0x74/0xfd > [] ? evdev_event+0x0/0xfd > [] input_pass_event+0x64/0xcc > [] ? input_pass_event+0x0/0xcc > [] input_handle_event+0x339/0x345 > [] input_event+0x63/0x7d > [] alps_process_packet+0x3b7/0x4cc > [] alps_process_byte+0x5b/0x6e > [] psmouse_handle_byte+0x17/0x10d > [] psmouse_interrupt+0x277/0x285 > [] ? serio_interrupt+0x2b/0x83 > [] serio_interrupt+0x47/0x83 > [] i8042_interrupt+0x200/0x215 > [] handle_IRQ_event+0x6b/0xa1 > [] handle_edge_irq+0xeb/0x131 > [] __irqentry_text_start+0x6d/0xd8 > [] ret_from_intr+0x0/0xf > [] ? tick_broadcast_oneshot_control+0x1f/0x102 > [] ? default_idle+0x35/0x4f > [] ? default_idle+0x33/0x4f > [] ? c1e_idle+0xda/0x101 > [] ? atomic_notifier_call_chain+0xf/0x11 > [] ? cpu_idle+0x5c/0x9d > [] ? rest_init+0x6b/0x6d