From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1757914Ab0CKNqA (ORCPT ); Thu, 11 Mar 2010 08:46:00 -0500 Received: from e5.ny.us.ibm.com ([32.97.182.145]:45128 "EHLO e5.ny.us.ibm.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1756598Ab0CKNp7 (ORCPT ); Thu, 11 Mar 2010 08:45:59 -0500 Date: Thu, 11 Mar 2010 05:45:56 -0800 From: "Paul E. McKenney" To: =?iso-8859-1?Q?Am=E9rico?= Wang Cc: Peter Zijlstra , LKML Subject: Re: 2.6.34-rc1: rcu lockdep bug? Message-ID: <20100311134556.GA6344@linux.vnet.ibm.com> Reply-To: paulmck@linux.vnet.ibm.com References: <2375c9f91003110205v1d7f00bfk89472cb11bd985d3@mail.gmail.com> MIME-Version: 1.0 Content-Type: text/plain; charset=iso-8859-1 Content-Disposition: inline Content-Transfer-Encoding: 8bit In-Reply-To: <2375c9f91003110205v1d7f00bfk89472cb11bd985d3@mail.gmail.com> User-Agent: Mutt/1.5.15+20070412 (2007-04-11) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Thu, Mar 11, 2010 at 06:05:38PM +0800, Américo Wang wrote: > Hello, Paul and Peter, > > Attached is the lockdep warning that I triggered today. > > I am not sure if this is a bug of rcu lockdep, because I am > testing my patch when this occurred. However, in the backtrace, > there is none of the functions that I touched, weird. > > So, please help to check if this is a bug of rcu lockdep. This sort of thing is caused by acquiring the same lock with softirq (AKA BH) blocked and not, which can result in self-deadlock. There was such a bug in the RCU lockdep stuff in -tip, but it has long since been fixed. If you were seeing that bug, rcu_do_batch() would be on the stack, which it does not appear to be. So does your patch involve the usbfs_mutex? Or attempt to manipulate vfs/fs state from withing networking softirq/BH context? Thanx, Paul > Please Cc netdev when necessary. > > Thanks much! > Mar 11 17:11:22 dhcp-66-70-5 kernel: ================================= > Mar 11 17:11:22 dhcp-66-70-5 kernel: [ INFO: inconsistent lock state ] > Mar 11 17:11:22 dhcp-66-70-5 kernel: 2.6.34-rc1 #58 > Mar 11 17:11:22 dhcp-66-70-5 kernel: --------------------------------- > Mar 11 17:11:22 dhcp-66-70-5 kernel: inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage. > Mar 11 17:11:22 dhcp-66-70-5 kernel: swapper/0 [HC0[0]:SC1[1]:HE0:SE0] takes: > Mar 11 17:11:22 dhcp-66-70-5 kernel: (usbfs_mutex){+.?...}, at: [] netif_receive_skb+0xe7/0x819 > Mar 11 17:11:22 dhcp-66-70-5 kernel: {SOFTIRQ-ON-W} state was registered at: > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] __lock_acquire+0xaec/0xe55 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] lock_acquire+0x163/0x1aa > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] mutex_lock_nested+0x64/0x4e9 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] usbdev_open+0x115/0x4e9 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] chrdev_open+0x27a/0x2fe > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] __dentry_open+0x2d4/0x4d2 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] nameidata_to_filp+0x58/0x7e > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] do_last+0x81b/0xa3d > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] do_filp_open+0x2ff/0x869 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] do_sys_open+0x8c/0x187 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] sys_open+0x27/0x30 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] system_call_fastpath+0x16/0x1b > Mar 11 17:11:22 dhcp-66-70-5 kernel: irq event stamp: 7135619 > Mar 11 17:11:22 dhcp-66-70-5 kernel: hardirqs last enabled at (7135618): [] __kmalloc_node_track_caller+0x18d/0x256 > Mar 11 17:11:22 dhcp-66-70-5 kernel: hardirqs last disabled at (7135619): [] _raw_spin_lock_irqsave+0x3f/0xe2 > Mar 11 17:11:22 dhcp-66-70-5 kernel: softirqs last enabled at (7135604): [] __do_softirq+0x334/0x35f > Mar 11 17:11:22 dhcp-66-70-5 kernel: softirqs last disabled at (7135611): [] call_softirq+0x1c/0x4c > Mar 11 17:11:22 dhcp-66-70-5 kernel: > Mar 11 17:11:22 dhcp-66-70-5 kernel: other info that might help us debug this: > Mar 11 17:11:22 dhcp-66-70-5 kernel: 2 locks held by swapper/0: > Mar 11 17:11:22 dhcp-66-70-5 kernel: #0: (rcu_read_lock){.+.+..}, at: [] net_rx_action+0xc9/0x40f > Mar 11 17:11:22 dhcp-66-70-5 kernel: #1: (&(&napi->poll_lock)->rlock){+.-...}, at: [] net_rx_action+0x158/0x40f > Mar 11 17:11:22 dhcp-66-70-5 kernel: > Mar 11 17:11:22 dhcp-66-70-5 kernel: stack backtrace: > Mar 11 17:11:22 dhcp-66-70-5 kernel: Pid: 0, comm: swapper Not tainted 2.6.34-rc1 #58 > Mar 11 17:11:22 dhcp-66-70-5 kernel: Call Trace: > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] print_usage_bug+0x26b/0x283 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] ? check_usage_forwards+0x0/0x141 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] mark_lock+0x4e0/0x8ff > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] __lock_acquire+0xa0d/0xe55 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] lock_acquire+0x163/0x1aa > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] ? netif_receive_skb+0xe7/0x819 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] _raw_spin_lock_irqsave+0x6c/0xe2 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] ? netif_receive_skb+0xe7/0x819 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] netif_receive_skb+0xe7/0x819 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] napi_skb_finish+0x37/0x6a > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] napi_gro_receive+0x44/0x50 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] tg3_poll_work+0x9c6/0xfab [tg3] > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] ? __lock_acquire+0xd8d/0xe55 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] tg3_poll+0xfb/0x322 [tg3] > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] net_rx_action+0x1b4/0x40f > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] ? net_rx_action+0xc9/0x40f > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] __do_softirq+0x194/0x35f > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] call_softirq+0x1c/0x4c > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] do_softirq+0x8c/0x181 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] irq_exit+0xa5/0xae > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] do_IRQ+0x10a/0x136 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] ret_from_intr+0x0/0xf > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] ? acpi_safe_halt+0x61/0x84 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] ? acpi_safe_halt+0x58/0x84 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] acpi_idle_enter_c1+0xd7/0x17b > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] ? __atomic_notifier_call_chain+0x92/0xa7 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] ? ladder_select_state+0x42/0x23d > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] cpuidle_idle_call+0x104/0x1b4 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] cpu_idle+0xfd/0x163 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] rest_init+0x13a/0x145 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] ? rest_init+0x0/0x145 > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] start_kernel+0x789/0x79d > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] x86_64_start_reservations+0x104/0x10f > Mar 11 17:11:22 dhcp-66-70-5 kernel: [] x86_64_start_kernel+0x1e0/0x1ee