[PATCH] ppp_generic: lockdep warning Re: [Bug 8132] New: pptp server lockup ...

[Jarek Poplawski <jarkao2@o2.pl>]

On Mon, Mar 19, 2007 at 10:49:12AM +0300, Yuriy N. Shkandybin wrote:
> I've changed kernel to rc4 and completely changed hardware.
> Now this is
> 
> I've got new trace, but this is another problem as i can see and connected 
> with pppoe
> 
> =======================================================
> [ INFO: possible circular locking dependency detected ]
> 2.6.21-rc4 #1
> -------------------------------------------------------
> pppd/8926 is trying to acquire lock:
> (&vlan_netdev_xmit_lock_key){-...}, at: [<c0265486>] 
> dev_queue_xmit+0x247/0x2f1
> 
> but task is already holding lock:
> (&pch->downl){-+..}, at: [<c0230c72>] ppp_channel_push+0x19/0x9a
> 
> which lock already depends on the new lock.
> 
> 
> the existing dependency chain (in reverse order) is:
> 
> -> #3 (&pch->downl){-+..}:
>       [<c013642b>] __lock_acquire+0xe62/0x1010
>       [<c0136642>] lock_acquire+0x69/0x83
>       [<c02afc13>] _spin_lock_bh+0x30/0x3d
>       [<c022f715>] ppp_push+0x5a/0x9a
>       [<c022fb40>] ppp_xmit_process+0x2e/0x511
>       [<c0231a05>] ppp_write+0xb8/0xf2
>       [<c015ec26>] vfs_write+0x7f/0xba
>       [<c015f158>] sys_write+0x3d/0x64
>       [<c01027de>] sysenter_past_esp+0x5f/0x99
>       [<ffffffff>] 0xffffffff
> 
> -> #2 (&ppp->wlock){-+..}:
>       [<c013642b>] __lock_acquire+0xe62/0x1010
>       [<c0136642>] lock_acquire+0x69/0x83
>       [<c02afc13>] _spin_lock_bh+0x30/0x3d
>       [<c022fb2b>] ppp_xmit_process+0x19/0x511
>       [<c02318d3>] ppp_start_xmit+0x18a/0x204
>       [<c0263a6f>] dev_hard_start_xmit+0x1f6/0x2c4
>       [<c026ded3>] __qdisc_run+0x81/0x1bc
>       [<c026549e>] dev_queue_xmit+0x25f/0x2f1
>       [<c027c75f>] ip_output+0x1be/0x25f
>       [<c02788ce>] ip_forward+0x159/0x22b
>       [<c027745c>] ip_rcv+0x297/0x4dd
>       [<c0263698>] netif_receive_skb+0x164/0x1f2
>       [<c022199d>] e1000_clean_rx_irq+0x12a/0x4b7
>       [<c02209bc>] e1000_clean+0x3ff/0x5dd
>       [<c0265084>] net_rx_action+0x7d/0x12b
>       [<c011e442>] __do_softirq+0x82/0xf2
>       [<c011e509>] do_softirq+0x57/0x59
>       [<c011e877>] irq_exit+0x7f/0x81
>       [<c0105011>] do_IRQ+0x45/0x84
>       [<c0103252>] common_interrupt+0x2e/0x34
>       [<c0100b66>] mwait_idle+0x12/0x14
>       [<c0100c60>] cpu_idle+0x6c/0x86
>       [<c01001cd>] rest_init+0x23/0x36
>       [<c0377d89>] start_kernel+0x3ca/0x461
>       [<00000000>] 0x0
>       [<ffffffff>] 0xffffffff
> 
> -> #1 (&dev->_xmit_lock){-+..}:
>       [<c013642b>] __lock_acquire+0xe62/0x1010
>       [<c0136642>] lock_acquire+0x69/0x83
>       [<c02afc13>] _spin_lock_bh+0x30/0x3d
>       [<c0266861>] dev_mc_add+0x34/0x16a
>       [<c02ab5c7>] vlan_dev_set_multicast_list+0x88/0x25c
>       [<c0266592>] __dev_mc_upload+0x22/0x24
>       [<c0266914>] dev_mc_add+0xe7/0x16a
>       [<c029f323>] igmp_group_added+0xe6/0xeb
>       [<c029f50b>] ip_mc_inc_group+0x13f/0x210
>       [<c029f5fa>] ip_mc_up+0x1e/0x61
>       [<c029ab81>] inetdev_event+0x154/0x2c7
>       [<c0125a46>] notifier_call_chain+0x2c/0x39
>       [<c0125a7c>] raw_notifier_call_chain+0x8/0xa
>       [<c026477a>] dev_open+0x6d/0x71
>       [<c0263028>] dev_change_flags+0x51/0x101
>       [<c029b7ca>] devinet_ioctl+0x4df/0x644
>       [<c029bc03>] inet_ioctl+0x5c/0x6f
>       [<c02596e0>] sock_ioctl+0x4f/0x1e8
>       [<c0168c32>] do_ioctl+0x22/0x71
>       [<c0168cd6>] vfs_ioctl+0x55/0x27e
>       [<c0168f32>] sys_ioctl+0x33/0x51
>       [<c01027de>] sysenter_past_esp+0x5f/0x99
>       [<ffffffff>] 0xffffffff
> 
> -> #0 (&vlan_netdev_xmit_lock_key){-...}:
>       [<c0136289>] __lock_acquire+0xcc0/0x1010
>       [<c0136642>] lock_acquire+0x69/0x83
>       [<c02afbd6>] _spin_lock+0x2b/0x38
>       [<c0265486>] dev_queue_xmit+0x247/0x2f1
>       [<c02334f6>] __pppoe_xmit+0x1a9/0x215
>       [<c023356c>] pppoe_xmit+0xa/0xc
>       [<c0230c9a>] ppp_channel_push+0x41/0x9a
>       [<c0231a13>] ppp_write+0xc6/0xf2
>       [<c015ec26>] vfs_write+0x7f/0xba
>       [<c015f158>] sys_write+0x3d/0x64
>       [<c01027de>] sysenter_past_esp+0x5f/0x99
>       [<ffffffff>] 0xffffffff
> 
> other info that might help us debug this:
> 
> 1 lock held by pppd/8926:
> #0:  (&pch->downl){-+..}, at: [<c0230c72>] ppp_channel_push+0x19/0x9a
> 
> stack backtrace:
> [<c0103834>] show_trace_log_lvl+0x1a/0x30
> [<c0103f16>] show_trace+0x12/0x14
> [<c0103f9d>] dump_stack+0x16/0x18
> [<c01343cd>] print_circular_bug_tail+0x68/0x71
> [<c0136289>] __lock_acquire+0xcc0/0x1010
> [<c0136642>] lock_acquire+0x69/0x83
> [<c02afbd6>] _spin_lock+0x2b/0x38
> [<c0265486>] dev_queue_xmit+0x247/0x2f1
> [<c02334f6>] __pppoe_xmit+0x1a9/0x215
> [<c023356c>] pppoe_xmit+0xa/0xc
> [<c0230c9a>] ppp_channel_push+0x41/0x9a
> [<c0231a13>] ppp_write+0xc6/0xf2
> [<c015ec26>] vfs_write+0x7f/0xba
> [<c015f158>] sys_write+0x3d/0x64
> [<c01027de>] sysenter_past_esp+0x5f/0x99
> =======================
> Clocksource tsc unstable (delta = 4686844667 ns)
> Time: acpi_pm clocksource has been installed.
...

