Re: [BUG] ISIC + 2.6.22 (via-rhine)



Arjan van de Ven wrote:

=================================
[ INFO: inconsistent lock state ]
2.6.22 #1
---------------------------------
inconsistent {in-hardirq-W} -> {hardirq-on-W} usage.
swapper/0 [HC0[0]:SC1[1]:HE1:SE0] takes:
(&rp->lock){++..}, at: [<f8c890db>] rhine_tx_timeout+0x6f/0xf4 [via_rhine]



this is a case of homegrown locking: the via-rhine driver does

/* protect against concurrent rx interrupts */
disable_irq(rp->pdev->irq);

spin_lock(&rp->lock);

/* clear all descriptors */
free_tbufs(dev);
free_rbufs(dev);
alloc_tbufs(dev);
alloc_rbufs(dev);

/* Reinitialize the hardware. */
rhine_chip_reset(dev);
init_registers(dev);

spin_unlock(&rp->lock);
enable_irq(rp->pdev->irq);


as a way to protect code against interrupts... rather than using the
normal mechanism.


the annotation is pretty simple (untested, not even compiled):

--- linux-2.6.22/drivers/net/via-rhine.c.org 2007-07-31 14:22:06.000000000 -0700
+++ linux-2.6.22/drivers/net/via-rhine.c 2007-07-31 14:22:26.000000000 -0700
@@ -1191,7 +1191,7 @@
mdio_read(dev, rp->mii_if.phy_id, MII_BMSR));
/* protect against concurrent rx interrupts */
- disable_irq(rp->pdev->irq);
+ disable_irq_lockdep(rp->pdev->irq);
spin_lock(&rp->lock);
@@ -1206,7 +1206,7 @@
init_registers(dev);
spin_unlock(&rp->lock);
- enable_irq(rp->pdev->irq);
+ enable_irq_lockdep(rp->pdev->irq);
dev->trans_start = jiffies;
rp->stats.tx_errors++;

thanks Arjan. Patch applied and now I get:

NETDEV WATCHDOG: eth0: transmit timed out
eth0: Transmit timed out, status 0000, PHY status 786d, resetting...

