2.6.17-mm5 -- inconsistent {in-softirq-W} -> {softirq-on-W} usage.

2.6.17-mm5 -- inconsistent {in-softirq-W} -> {softirq-on-W} usage.

[Miles Lane]

[ INFO: inconsistent lock state ]
---------------------------------
inconsistent {in-softirq-W} -> {softirq-on-W} usage.
modprobe/2881 [HC0[0]:SC0[0]:HE1:SE1] takes:
 (&dev->_xmit_lock){-+..}, at: [<c11ad5cb>] netpoll_send_skb+0x79/0xea
{in-softirq-W} state was registered at:
  [<c102d152>] lock_acquire+0x60/0x80
  [<c1200376>] _spin_lock+0x23/0x32
  [<c11af282>] dev_watchdog+0x14/0xb1
  [<c101dab2>] run_timer_softirq+0xf2/0x14a
  [<c101a691>] __do_softirq+0x55/0xb0
  [<c1004a8d>] do_softirq+0x58/0xbd
irq event stamp: 3780
hardirqs last  enabled at (3779): [<c1200800>] _spin_unlock_irqrestore+0x36/0x59
hardirqs last disabled at (3780): [<c1200581>] _spin_lock_irqsave+0xf/0x3c
softirqs last  enabled at (3544): [<c101a6e7>] __do_softirq+0xab/0xb0
softirqs last disabled at (3535): [<c1004a8d>] do_softirq+0x58/0xbd

other info that might help us debug this:
1 lock held by modprobe/2881:
 #0:  (&dev->_xmit_lock){-+..}, at: [<c11ad5cb>] netpoll_send_skb+0x79/0xea

stack backtrace:
 [<c1003502>] show_trace_log_lvl+0x54/0xfd
 [<c1003b6a>] show_trace+0xd/0x10
 [<c1003c0e>] dump_stack+0x19/0x1b
 [<c102b7c7>] print_usage_bug+0x1cc/0x1d9
 [<c102bd71>] mark_lock+0x23c/0x360
 [<c102bedc>] mark_held_locks+0x47/0x65
 [<c102bfe9>] trace_hardirqs_on+0xef/0x119
 [<c1200845>] _spin_unlock_irq+0x22/0x43
 [<f9099d31>] rtl8139_start_xmit+0xd9/0xff [8139too]
 [<c11ad5ea>] netpoll_send_skb+0x98/0xea
 [<c11ae2ef>] netpoll_send_udp+0x1e8/0x1f1
 [<f93160cd>] write_msg+0x40/0x67 [netconsole]
 [<c1015e8d>] __call_console_drivers+0x45/0x51
 [<c1015ee7>] _call_console_drivers+0x4e/0x52
 [<c1016003>] release_console_sem+0x118/0x1ed
 [<c1016364>] register_console+0x190/0x197
 [<f9316079>] init_netconsole+0x60/0x74 [netconsole]
 [<c1033794>] sys_init_module+0x12cc/0x14b1
 [<c1002d6d>] sysenter_past_esp+0x56/0x8d
netconsole: network logging started

Re: 2.6.17-mm5 -- inconsistent {in-softirq-W} -> {softirq-on-W} usage.

[Arjan van de Ven]

> stack backtrace:

>  [<f9099d31>] rtl8139_start_xmit+0xd9/0xff [8139too]
>  [<c11ad5ea>] netpoll_send_skb+0x98/0xea

This seems to be a real deadlock...

So netpoll_send_skb takes the _xmit_lock, which is all nitty gritty
but then rtl8139_start_xmit comes around while that lock is taken, and
does

      spin_unlock_irq(&tp->lock);

which.. enables interrupts and softirqs; this is quite bad because the
xmit lock is taken in softirq context for the watchdog like this:
  [<c1200376>] _spin_lock+0x23/0x32
  [<c11af282>] dev_watchdog+0x14/0xb1
  [<c101dab2>] run_timer_softirq+0xf2/0x14a
  [<c101a691>] __do_softirq+0x55/0xb0
  [<c1004a8d>] do_softirq+0x58/0xbd

Which would deadlock now that the spin_unlock_irq() has enabled
irqs/softirqs while the _xmit_lock is still held.


The patch below turns this into a irqsave/irqrestore pair so that
interrupts don't get enabled unconditionally.

Signed-off-by: Arjan van de Ven <arjan@linux.intel.com>

---
 drivers/net/8139too.c |    5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

Index: linux-2.6.17-mm4/drivers/net/8139too.c
===================================================================
--- linux-2.6.17-mm4.orig/drivers/net/8139too.c
+++ linux-2.6.17-mm4/drivers/net/8139too.c
@@ -1710,6 +1710,7 @@ static int rtl8139_start_xmit (struct sk
 	void __iomem *ioaddr = tp->mmio_addr;
 	unsigned int entry;
 	unsigned int len = skb->len;
+	unsigned long flags;
 
 	/* Calculate the next Tx descriptor entry. */
 	entry = tp->cur_tx % NUM_TX_DESC;
@@ -1726,7 +1727,7 @@ static int rtl8139_start_xmit (struct sk
 		return 0;
 	}
 
-	spin_lock_irq(&tp->lock);
+	spin_lock_irqsave(&tp->lock, flags);
 	RTL_W32_F (TxStatus0 + (entry * sizeof (u32)),
 		   tp->tx_flag | max(len, (unsigned int)ETH_ZLEN));
 
@@ -1737,7 +1738,7 @@ static int rtl8139_start_xmit (struct sk
 
 	if ((tp->cur_tx - NUM_TX_DESC) == tp->dirty_tx)
 		netif_stop_queue (dev);
-	spin_unlock_irq(&tp->lock);
+	spin_unlock_irqrestore(&tp->lock, flags);
 
 	if (netif_msg_tx_queued(tp))
 		printk (KERN_DEBUG "%s: Queued Tx packet size %u to slot %d.\n",