From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1755630Ab3BFBKj (ORCPT ); Tue, 5 Feb 2013 20:10:39 -0500 Received: from mail.candelatech.com ([208.74.158.172]:41085 "EHLO ns3.lanforge.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753950Ab3BFBKh (ORCPT ); Tue, 5 Feb 2013 20:10:37 -0500 Message-ID: <5111AD8D.1080005@candelatech.com> Date: Tue, 05 Feb 2013 17:10:37 -0800 From: Ben Greear Organization: Candela Technologies User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:17.0) Gecko/20130110 Thunderbird/17.0.2 MIME-Version: 1.0 To: Linux Kernel Mailing List Subject: Question on lockdep and MAX_LOCK_DEPTH Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org I'm debugging something that could be my own bug in my wanlink module (but then again, haven't seen this on 3.5 kernels, and my module is basically un-changed since then). I'm using lockdep, and keep seeing "BUG: MAX_LOCK_DEPTH too low". I tried changing the depth to 96 from 48, but it still hits. I also added debug_show_all_locks(); when this error case hits. I was assuming that if lockdep depth is large, there would be lots of locks held..but that does not seem to be the case?? =============================== [ INFO: suspicious RCU usage. ] 3.7.6+ #4 Tainted: G C O ------------------------------- /home/greearb/git/linux-3.7.dev.y/kernel/rcutree.c:360 Illegal idle entry in RCU read-side critical section.! other info that might help us debug this: RCU used illegally from idle CPU! rcu_scheduler_active = 1, debug_locks = 1 RCU used illegally from extended quiescent state! 1 lock held by swapper/1/0: #0: (rcu_read_lock){.+.+..}, at: [] rcu_read_lock+0x0/0x6f stack backtrace: Pid: 0, comm: swapper/1 Tainted: G C O 3.7.6+ #4 Call Trace: [] lockdep_rcu_suspicious+0xfc/0x105 [] rcu_eqs_enter_common+0xef/0x178 [] rcu_irq_exit+0x7f/0xb0 [] irq_exit+0xc0/0xcc [] do_IRQ+0x97/0xae [] common_interrupt+0x72/0x72 [] ? mwait_idle+0x77/0x9f [] ? mwait_idle+0x6e/0x9f [] cpu_idle+0x68/0xbc [] start_secondary+0x1fc/0x203 Showing all locks held in the system: 1 lock held by bash/2481: #0: (&tty->atomic_read_lock){+.+...}, at: [] n_tty_read+0x28d/0x785 1 lock held by mingetty/2853: #0: (&tty->atomic_read_lock){+.+...}, at: [] n_tty_read+0x28d/0x785 1 lock held by mingetty/2857: #0: (&tty->atomic_read_lock){+.+...}, at: [] n_tty_read+0x28d/0x785 1 lock held by mingetty/2862: #0: (&tty->atomic_read_lock){+.+...}, at: [] n_tty_read+0x28d/0x785 1 lock held by mingetty/2865: #0: (&tty->atomic_read_lock){+.+...}, at: [] n_tty_read+0x28d/0x785 1 lock held by mingetty/2867: #0: (&tty->atomic_read_lock){+.+...}, at: [] n_tty_read+0x28d/0x785 1 lock held by mingetty/2869: #0: (&tty->atomic_read_lock){+.+...}, at: [] n_tty_read+0x28d/0x785 1 lock held by bash/3017: #0: (&tty->atomic_read_lock){+.+...}, at: [] n_tty_read+0x28d/0x785 ============================================= BUG: MAX_LOCK_DEPTH too low, depth: 96 max: 96! turning off the locking correctness validator. Pid: 0, comm: swapper/1 Tainted: G C O 3.7.6+ #4 Call Trace: [] __lock_acquire+0xe80/0xf06 [] ? check_irq_usage+0xad/0xbe [] lock_acquire+0x64/0x81 [] ? cpu_cgroup_can_attach+0x66/0x66 [] rcu_read_lock+0x33/0x6f [] ? cpu_cgroup_can_attach+0x66/0x66 [] ttwu_stat+0x60/0x11c [] try_to_wake_up+0x1e6/0x20b [] default_wake_function+0xd/0xf [] __wake_up_common+0x49/0x7f [] __wake_up+0x34/0x48 [] handleRcvWlp+0xf4d/0xfd5 [wanlink] [] ? __lock_acquire+0x389/0xf06 [] wp_handle_rcv_pkt+0x1f5/0x243 [wanlink] [] handle_rcv+0x1a9/0x1dd [wanlink] [] deliver_skb+0x58/0x60 [] __netif_receive_skb+0x507/0x63c [] ? read_tsc+0x9/0x1b [] netif_receive_skb+0x56/0x8b [] ? __napi_gro_receive+0xf3/0x102 [] napi_skb_finish+0x24/0x57 [] napi_gro_receive+0x91/0x96 [] e1000_receive_skb+0x50/0x5b [e1000e] [] e1000_clean_rx_irq+0x29f/0x341 [e1000e] [] e1000e_poll+0x7d/0x239 [e1000e] [] net_rx_action+0xb2/0x1e2 [] ? __do_softirq+0x6d/0x17b [] __do_softirq+0xab/0x17b [] ? hrtimer_interrupt+0x127/0x1e2 [] call_softirq+0x1c/0x30 [] do_softirq+0x46/0x9e [] irq_exit+0x4e/0xcc [] smp_apic_timer_interrupt+0x85/0x93 [] apic_timer_interrupt+0x72/0x80 [] ? retint_restore_args+0x13/0x13 [] ? mwait_idle+0x77/0x9f [] ? mwait_idle+0x6e/0x9f [] cpu_idle+0x68/0xbc [] start_secondary+0x1fc/0x203 BUG: sleeping function called from invalid context at /home/greearb/git/linux-3.7.dev.y/kernel/mutex.c:269 in_atomic(): 0, irqs_disabled(): 0, pid: 1375, name: rs:main Q:Reg INFO: lockdep is turned off. Pid: 1375, comm: rs:main Q:Reg Tainted: G C O 3.7.6+ #4 Call Trace: [] __might_sleep+0x1a2/0x1ab [] mutex_lock_nested+0x20/0x3b [] process_output+0x24/0x52 [] n_tty_write+0x273/0x356 [] ? try_to_wake_up+0x20b/0x20b [] tty_write+0x19b/0x23a [] ? n_tty_ioctl+0xc6/0xc6 [] redirected_tty_write+0x8a/0x95 [] vfs_write+0xa9/0x105 [] sys_write+0x54/0x89 [] system_call_fastpath+0x16/0x1b -- Ben Greear Candela Technologies Inc http://www.candelatech.com