======================================================
[ INFO: hard-safe -> hard-unsafe lock order detected ]
2.6.22 #1
------------------------------------------------------
swapper/0 [HC0[0]:SC1[1]:HE0:SE0] is trying to acquire:
(af_callback_keys + sk->sk_family#3){-.-?}, at: [<c05ab7d3>] sock_def_write_space+0x18/0x96

and this task is already holding:
(&rp->lock){++..}, at: [<f8d0a0e1>] rhine_tx_timeout+0x75/0x102 [via_rhine]
which would create a new lock dependency:
(&rp->lock){++..} -> (af_callback_keys + sk->sk_family#3){-.-?}

but this new dependency connects a hard-irq-safe lock:
(&rp->lock){++..}
... which became hard-irq-safe at:
[<c04440d4>] __lock_acquire+0x38c/0xb12
[<c0444c1b>] lock_acquire+0x56/0x6f
[<c0615279>] _spin_lock+0x2b/0x38
[<f8d08b49>] rhine_interrupt+0x16b/0x69b [via_rhine]
[<c045aac6>] handle_IRQ_event+0x1a/0x46
[<c045bbc0>] handle_fasteoi_irq+0x7d/0xb6
[<c0407089>] do_IRQ+0xb1/0xd8
[<ffffffff>] 0xffffffff

to a hard-irq-unsafe lock:
(af_callback_keys + sk->sk_family#3){-.-?}
... which became hard-irq-unsafe at:
... [<c0444144>] __lock_acquire+0x3fc/0xb12
[<c0444c1b>] lock_acquire+0x56/0x6f
[<c061532b>] _write_lock_bh+0x30/0x3d
[<c05d829e>] tcp_close+0x24e/0x531
[<c05f1175>] inet_release+0x43/0x49
[<c05a85d4>] sock_release+0x17/0x62
[<c05a89fb>] sock_close+0x2d/0x33
[<c047db0f>] __fput+0xbe/0x168
[<c047dbd0>] fput+0x17/0x19
[<c047b4b5>] filp_close+0x54/0x5c
[<c047c444>] sys_close+0x78/0xb0
[<c0404e26>] sysenter_past_esp+0x5f/0x99
[<ffffffff>] 0xffffffff

other info that might help us debug this:

2 locks held by swapper/0:
#0: (_xmit_ETHER){-+..}, at: [<c05c042a>] dev_watchdog+0x14/0xbf
#1: (&rp->lock){++..}, at: [<f8d0a0e1>] rhine_tx_timeout+0x75/0x102 [via_rhine]

the hard-irq-safe lock's dependencies:
-> (&rp->lock){++..} ops: 0 {
initial-use at:
[<c044417d>] __lock_acquire+0x435/0xb12
[<c0444c1b>] lock_acquire+0x56/0x6f
[<c06155af>] _spin_lock_irqsave+0x34/0x44
[<f8d0a19b>] rhine_get_stats+0x2d/0x9d [via_rhine]
[<c05b9017>] rtnl_fill_ifinfo+0x2e9/0x414
[<c05b9547>] rtmsg_ifinfo+0x57/0xd4
[<c05b95fc>] rtnetlink_event+0x38/0x3c
[<c0616f9e>] notifier_call_chain+0x2b/0x4a
[<c0433984>] __raw_notifier_call_chain+0x19/0x1e
[<c04339a3>] raw_notifier_call_chain+0x1a/0x1c
[<c05b14a3>] register_netdevice+0x335/0x33f
[<c05b27d6>] register_netdev+0x40/0x4d
[<f8d09d07>] rhine_init_one+0x515/0x6c7 [via_rhine]
[<c04f8085>] pci_device_probe+0x39/0x5b
[<c055cffc>] driver_probe_device+0xe9/0x16a
[<c055d1a6>] __driver_attach+0x76/0xaf
[<c055c4ec>] bus_for_each_dev+0x3a/0x5f
[<c055ce47>] driver_attach+0x19/0x1b
[<c055c80a>] bus_add_driver+0x79/0x181
[<c055d3a1>] driver_register+0x67/0x6c
[<c04f81dd>] __pci_register_driver+0x56/0x83
[<f885f06c>] 0xf885f06c
[<c044b77f>] sys_init_module+0x1579/0x16ca
[<c0404e26>] sysenter_past_esp+0x5f/0x99
[<ffffffff>] 0xffffffff
in-hardirq-W at:
[<c04440d4>] __lock_acquire+0x38c/0xb12
[<c0444c1b>] lock_acquire+0x56/0x6f
[<c0615279>] _spin_lock+0x2b/0x38
[<f8d08b49>] rhine_interrupt+0x16b/0x69b [via_rhine]
[<c045aac6>] handle_IRQ_event+0x1a/0x46
[<c045bbc0>] handle_fasteoi_irq+0x7d/0xb6
[<c0407089>] do_IRQ+0xb1/0xd8
[<ffffffff>] 0xffffffff
in-softirq-W at:
[<c04440f5>] __lock_acquire+0x3ad/0xb12
[<c0444c1b>] lock_acquire+0x56/0x6f
[<c06154e4>] _spin_lock_irq+0x31/0x3e
[<f8d0a68e>] rhine_start_tx+0x1b2/0x24a [via_rhine]
[<c05b21e9>] dev_hard_start_xmit+0x1ea/0x247
[<c05c0344>] __qdisc_run+0xc9/0x19b
[<c05b3ce0>] dev_queue_xmit+0x157/0x26b
[<f8fa81ed>] mld_sendpack+0x210/0x35a [ipv6]
[<f8fa8eb8>] mld_ifc_timer_expire+0x1e9/0x211 [ipv6]
[<c04303be>] run_timer_softirq+0x11a/0x182
[<c042d1fe>] __do_softirq+0x6f/0xe9
[<c0406f72>] do_softirq+0x61/0xc7
[<ffffffff>] 0xffffffff
}
... key at: [<f8d0f200>] __key.22744+0x0/0xffffb5f3 [via_rhine]

the hard-irq-unsafe lock's dependencies:
-> (af_callback_keys + sk->sk_family#3){-.-?} ops: 0 {
initial-use at:
[<c044417d>] __lock_acquire+0x435/0xb12
[<c0444c1b>] lock_acquire+0x56/0x6f
[<c061532b>] _write_lock_bh+0x30/0x3d
[<c05d829e>] tcp_close+0x24e/0x531
[<c05f1175>] inet_release+0x43/0x49
[<c05a85d4>] sock_release+0x17/0x62
[<c05a89fb>] sock_close+0x2d/0x33
[<c047db0f>] __fput+0xbe/0x168
[<c047dbd0>] fput+0x17/0x19
[<c047b4b5>] filp_close+0x54/0x5c
[<c047c444>] sys_close+0x78/0xb0
[<c0404e26>] sysenter_past_esp+0x5f/0x99
[<ffffffff>] 0xffffffff
hardirq-on-W at:
[<c0444144>] __lock_acquire+0x3fc/0xb12
[<c0444c1b>] lock_acquire+0x56/0x6f
[<c061532b>] _write_lock_bh+0x30/0x3d
[<c05d829e>] tcp_close+0x24e/0x531
[<c05f1175>] inet_release+0x43/0x49
[<c05a85d4>] sock_release+0x17/0x62
[<c05a89fb>] sock_close+0x2d/0x33
[<c047db0f>] __fput+0xbe/0x168
[<c047dbd0>] fput+0x17/0x19
[<c047b4b5>] filp_close+0x54/0x5c
[<c047c444>] sys_close+0x78/0xb0
[<c0404e26>] sysenter_past_esp+0x5f/0x99
[<ffffffff>] 0xffffffff
in-softirq-R at:
[<c04440f5>] __lock_acquire+0x3ad/0xb12
[<c0444c1b>] lock_acquire+0x56/0x6f
[<c06153de>] _read_lock+0x2b/0x38
[<c05ab765>] sock_def_readable+0x18/0x6e
[<c05abca3>] sock_queue_rcv_skb+0xe1/0x102
[<c05ead1f>] udp_queue_rcv_skb+0x2d8/0x383
[<c05eb23b>] __udp4_lib_rcv+0x471/0x73a
[<c05eb516>] udp_rcv+0x12/0x14
[<c05cda19>] ip_local_deliver+0x187/0x232
[<c05cd85a>] ip_rcv+0x490/0x4c8
[<c05b1bc2>] netif_receive_skb+0x2ce/0x33e
[<c05b389b>] process_backlog+0x8b/0xec
[<c05b3a86>] net_rx_action+0x9b/0x19e
[<c042d1fe>] __do_softirq+0x6f/0xe9
[<c0406f72>] do_softirq+0x61/0xc7
[<ffffffff>] 0xffffffff
softirq-on-R at:
[<c0444168>] __lock_acquire+0x420/0xb12
[<c0444c1b>] lock_acquire+0x56/0x6f
[<c06153de>] _read_lock+0x2b/0x38
[<c05ab7d3>] sock_def_write_space+0x18/0x96
[<c05aae32>] sock_setsockopt+0x11b/0x4d4
[<c05a7e9d>] sys_setsockopt+0x61/0x97
[<c05a9513>] sys_socketcall+0x1e8/0x241
[<c0404e26>] sysenter_past_esp+0x5f/0x99
[<ffffffff>] 0xffffffff
hardirq-on-R at:
[<c0444119>] __lock_acquire+0x3d1/0xb12
[<c0444c1b>] lock_acquire+0x56/0x6f
[<c06153de>] _read_lock+0x2b/0x38
[<c05ab7d3>] sock_def_write_space+0x18/0x96
[<c05abbad>] sock_wfree+0x27/0x3c
[<c0562b18>] loopback_xmit+0x12/0x66
[<c05b21e9>] dev_hard_start_xmit+0x1ea/0x247
[<c05b3d48>] dev_queue_xmit+0x1bf/0x26b
[<c05b854d>] neigh_resolve_output+0x1f7/0x22c
[<c05d25e6>] ip_output+0x287/0x2b5
[<c05cfd04>] ip_push_pending_frames+0x2f9/0x3ba
[<c05ea8aa>] udp_push_pending_frames+0x2c7/0x2e9
[<c05eba55>] udp_sendmsg+0x455/0x580
[<c05f0b8f>] inet_sendmsg+0x3e/0x49
[<c05a834f>] sock_sendmsg+0xe7/0x104
[<c05a8c26>] sys_sendto+0xcc/0xec
[<c05a8c7c>] sys_send+0x36/0x38
[<c05a9469>] sys_socketcall+0x13e/0x241
[<c0404e26>] sysenter_past_esp+0x5f/0x99
[<ffffffff>] 0xffffffff
}
... key at: [<c0a2dfd0>] af_callback_keys+0x10/0x110

stack backtrace:
[<c0405e6a>] show_trace_log_lvl+0x1a/0x2f
[<c04068cf>] show_trace+0x12/0x14
[<c0406928>] dump_stack+0x16/0x18
[<c0443cb4>] check_usage+0x258/0x262
[<c04445ee>] __lock_acquire+0x8a6/0xb12
[<c0444c1b>] lock_acquire+0x56/0x6f
[<c06153de>] _read_lock+0x2b/0x38
[<c05ab7d3>] sock_def_write_space+0x18/0x96
[<c05abbad>] sock_wfree+0x27/0x3c
[<c05ad393>] __kfree_skb+0xa6/0xfc
[<c05ad417>] kfree_skb+0x2e/0x30
[<f8d084dd>] free_tbufs+0x3f/0x66 [via_rhine]
[<f8d0a0e8>] rhine_tx_timeout+0x7c/0x102 [via_rhine]
[<c05c048c>] dev_watchdog+0x76/0xbf
[<c04303be>] run_timer_softirq+0x11a/0x182
[<c042d1fe>] __do_softirq+0x6f/0xe9
[<c0406f72>] do_softirq+0x61/0xc7
=======================
eth0: link up, 100Mbps, full-duplex, lpa 0x45E1
NETDEV WATCHDOG: eth0: transmit timed out
eth0: Transmit timed out, status 0000, PHY status 786d, resetting...
eth0: link up, 100Mbps, full-duplex, lpa 0x45E1
NETDEV WATCHDOG: eth0: transmit timed out
eth0: Transmit timed out, status 0000, PHY status 786d, resetting...
eth0: link up, 100Mbps, full-duplex, lpa 0x45E1
NETDEV WATCHDOG: eth0: transmit timed out
eth0: Transmit timed out, status 0000, PHY status 786d, resetting...
eth0: link up, 100Mbps, full-duplex, lpa 0x45E1
NETDEV WATCHDOG: eth0: transmit timed out
eth0: Transmit timed out, status 0000, PHY status 786d, resetting...
eth0: link up, 100Mbps, full-duplex, lpa 0x45E1
NETDEV WATCHDOG: eth0: transmit timed out
eth0: Transmit timed out, status 0000, PHY status 786d, resetting...
eth0: link up, 100Mbps, full-duplex, lpa 0x45E1



--
Politicos de mierda, yo no soy un terrorista.
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/



Relevant Pages

  • Re: No IP on boot
    ... While not necessarily the root of your issue, you could drop the HWADDR line and the TYPE line...the fact that the device name is eth0 is pretty much indicative of the type of connection, and the card is going to send it's MAC address, anyhow. ... link up, 100Mbps, full-duplex, lpa 0x41E1 ... eth0: no IPv6 routers present ...
    (RedHat)
  • device eth1 not present?
    ... Determining IP information for eth0... ... Bringing up interface eth1: 8139too device eth1 does not seem to be present, ... Media Link On 100mbps full-duplex ... eth0: no IPv6 routers present ...
    (Fedora)
  • [BUG] ISIC + 2.6.22 (via-rhine)
    ... eth0: link up, 100Mbps, full-duplex, lpa 0x45E1 ... [INFO: inconsistent lock state] ... irq event stamp: 18052892 ...
    (Linux-Kernel)
  • Re: No IP on boot
    ... eth0: ... link up, 100Mbps, full-duplex, lpa 0x41E1 ... eth0: no IPv6 routers present ... On Friday 14 April 2006 14:30, Cesar Covarrubias wrote: ...
    (RedHat)
  • Re: Detecting a network card
    ... eth0: ... link up, 10Mbps, half-duplex, lpa 0x0000 ... and ping may or may ...
    (alt.os.linux)