forcedeth: lockdep warning on ethtool -s

From: Tobias Diedrich
Date: Sun Jun 01 2008 - 04:37:50 EST


Hi,

After enabling CONFIG_LOCKDEP and CONFIG_PROVE_LOCKING I get the
following warning when ethtool -s is first called on one of the
forcedeth ports:

=================================
[ INFO: inconsistent lock state ]
2.6.26-rc4 #28
---------------------------------
inconsistent {in-hardirq-W} -> {hardirq-on-W} usage.
ethtool/1985 [HC0[0]:SC0[1]:HE1:SE0] takes:
(&np->lock){++..}, at: [<ffffffffa000c5fd>] nv_set_settings+0xc8/0x3de [forcedeth]
{in-hardirq-W} state was registered at:
[<ffffffffffffffff>] 0xffffffffffffffff
irq event stamp: 3606
hardirqs last enabled at (3605): [<ffffffff8068106f>] _spin_unlock_irqrestore+0x3f/0x68
hardirqs last disabled at (3604): [<ffffffff80680d38>] _spin_lock_irqsave+0x13/0x46
softirqs last enabled at (3534): [<ffffffff80246ba5>] __do_softirq+0xbc/0xc5
softirqs last disabled at (3606): [<ffffffff80680b33>] _spin_lock_bh+0x11/0x41

other info that might help us debug this:
2 locks held by ethtool/1985:
#0: (rtnl_mutex){--..}, at: [<ffffffff80596072>] rtnl_lock+0x12/0x14
#1: (_xmit_ETHER){-+..}, at: [<ffffffffa000c5e8>] nv_set_settings+0xb3/0x3de [forcedeth]

stack backtrace:
Pid: 1985, comm: ethtool Not tainted 2.6.26-rc4 #28

Call Trace:
[<ffffffff8025f190>] print_usage_bug+0x162/0x173
[<ffffffff8025fa8b>] mark_lock+0x231/0x41f
[<ffffffff802607cf>] __lock_acquire+0x4e7/0xcac
[<ffffffff8025fe64>] ? trace_hardirqs_on+0xf1/0x115
[<ffffffff80272c3a>] ? disable_irq_nosync+0x6f/0x7b
[<ffffffff80261375>] lock_acquire+0x55/0x6e
[<ffffffffa000c5fd>] ? :forcedeth:nv_set_settings+0xc8/0x3de
[<ffffffff80680b15>] _spin_lock+0x2f/0x3c
[<ffffffffa000c5fd>] :forcedeth:nv_set_settings+0xc8/0x3de
[<ffffffff8058f8bb>] dev_ethtool+0x186/0xea3
[<ffffffff8067f446>] ? mutex_lock_nested+0x243/0x275
[<ffffffff8025df2b>] ? debug_mutex_free_waiter+0x46/0x4a
[<ffffffff8067f469>] ? mutex_lock_nested+0x266/0x275
[<ffffffff8058e1ce>] dev_ioctl+0x4eb/0x600
[<ffffffff8068106f>] ? _spin_unlock_irqrestore+0x3f/0x68
[<ffffffff80580f91>] sock_ioctl+0x1f5/0x202
[<ffffffff802a322e>] vfs_ioctl+0x2a/0x77
[<ffffffff802a34d6>] do_vfs_ioctl+0x25b/0x270
[<ffffffff806807b6>] ? trace_hardirqs_on_thunk+0x35/0x3a
[<ffffffff802a352d>] sys_ioctl+0x42/0x65
[<ffffffff8021fffb>] system_call_after_swapgs+0x7b/0x80


I think this is caused by the following snippet in nv_set_settings:

netif_carrier_off(dev);
if (netif_running(dev)) {
nv_disable_irq(dev);
netif_tx_lock_bh(dev);
spin_lock(&np->lock);
/* stop engines */
nv_stop_rxtx(dev);
spin_unlock(&np->lock);
netif_tx_unlock_bh(dev);
}


Because of nv_disable_irq this is probably not really a problem
though (I guess) and replacing the spin_lock with spin_lock_irqsave
could keep interrupts disabled for a longer period of time because
of delays in nv_stop_rx and nv_stop_tx.

--
Tobias PGP: http://9ac7e0bc.uguu.de
ããããããååååçãããããããäããããããã
--
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/