lockdep has seen locks "-> #0" - "-> #3" taken in circular
order, but IMHO, lock "-> #3" (&pch->downl) taken after
"-> #2" (&ppp->wlock) differs from &pch->downl lock taken in
"-> #0" (before &vlan_netdev_xmit_lock_key) and lockdep
should be notified about this.

This patch proposal needs confirmation by some PPP expert
that channels processed in ppp_channel_push() differ from
channels processed in ppp_xmit_process(), so the same channel
cannot be processed by turns with both these functions.

I also hope Yuriy could test this patch (this should apply to
2.6.21-rc4 or later, CONFIG_PROVE_LOCKING = y), thanks.

Reported & tested by: "Yuriy N. Shkandybin" <jura@netams.com>
Signed-off-by: Jarek Poplawski <jarkao2@o2.pl>

(don't apply without above mentioned acks)
---

diff -Nurp 2.6.21-rc5-git1-/drivers/net/ppp_generic.c 2.6.21-rc5-git1/drivers/net/ppp_generic.c
--- 2.6.21-rc5-git1-/drivers/net/ppp_generic.c	2007-03-27 20:24:30.000000000 +0200
+++ 2.6.21-rc5-git1/drivers/net/ppp_generic.c	2007-03-27 20:34:44.000000000 +0200
@@ -1435,7 +1435,8 @@ ppp_channel_push(struct channel *pch)
 	struct sk_buff *skb;
 	struct ppp *ppp;
 
-	spin_lock_bh(&pch->downl);
+	local_bh_disable();
+	spin_lock_nested(&pch->downl, SINGLE_DEPTH_NESTING);
 	if (pch->chan != 0) {
 		while (!skb_queue_empty(&pch->file.xq)) {
 			skb = skb_dequeue(&pch->file.xq);
@@ -1449,7 +1450,8 @@ ppp_channel_push(struct channel *pch)
 		/* channel got deregistered */
 		skb_queue_purge(&pch->file.xq);
 	}
-	spin_unlock_bh(&pch->downl);
+	spin_unlock(&pch->downl);
+	local_bh_enable();
 	/* see if there is anything from the attached unit to be sent */
 	if (skb_queue_empty(&pch->file.xq)) {
 		read_lock_bh(&pch->upl);