2.6.20-git14 rtl8139 possible circular locking dependency detected

2.6.20-git14 rtl8139 possible circular locking dependency detected

[Michal Piotrowski]

Hi,

Feb 17 20:07:09 bitis-gabonica kernel: =======================================================
Feb 17 20:07:09 bitis-gabonica kernel: [ INFO: possible circular locking dependency detected ]
Feb 17 20:07:09 bitis-gabonica kernel: 2.6.20 #54
Feb 17 20:07:09 bitis-gabonica kernel: -------------------------------------------------------
Feb 17 20:07:09 bitis-gabonica kernel: swapper/0 is trying to acquire lock:
Feb 17 20:07:09 bitis-gabonica kernel:  (&mc->mca_lock){-+..}, at: [<fd989a99>] ipv6_chk_mcast_addr+0xbd/0x154 [ipv6]
Feb 17 20:07:09 bitis-gabonica kernel:
Feb 17 20:07:09 bitis-gabonica kernel: but task is already holding lock:
Feb 17 20:07:09 bitis-gabonica kernel:  (&tp->rx_lock){-+..}, at: [<c025ce98>] rtl8139_poll+0x42/0x40d
Feb 17 20:07:09 bitis-gabonica kernel:
Feb 17 20:07:09 bitis-gabonica kernel: which lock already depends on the new lock.
Feb 17 20:07:10 bitis-gabonica kernel:
Feb 17 20:07:10 bitis-gabonica kernel:
Feb 17 20:07:10 bitis-gabonica kernel: the existing dependency chain (in reverse order) is:
Feb 17 20:07:10 bitis-gabonica kernel:
Feb 17 20:07:10 bitis-gabonica kernel: -> #2 (&tp->rx_lock){-+..}:
Feb 17 20:07:10 bitis-gabonica kernel:        [<c013d5cc>] __lock_acquire+0xa12/0xb94
Feb 17 20:07:10 bitis-gabonica kernel:        [<c013d7b6>] lock_acquire+0x68/0x82
Feb 17 20:07:10 bitis-gabonica kernel:        [<c0311277>] _spin_lock+0x35/0x42
Feb 17 20:07:10 bitis-gabonica kernel:        [<c025ce98>] rtl8139_poll+0x42/0x40d
Feb 17 20:07:10 bitis-gabonica kernel:        [<c02d2b53>] netpoll_poll+0x83/0x329
Feb 17 20:07:10 bitis-gabonica kernel:        [<c02d2ebe>] netpoll_send_skb+0xc5/0x12c
Feb 17 20:07:10 bitis-gabonica kernel:        [<c02d3cbc>] netpoll_send_udp+0x244/0x24c
Feb 17 20:07:10 bitis-gabonica kernel:        [<c025dbd5>] write_msg+0x40/0x67
Feb 17 20:07:10 bitis-gabonica kernel:        [<c0121c9e>] __call_console_drivers+0x4e/0x5a
Feb 17 20:07:10 bitis-gabonica kernel:        [<c0121d01>] _call_console_drivers+0x57/0x5b
Feb 17 20:07:10 bitis-gabonica kernel:        [<c0121e5b>] release_console_sem+0x11e/0x1bb
Feb 17 20:07:10 bitis-gabonica kernel:        [<c0122190>] register_console+0x190/0x197
Feb 17 20:07:10 bitis-gabonica kernel:        [<c025db6a>] init_netconsole+0x57/0x69
Feb 17 20:07:10 bitis-gabonica kernel:        [<c0421514>] init+0x11e/0x203
Feb 17 20:07:10 bitis-gabonica kernel:        [<c0104dd3>] kernel_thread_helper+0x7/0x10
Feb 17 20:07:10 bitis-gabonica kernel:        [<ffffffff>] 0xffffffff
Feb 17 20:07:10 bitis-gabonica kernel:
Feb 17 20:07:10 bitis-gabonica kernel: -> #1 (&dev->_xmit_lock){-+..}:
Feb 17 20:07:10 bitis-gabonica kernel:        [<c013d5cc>] __lock_acquire+0xa12/0xb94
Feb 17 20:07:10 bitis-gabonica kernel:        [<c013d7b6>] lock_acquire+0x68/0x82
Feb 17 20:07:10 bitis-gabonica kernel:        [<c03112be>] _spin_lock_bh+0x3a/0x47
Feb 17 20:07:10 bitis-gabonica kernel:        [<c02caba0>] dev_mc_add+0x33/0x142
Feb 17 20:07:10 bitis-gabonica kernel:        [<fd987d88>] igmp6_group_added+0x58/0x120 [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:        [<fd9884f8>] ipv6_dev_mc_inc+0x2b4/0x2ff [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:        [<fd9772e1>] ipv6_add_dev+0x222/0x230 [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:        [<fd97733b>] ipv6_find_idev+0x4c/0x68 [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:        [<fd977397>] addrconf_add_dev+0x40/0x5d [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:        [<fd977d09>] addrconf_notify+0x59e/0x786 [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:        [<c02c80ea>] register_netdevice_notifier+0x43/0x56
Feb 17 20:07:10 bitis-gabonica kernel:        [<fd93c358>] __param_forward+0x2b8/0xffffffca [ip6table_filter]
Feb 17 20:07:10 bitis-gabonica kernel:        [<fd93c1d5>] __param_forward+0x135/0xffffffca [ip6table_filter]
Feb 17 20:07:10 bitis-gabonica kernel:        [<c0144a14>] sys_init_module+0x94/0x13f
Feb 17 20:07:10 bitis-gabonica kernel:        [<c01040da>] sysenter_past_esp+0x5f/0x99
Feb 17 20:07:10 bitis-gabonica kernel:        [<ffffffff>] 0xffffffff
Feb 17 20:07:10 bitis-gabonica kernel:
Feb 17 20:07:10 bitis-gabonica kernel: -> #0 (&mc->mca_lock){-+..}:
Feb 17 20:07:10 bitis-gabonica kernel:        [<c013d4b0>] __lock_acquire+0x8f6/0xb94
Feb 17 20:07:10 bitis-gabonica kernel:        [<c013d7b6>] lock_acquire+0x68/0x82
Feb 17 20:07:10 bitis-gabonica kernel:        [<c03112be>] _spin_lock_bh+0x3a/0x47
Feb 17 20:07:10 bitis-gabonica kernel:        [<fd989a99>] ipv6_chk_mcast_addr+0xbd/0x154 [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:        [<fd97336a>] ip6_input+0x192/0x362 [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:        [<fd973599>] ip6_mc_input+0x5f/0x6d [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:        [<fd973baa>] ipv6_rcv+0x2cd/0x36f [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:        [<c02c7b43>] netif_receive_skb+0x1a0/0x230
Feb 17 20:07:10 bitis-gabonica kernel:        [<c025d108>] rtl8139_poll+0x2b2/0x40d
Feb 17 20:07:10 bitis-gabonica kernel:        [<c02c97d0>] net_rx_action+0x9f/0x192
Feb 17 20:07:10 bitis-gabonica kernel:        [<c0126568>] __do_softirq+0x6d/0xea
Feb 17 20:07:10 bitis-gabonica kernel:        [<c0106ab9>] do_softirq+0x64/0xd1
Feb 17 20:07:10 bitis-gabonica kernel:        [<ffffffff>] 0xffffffff
Feb 17 20:07:10 bitis-gabonica kernel:
Feb 17 20:07:10 bitis-gabonica kernel: other info that might help us debug this:
Feb 17 20:07:10 bitis-gabonica kernel:
Feb 17 20:07:10 bitis-gabonica kernel: 3 locks held by swapper/0:
Feb 17 20:07:10 bitis-gabonica kernel:  #0:  (&npinfo->poll_lock){-+..}, at: [<c02c97a8>] net_rx_action+0x77/0x192
Feb 17 20:07:10 bitis-gabonica kernel:  #1:  (&tp->rx_lock){-+..}, at: [<c025ce98>] rtl8139_poll+0x42/0x40d
Feb 17 20:07:10 bitis-gabonica kernel:  #2:  (&ndev->lock){-.-+}, at: [<fd989a3b>] ipv6_chk_mcast_addr+0x5f/0x154 [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:
Feb 17 20:07:10 bitis-gabonica kernel: stack backtrace:
Feb 17 20:07:10 bitis-gabonica kernel:  [<c010513d>] show_trace_log_lvl+0x1a/0x2f
Feb 17 20:07:10 bitis-gabonica kernel:  [<c0105824>] show_trace+0x12/0x14
Feb 17 20:07:10 bitis-gabonica kernel:  [<c01058d6>] dump_stack+0x16/0x18
Feb 17 20:07:10 bitis-gabonica kernel:  [<c013bcc5>] print_circular_bug_tail+0x5f/0x68
Feb 17 20:07:10 bitis-gabonica kernel:  [<c013d4b0>] __lock_acquire+0x8f6/0xb94
Feb 17 20:07:10 bitis-gabonica kernel:  [<c013d7b6>] lock_acquire+0x68/0x82
Feb 17 20:07:10 bitis-gabonica kernel:  [<c03112be>] _spin_lock_bh+0x3a/0x47
Feb 17 20:07:10 bitis-gabonica kernel:  [<fd989a99>] ipv6_chk_mcast_addr+0xbd/0x154 [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:  [<fd97336a>] ip6_input+0x192/0x362 [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:  [<fd973599>] ip6_mc_input+0x5f/0x6d [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:  [<fd973baa>] ipv6_rcv+0x2cd/0x36f [ipv6]
Feb 17 20:07:10 bitis-gabonica kernel:  [<c02c7b43>] netif_receive_skb+0x1a0/0x230
Feb 17 20:07:10 bitis-gabonica kernel:  [<c025d108>] rtl8139_poll+0x2b2/0x40d
Feb 17 20:07:10 bitis-gabonica kernel:  [<c02c97d0>] net_rx_action+0x9f/0x192
Feb 17 20:07:10 bitis-gabonica kernel:  [<c0126568>] __do_softirq+0x6d/0xea
Feb 17 20:07:10 bitis-gabonica kernel:  [<c0106ab9>] do_softirq+0x64/0xd1
Feb 17 20:07:10 bitis-gabonica kernel:  =======================

0xc02c97a8 is in net_rx_action (/mnt/md0/devel/linux-git/include/linux/netpoll.h:72).
67      static inline void *netpoll_poll_lock(struct net_device *dev)
68      {
69              rcu_read_lock(); /* deal with race on ->npinfo */
70              if (dev->npinfo) {
71                      spin_lock(&dev->npinfo->poll_lock);
72                      dev->npinfo->poll_owner = smp_processor_id();
73                      return dev->npinfo;
74              }
75              return NULL;
76      }

0xc025ce98 is in rtl8139_poll (/mnt/md0/devel/linux-git/drivers/net/8139too.c:2122).
2117            void __iomem *ioaddr = tp->mmio_addr;
2118            int orig_budget = min(*budget, dev->quota);
2119            int done = 1;
2120
2121            spin_lock(&tp->rx_lock);
2122            if (likely(RTL_R16(IntrStatus) & RxAckBits)) {
2123                    int work_done;
2124
2125                    work_done = rtl8139_rx(dev, tp, orig_budget);
2126                    if (likely(work_done > 0)) {

http://www.stardust.webpages.pl/files/tbf/euridica/2.6.20-git13/git-config

Regards,
Michal

--
Michal K. K. Piotrowski
LTG - Linux Testers Group (PL)
(http://www.stardust.webpages.pl/ltg/)
LTG - Linux Testers Group (EN)
(http://www.stardust.webpages.pl/linux_testers_group_en/)

Re: 2.6.20-git14 rtl8139 possible circular locking dependency detected

[Francois Romieu]

Michal Piotrowski <michal.k.k.piotrowski@gmail.com> :
[...]

Did you enable RTL8139_DEBUG ?

If so you can try the patch below.

diff --git a/drivers/net/8139too.c b/drivers/net/8139too.c
index 35ad5cf..da61368 100644
--- a/drivers/net/8139too.c
+++ b/drivers/net/8139too.c
@@ -634,7 +634,6 @@ static int rtl8139_close (struct net_dev
 static int netdev_ioctl (struct net_device *dev, struct ifreq *rq, int cmd);
 static struct net_device_stats *rtl8139_get_stats (struct net_device *dev);
 static void rtl8139_set_rx_mode (struct net_device *dev);
-static void __set_rx_mode (struct net_device *dev);
 static void rtl8139_hw_start (struct net_device *dev);
 static void rtl8139_thread (struct work_struct *work);
 static void rtl8139_tx_timeout_task(struct work_struct *work);
@@ -2497,10 +2496,11 @@ static struct net_device_stats *rtl8139_
 	return &tp->stats;
 }
 
-/* Set or clear the multicast filter for this adaptor.
-   This routine is not state sensitive and need not be SMP locked. */
-
-static void __set_rx_mode (struct net_device *dev)
+/*
+ * Set or clear the multicast filter for this adaptor.
+ * This routine is not state sensitive and need not be SMP locked.
+ */
+static void rtl8139_set_rx_mode (struct net_device *dev)
 {
 	struct rtl8139_private *tp = netdev_priv(dev);
 	void __iomem *ioaddr = tp->mmio_addr;
@@ -2545,16 +2545,6 @@ static void __set_rx_mode (struct net_de
 	RTL_W32_F (MAR0 + 4, mc_filter[1]);
 }
 
-static void rtl8139_set_rx_mode (struct net_device *dev)
-{
-	unsigned long flags;
-	struct rtl8139_private *tp = netdev_priv(dev);
-
-	spin_lock_irqsave (&tp->lock, flags);
-	__set_rx_mode(dev);
-	spin_unlock_irqrestore (&tp->lock, flags);
-}
-
 #ifdef CONFIG_PM
 
 static int rtl8139_suspend (struct pci_dev *pdev, pm_message_t state)

netpoll again ? (was: Re: 2.6.20-git14 rtl8139 possible circular locking dependency detected)

[Francois Romieu]

Francois Romieu <romieu@fr.zoreil.com> :
> Michal Piotrowski <michal.k.k.piotrowski@gmail.com> :
> [...]
> 
> Did you enable RTL8139_DEBUG ?
> 
> If so you can try the patch below.

It's buggy there too but you are not experiencing this one.

1 - netpoll() calls the poll() handler of the device through netpoll_poll()
2 - The poll handler of the device tries to acquire dev->_xmit_lock
    through dev_mc_add during the Rx protocol processing
3 - netpoll() holds dev->_xmit_lock to avoid recursion in netpoll_poll()

#2 and #3 have opposite requirements.

-- 
Ueimor

Re: 2.6.20-git14 rtl8139 possible circular locking dependency detected

[Michal Piotrowski]

On 17/02/07, Francois Romieu <romieu@fr.zoreil.com> wrote:
> Michal Piotrowski <michal.k.k.piotrowski@gmail.com> :
> [...]
>
> Did you enable RTL8139_DEBUG ?
>
> If so you can try the patch below.
>

I enabled debugging
#define RTL8139_DEBUG 3

Here is a full log
http://www.stardust.webpages.pl/files/tbf/bitis-gabonica/2.6.20-git14/bug.txt
http://www.stardust.webpages.pl/files/tbf/bitis-gabonica/2.6.20-git14/git-config

Regards,
Michal

-- 
Michal K. K. Piotrowski
LTG - Linux Testers Group (PL)
(http://www.stardust.webpages.pl/ltg/)
LTG - Linux Testers Group (EN)
(http://www.stardust.webpages.pl/linux_testers_group_en/)