Hi all,
this got dumped into my kern.log, so I thought I'll post it for more
savvy eyes to look at:
INFO: possible circular locking dependency detected
(See below for the full text.)
Basically, I was running a browser for a few hours, and then opened a
new tab to watch a new video. Immediately, the above message poured
into kern.log! (I had the latter open because I was watching for
another problem.)
The kernel is a wireless-testing, 3.0.0-rc7-wl, and has been running
(w/o this problem) for about a month.
The 2-core CPU is a Nehalem Core i3.
The box continues to run fine! Even the browser tab opened!
This is more FYI than anything, but I can try to provide more info if
anyone's interested.
regards,
ali
PS the full output in kern.log:
Aug 26 01:02:00 suxbox kernel: [31157.010143]
Aug 26 01:02:00 suxbox kernel: [31157.010145] =======================================================
Aug 26 01:02:00 suxbox kernel: [31157.010149] [ INFO: possible circular locking dependency detected ]
Aug 26 01:02:00 suxbox kernel: [31157.010153] 3.0.0-rc7-wl_m_M01aug2011 #1
Aug 26 01:02:00 suxbox kernel: [31157.010154] -------------------------------------------------------
Aug 26 01:02:00 suxbox kernel: [31157.010156] opera/18222 is trying to acquire lock:
Aug 26 01:02:00 suxbox kernel: [31157.010158] (&(&sch->busylock)->rlock){+.-...}, at: [<ffffffff812d4200>] dev_queue_xmit+0x7c0/0x840
Aug 26 01:02:00 suxbox kernel: [31157.010168]
Aug 26 01:02:00 suxbox kernel: [31157.010169] but task is already holding lock:
Aug 26 01:02:00 suxbox kernel: [31157.010171] (&(&pch->downl)->rlock){+.-.-.}, at: [<ffffffffa04ac5fd>] ppp_push+0x15d/0x6a0 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010179]
Aug 26 01:02:00 suxbox kernel: [31157.010179] which lock already depends on the new lock.
Aug 26 01:02:00 suxbox kernel: [31157.010180]
Aug 26 01:02:00 suxbox kernel: [31157.010183]
Aug 26 01:02:00 suxbox kernel: [31157.010183] the existing dependency chain (in reverse order) is:
Aug 26 01:02:00 suxbox kernel: [31157.010185]
Aug 26 01:02:00 suxbox kernel: [31157.010186] -> #3 (&(&pch->downl)->rlock){+.-.-.}:
Aug 26 01:02:00 suxbox kernel: [31157.010189] [<ffffffff81082cf8>] lock_acquire+0x58/0x70
Aug 26 01:02:00 suxbox kernel: [31157.010195] [<ffffffff813b8fbb>] _raw_spin_lock_bh+0x3b/0x50
Aug 26 01:02:00 suxbox kernel: [31157.010201] [<ffffffffa04ac5fd>] ppp_push+0x15d/0x6a0 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010205] [<ffffffffa04ad9bf>] ppp_xmit_process+0x42f/0x600 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010210] [<ffffffffa04ae3c0>] ppp_write+0xf0/0x100 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010215] [<ffffffff8111fe28>] vfs_write+0xc8/0x190
Aug 26 01:02:00 suxbox kernel: [31157.010221] [<ffffffff8111ffdc>] sys_write+0x4c/0x90
Aug 26 01:02:00 suxbox kernel: [31157.010225] [<ffffffff813bef7b>] system_call_fastpath+0x16/0x1b
Aug 26 01:02:00 suxbox kernel: [31157.010230]
Aug 26 01:02:00 suxbox kernel: [31157.010231] -> #2 (&(&ppp->wlock)->rlock){+.-.-.}:
Aug 26 01:02:00 suxbox kernel: [31157.010233] [<ffffffff81082cf8>] lock_acquire+0x58/0x70
Aug 26 01:02:00 suxbox kernel: [31157.010236] [<ffffffff813b8fbb>] _raw_spin_lock_bh+0x3b/0x50
Aug 26 01:02:00 suxbox kernel: [31157.010238] [<ffffffffa04ad5b7>] ppp_xmit_process+0x27/0x600 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010241] [<ffffffffa04adcd8>] ppp_start_xmit+0x148/0x210 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010245] [<ffffffff812d24bc>] dev_hard_start_xmit+0x33c/0x670
Aug 26 01:02:00 suxbox kernel: [31157.010247] [<ffffffff812eaefa>] sch_direct_xmit+0xda/0x270
Aug 26 01:02:00 suxbox kernel: [31157.010252] [<ffffffff812d3bdd>] dev_queue_xmit+0x19d/0x840
Aug 26 01:02:00 suxbox kernel: [31157.010254] [<ffffffff81306d16>] ip_finish_output+0x336/0x540
Aug 26 01:02:00 suxbox kernel: [31157.010257] [<ffffffff81307330>] ip_output+0xf0/0x160
Aug 26 01:02:00 suxbox kernel: [31157.010260] [<ffffffff81305468>] ip_local_out+0x28/0x80
Aug 26 01:02:00 suxbox kernel: [31157.010262] [<ffffffff813054d6>] ip_send_skb+0x16/0x70
Aug 26 01:02:00 suxbox kernel: [31157.010264] [<ffffffff8132a095>] udp_send_skb+0x115/0x3b0
Aug 26 01:02:00 suxbox kernel: [31157.010268] [<ffffffff8132af05>] udp_sendmsg+0x335/0x960
Aug 26 01:02:00 suxbox kernel: [31157.010270] [<ffffffff81335f01>] inet_sendmsg+0xc1/0x100
Aug 26 01:02:00 suxbox kernel: [31157.010273] [<ffffffff812bb1da>] sock_sendmsg+0xea/0x120
Aug 26 01:02:00 suxbox kernel: [31157.010276] [<ffffffff812bb394>] sys_sendto+0x134/0x180
Aug 26 01:02:00 suxbox kernel: [31157.010278] [<ffffffff813bef7b>] system_call_fastpath+0x16/0x1b
Aug 26 01:02:00 suxbox kernel: [31157.010281]
Aug 26 01:02:00 suxbox kernel: [31157.010281] -> #1 (_xmit_PPP#2){+.-.-.}:
Aug 26 01:02:00 suxbox kernel: [31157.010284] [<ffffffff81082cf8>] lock_acquire+0x58/0x70
Aug 26 01:02:00 suxbox kernel: [31157.010287] [<ffffffff813b8e06>] _raw_spin_lock+0x36/0x50
Aug 26 01:02:00 suxbox kernel: [31157.010290] [<ffffffff812eaed4>] sch_direct_xmit+0xb4/0x270
Aug 26 01:02:00 suxbox kernel: [31157.010293] [<ffffffff812d3bdd>] dev_queue_xmit+0x19d/0x840
Aug 26 01:02:00 suxbox kernel: [31157.010295] [<ffffffff81306d16>] ip_finish_output+0x336/0x540
Aug 26 01:02:00 suxbox kernel: [31157.010297] [<ffffffff81307330>] ip_output+0xf0/0x160
Aug 26 01:02:00 suxbox kernel: [31157.010300] [<ffffffff81305468>] ip_local_out+0x28/0x80
Aug 26 01:02:00 suxbox kernel: [31157.010302] [<ffffffff813054d6>] ip_send_skb+0x16/0x70
Aug 26 01:02:00 suxbox kernel: [31157.010304] [<ffffffff8132a095>] udp_send_skb+0x115/0x3b0
Aug 26 01:02:00 suxbox kernel: [31157.010307] [<ffffffff8132af05>] udp_sendmsg+0x335/0x960
Aug 26 01:02:00 suxbox kernel: [31157.010309] [<ffffffff81335f01>] inet_sendmsg+0xc1/0x100
Aug 26 01:02:00 suxbox kernel: [31157.010311] [<ffffffff812bb1da>] sock_sendmsg+0xea/0x120
Aug 26 01:02:00 suxbox kernel: [31157.010313] [<ffffffff812bb394>] sys_sendto+0x134/0x180
Aug 26 01:02:00 suxbox kernel: [31157.010316] [<ffffffff813bef7b>] system_call_fastpath+0x16/0x1b
Aug 26 01:02:00 suxbox kernel: [31157.010318]
Aug 26 01:02:00 suxbox kernel: [31157.010319] -> #0 (&(&sch->busylock)->rlock){+.-...}:
Aug 26 01:02:00 suxbox kernel: [31157.010321] [<ffffffff810826c8>] __lock_acquire+0x1548/0x1660
Aug 26 01:02:00 suxbox kernel: [31157.010324] [<ffffffff81082cf8>] lock_acquire+0x58/0x70
Aug 26 01:02:00 suxbox kernel: [31157.010326] [<ffffffff813b8e06>] _raw_spin_lock+0x36/0x50
Aug 26 01:02:00 suxbox kernel: [31157.010328] [<ffffffff812d4200>] dev_queue_xmit+0x7c0/0x840
Aug 26 01:02:00 suxbox kernel: [31157.010331] [<ffffffffa03086c7>] __pppoe_xmit+0x157/0x1a0 [pppoe]
Aug 26 01:02:00 suxbox kernel: [31157.010334] [<ffffffffa030871c>] pppoe_xmit+0xc/0x10 [pppoe]
Aug 26 01:02:00 suxbox kernel: [31157.010337] [<ffffffffa04ac618>] ppp_push+0x178/0x6a0 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010340] [<ffffffffa04ad9bf>] ppp_xmit_process+0x42f/0x600 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010343] [<ffffffffa04adcd8>] ppp_start_xmit+0x148/0x210 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010346] [<ffffffff812d24bc>] dev_hard_start_xmit+0x33c/0x670
Aug 26 01:02:00 suxbox kernel: [31157.010348] [<ffffffff812eaefa>] sch_direct_xmit+0xda/0x270
Aug 26 01:02:00 suxbox kernel: [31157.010351] [<ffffffff812d3bdd>] dev_queue_xmit+0x19d/0x840
Aug 26 01:02:00 suxbox kernel: [31157.010353] [<ffffffff81306d16>] ip_finish_output+0x336/0x540
Aug 26 01:02:00 suxbox kernel: [31157.010355] [<ffffffff81307330>] ip_output+0xf0/0x160
Aug 26 01:02:00 suxbox kernel: [31157.010357] [<ffffffff81305468>] ip_local_out+0x28/0x80
Aug 26 01:02:00 suxbox kernel: [31157.010359] [<ffffffff81305a08>] ip_queue_xmit+0x188/0x500
Aug 26 01:02:00 suxbox kernel: [31157.010362] [<ffffffff8131c294>] tcp_transmit_skb+0x414/0x910
Aug 26 01:02:00 suxbox kernel: [31157.010365] [<ffffffff8131eaf7>] tcp_write_xmit+0x1e7/0x9d0
Aug 26 01:02:00 suxbox kernel: [31157.010367] [<ffffffff8131f30b>] tcp_push_one+0x2b/0x40
Aug 26 01:02:00 suxbox kernel: [31157.010369] [<ffffffff81311e29>] tcp_sendmsg+0xb99/0xc00
Aug 26 01:02:00 suxbox kernel: [31157.010372] [<ffffffff81335f01>] inet_sendmsg+0xc1/0x100
Aug 26 01:02:00 suxbox kernel: [31157.010374] [<ffffffff812bb1da>] sock_sendmsg+0xea/0x120
Aug 26 01:02:00 suxbox kernel: [31157.010376] [<ffffffff812bb394>] sys_sendto+0x134/0x180
Aug 26 01:02:00 suxbox kernel: [31157.010379] [<ffffffff813bef7b>] system_call_fastpath+0x16/0x1b
Aug 26 01:02:00 suxbox kernel: [31157.010381]
Aug 26 01:02:00 suxbox kernel: [31157.010382] other info that might help us debug this:
Aug 26 01:02:00 suxbox kernel: [31157.010382]
Aug 26 01:02:00 suxbox kernel: [31157.010384] Chain exists of:
Aug 26 01:02:00 suxbox kernel: [31157.010384] &(&sch->busylock)->rlock --> &(&ppp->wlock)->rlock --> &(&pch->downl)->rlock
Aug 26 01:02:00 suxbox kernel: [31157.010388]
Aug 26 01:02:00 suxbox kernel: [31157.010389] Possible unsafe locking scenario:
Aug 26 01:02:00 suxbox kernel: [31157.010389]
Aug 26 01:02:00 suxbox kernel: [31157.010390] CPU0 CPU1
Aug 26 01:02:00 suxbox kernel: [31157.010392] ---- ----
Aug 26 01:02:00 suxbox kernel: [31157.010393] lock(&(&pch->downl)->rlock);
Aug 26 01:02:00 suxbox kernel: [31157.010394] lock(&(&ppp->wlock)->rlock);
Aug 26 01:02:00 suxbox kernel: [31157.010397] lock(&(&pch->downl)->rlock);
Aug 26 01:02:00 suxbox kernel: [31157.010399] lock(&(&sch->busylock)->rlock);
Aug 26 01:02:00 suxbox kernel: [31157.010401]
Aug 26 01:02:00 suxbox kernel: [31157.010401] *** DEADLOCK ***
Aug 26 01:02:00 suxbox kernel: [31157.010401]
Aug 26 01:02:00 suxbox kernel: [31157.010403] 7 locks held by opera/18222:
Aug 26 01:02:00 suxbox kernel: [31157.010404] #0: (sk_lock-AF_INET){+.+.+.}, at: [<ffffffff813112b4>] tcp_sendmsg+0x24/0xc00
Aug 26 01:02:00 suxbox kernel: [31157.010408] #1: (rcu_read_lock){.+.+..}, at: [<ffffffff81305880>] ip_queue_xmit+0x0/0x500
Aug 26 01:02:00 suxbox kernel: [31157.010412] #2: (rcu_read_lock_bh){.+....}, at: [<ffffffff812d3a40>] dev_queue_xmit+0x0/0x840
Aug 26 01:02:00 suxbox kernel: [31157.010416] #3: (_xmit_PPP#2){+.-.-.}, at: [<ffffffff812eaed4>] sch_direct_xmit+0xb4/0x270
Aug 26 01:02:00 suxbox kernel: [31157.010421] #4: (&(&ppp->wlock)->rlock){+.-.-.}, at: [<ffffffffa04ad5b7>] ppp_xmit_process+0x27/0x600 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010426] #5: (&(&pch->downl)->rlock){+.-.-.}, at: [<ffffffffa04ac5fd>] ppp_push+0x15d/0x6a0 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010430] #6: (rcu_read_lock_bh){.+....}, at: [<ffffffff812d3a40>] dev_queue_xmit+0x0/0x840
Aug 26 01:02:00 suxbox kernel: [31157.010434]
Aug 26 01:02:00 suxbox kernel: [31157.010434] stack backtrace:
Aug 26 01:02:00 suxbox kernel: [31157.010437] Pid: 18222, comm: opera Not tainted 3.0.0-rc7-wl_m_M01aug2011 #1
Aug 26 01:02:00 suxbox kernel: [31157.010439] Call Trace:
Aug 26 01:02:00 suxbox kernel: [31157.010442] [<ffffffff8107fa42>] print_circular_bug+0x212/0x2f0
Aug 26 01:02:00 suxbox kernel: [31157.010444] [<ffffffff810826c8>] __lock_acquire+0x1548/0x1660
Aug 26 01:02:00 suxbox kernel: [31157.010447] [<ffffffff81082cf8>] lock_acquire+0x58/0x70
Aug 26 01:02:00 suxbox kernel: [31157.010449] [<ffffffff812d4200>] ? dev_queue_xmit+0x7c0/0x840
Aug 26 01:02:00 suxbox kernel: [31157.010452] [<ffffffff813b8e06>] _raw_spin_lock+0x36/0x50
Aug 26 01:02:00 suxbox kernel: [31157.010454] [<ffffffff812d4200>] ? dev_queue_xmit+0x7c0/0x840
Aug 26 01:02:00 suxbox kernel: [31157.010456] [<ffffffff812d4200>] dev_queue_xmit+0x7c0/0x840
Aug 26 01:02:00 suxbox kernel: [31157.010458] [<ffffffff812d3a40>] ? dev_ioctl+0x820/0x820
Aug 26 01:02:00 suxbox kernel: [31157.010461] [<ffffffffa03086c7>] __pppoe_xmit+0x157/0x1a0 [pppoe]
Aug 26 01:02:00 suxbox kernel: [31157.010463] [<ffffffffa030871c>] pppoe_xmit+0xc/0x10 [pppoe]
Aug 26 01:02:00 suxbox kernel: [31157.010466] [<ffffffffa04ac618>] ppp_push+0x178/0x6a0 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010469] [<ffffffff813b9525>] ? _raw_spin_unlock_irqrestore+0x65/0x80
Aug 26 01:02:00 suxbox kernel: [31157.010471] [<ffffffff81080de5>] ? trace_hardirqs_on_caller+0x65/0x180
Aug 26 01:02:00 suxbox kernel: [31157.010473] [<ffffffff813b94fd>] ? _raw_spin_unlock_irqrestore+0x3d/0x80
Aug 26 01:02:00 suxbox kernel: [31157.010477] [<ffffffffa04ad9bf>] ppp_xmit_process+0x42f/0x600 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010480] [<ffffffffa04adcd8>] ppp_start_xmit+0x148/0x210 [ppp_generic]
Aug 26 01:02:00 suxbox kernel: [31157.010482] [<ffffffff812d24bc>] dev_hard_start_xmit+0x33c/0x670
Aug 26 01:02:00 suxbox kernel: [31157.010485] [<ffffffff812eaefa>] sch_direct_xmit+0xda/0x270
Aug 26 01:02:00 suxbox kernel: [31157.010487] [<ffffffff812d3bdd>] dev_queue_xmit+0x19d/0x840
Aug 26 01:02:00 suxbox kernel: [31157.010489] [<ffffffff812d3a40>] ? dev_ioctl+0x820/0x820
Aug 26 01:02:00 suxbox kernel: [31157.010491] [<ffffffff81306d16>] ip_finish_output+0x336/0x540
Aug 26 01:02:00 suxbox kernel: [31157.010496] [<ffffffff8103cb71>] ? get_parent_ip+0x11/0x50
Aug 26 01:02:00 suxbox kernel: [31157.010498] [<ffffffff81307330>] ip_output+0xf0/0x160
Aug 26 01:02:00 suxbox kernel: [31157.010500] [<ffffffff81305468>] ip_local_out+0x28/0x80
Aug 26 01:02:00 suxbox kernel: [31157.010502] [<ffffffff81305a08>] ip_queue_xmit+0x188/0x500
Aug 26 01:02:00 suxbox kernel: [31157.010504] [<ffffffff81305880>] ? ip_send_reply+0x320/0x320
Aug 26 01:02:00 suxbox kernel: [31157.010507] [<ffffffff8131c294>] tcp_transmit_skb+0x414/0x910
Aug 26 01:02:00 suxbox kernel: [31157.010509] [<ffffffff8131eaf7>] tcp_write_xmit+0x1e7/0x9d0
Aug 26 01:02:00 suxbox kernel: [31157.010512] [<ffffffff812c2aae>] ? __alloc_skb+0x7e/0x170
Aug 26 01:02:00 suxbox kernel: [31157.010514] [<ffffffff8131f30b>] tcp_push_one+0x2b/0x40
Aug 26 01:02:00 suxbox kernel: [31157.010516] [<ffffffff81311e29>] tcp_sendmsg+0xb99/0xc00
Aug 26 01:02:00 suxbox kernel: [31157.010519] [<ffffffff81335f01>] inet_sendmsg+0xc1/0x100
Aug 26 01:02:00 suxbox kernel: [31157.010521] [<ffffffff81335e40>] ? inet_recvmsg+0x100/0x100
Aug 26 01:02:00 suxbox kernel: [31157.010523] [<ffffffff81080ebd>] ? trace_hardirqs_on_caller+0x13d/0x180
Aug 26 01:02:00 suxbox kernel: [31157.010525] [<ffffffff812bb1da>] sock_sendmsg+0xea/0x120
Aug 26 01:02:00 suxbox kernel: [31157.010527] [<ffffffff81081367>] ? __lock_acquire+0x1e7/0x1660
Aug 26 01:02:00 suxbox kernel: [31157.010530] [<ffffffff813bca9d>] ? sub_preempt_count+0x9d/0xd0
Aug 26 01:02:00 suxbox kernel: [31157.010532] [<ffffffff813b9490>] ? _raw_spin_unlock+0x30/0x60
Aug 26 01:02:00 suxbox kernel: [31157.010535] [<ffffffff81084af1>] ? futex_wake+0x111/0x130
Aug 26 01:02:00 suxbox kernel: [31157.010538] [<ffffffff81121a57>] ? fget_light+0xd7/0x140
Aug 26 01:02:00 suxbox kernel: [31157.010540] [<ffffffff811219bb>] ? fget_light+0x3b/0x140
Aug 26 01:02:00 suxbox kernel: [31157.010543] [<ffffffff812bb394>] sys_sendto+0x134/0x180
Aug 26 01:02:00 suxbox kernel: [31157.010545] [<ffffffff8103cb71>] ? get_parent_ip+0x11/0x50
Aug 26 01:02:00 suxbox kernel: [31157.010548] [<ffffffff813befac>] ? sysret_check+0x27/0x62
Aug 26 01:02:00 suxbox kernel: [31157.010550] [<ffffffff81080ebd>] ? trace_hardirqs_on_caller+0x13d/0x180
Aug 26 01:02:00 suxbox kernel: [31157.010554] [<ffffffff811f06be>] ? trace_hardirqs_on_thunk+0x3a/0x3f
Aug 26 01:02:00 suxbox kernel: [31157.010556] [<ffffffff813bef7b>] system_call_fastpath+0x16/0x1b
--
To unsubscribe from this list: send the line "unsubscribe linux-smp" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
