linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* BUG: scheduling while atomic: ifup-bonding/3711/0x00000002 --  V3.6.7
@ 2012-11-27 20:37 Linda Walsh
  2012-11-28  5:47 ` Cong Wang
  0 siblings, 1 reply; 7+ messages in thread
From: Linda Walsh @ 2012-11-27 20:37 UTC (permalink / raw)
  To: LKML



Is this a known problem / bug, or should I file a bug on it?  
It doesn't cause a complete failure, and it happens multiple times (~28 
times
in 2.5 days?... so maybe 10x/day?)  about 8 start with ifup, and the rest
start @ kworker -- both happen upon enabling the bonding driver
on a 10Gb dual port adapter (trying to get 1 20Gb adapter).

The 2 tracebacks tyeps (ifup-bonding + kworker) follow:


----------------- ifup-bonding traceback:

[  229.208603] bonding: bond0: Setting MII monitoring interval to 100.
[  229.222336] bonding: bond0: Adding slave p2p1.
[  229.685599] BUG: scheduling while atomic: ifup-bonding/3711/0x00000002
[  229.692166] 4 locks held by ifup-bonding/3711:
[  229.696645]  #0:  (&buffer->mutex){......}, at: [<ffffffff811acd3f>] 
sysfs_write_file+0x3f/0x150
[  229.705721]  #1:  (s_active#75){......}, at: [<ffffffff811acdbb>] 
sysfs_write_file+0xbb/0x150
[  229.714538]  #2:  (rtnl_mutex){......}, at: [<ffffffff8159e1e0>] 
rtnl_trylock+0x10/0x20
[  229.722772]  #3:  (&bond->lock){......}, at: [<ffffffffa02964af>] 
bond_enslave+0x4df/0xb50 [bonding]
[  229.732188] Modules linked in: bonding fan mousedev kvm_intel 
iTCO_wdt iTCO_vendor_support gpio_ich kvm acpi_cpufreq mperf tpm_tis tpm 
tpm_bios processor button
[  229.747197] Pid: 3711, comm: ifup-bonding Not tainted 3.6.7-Isht-Van #1
[  229.753843] Call Trace:
[  229.756333]  [<ffffffff8168ead9>] __schedule_bug+0x5e/0x6c
[  229.761863]  [<ffffffff8169893c>] __schedule+0x77c/0x810
[  229.767214]  [<ffffffff81698a54>] schedule+0x24/0x70
[  229.772214]  [<ffffffff81697b6c>] 
schedule_hrtimeout_range_clock+0xfc/0x140
[  229.779210]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
[  229.784645]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
[  229.790950]  [<ffffffff81697bbe>] schedule_hrtimeout_range+0xe/0x10
[  229.797254]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
[  229.802611]  [<ffffffff814c519c>] ixgbe_acquire_swfw_sync_X540+0xbc/0x110
[  229.809429]  [<ffffffff814c146d>] ixgbe_read_phy_reg_generic+0x3d/0x120
[  229.816078]  [<ffffffff814c16dc>] 
ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
[  229.824022]  [<ffffffffa02964af>] ? bond_enslave+0x4df/0xb50 [bonding]
[  229.830581]  [<ffffffff814b93e4>] ixgbe_get_settings+0x34/0x2b0
[  229.836534]  [<ffffffff81594385>] __ethtool_get_settings+0x85/0x140
[  229.842837]  [<ffffffffa0292303>] bond_update_speed_duplex+0x23/0x60 
[bonding]
[  229.850092]  [<ffffffffa0296518>] bond_enslave+0x548/0xb50 [bonding]
[  229.856478]  [<ffffffffa029e62f>] bonding_store_slaves+0x13f/0x190 
[bonding]
[  229.863556]  [<ffffffff813fe163>] dev_attr_store+0x13/0x30
[  229.869074]  [<ffffffff811acdd4>] sysfs_write_file+0xd4/0x150
[  229.874856]  [<ffffffff81142c01>] vfs_write+0xb1/0x180
[  229.880034]  [<ffffffff81142f28>] sys_write+0x48/0x90
[  229.885125]  [<ffffffff8169b162>] system_call_fastpath+0x16/0x1b
[  229.891259] BUG: scheduling while atomic: ifup-bonding/3711/0x00000002
[  229.897839] 4 locks held by ifup-bonding/3711:
[  229.902320]  #0:  (&buffer->mutex){......}, at: [<ffffffff811acd3f>] 
sysfs_write_file+0x3f/0x150
[  229.911395]  #1:  (s_active#75){......}, at: [<ffffffff811acdbb>] 
sysfs_write_file+0xbb/0x150
[  229.920212]  #2:  (rtnl_mutex){......}, at: [<ffffffff8159e1e0>] 
rtnl_trylock+0x10/0x20
[  229.928449]  #3:  (&bond->lock){......}, at: [<ffffffffa02964af>] 
bond_enslave+0x4df/0xb50 [bonding]
[  229.937866] Modules linked in: bonding fan mousedev kvm_intel 
iTCO_wdt iTCO_vendor_support gpio_ich kvm acpi_cpufreq mperf tpm_tis tpm 
tpm_bios processor button
[  229.952904] Pid: 3711, comm: ifup-bonding Tainted: G        W    
3.6.7-Isht-Van #1
[  229.960507] Call Trace:
[  229.962997]  [<ffffffff8168ead9>] __schedule_bug+0x5e/0x6c
[  229.968526]  [<ffffffff8169893c>] __schedule+0x77c/0x810
[  229.973875]  [<ffffffff81698a54>] schedule+0x24/0x70
[  229.978876]  [<ffffffff81697b6c>] 
schedule_hrtimeout_range_clock+0xfc/0x140
[  229.985871]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
[  229.991303]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
[  229.996739]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
[  230.003040]  [<ffffffff81697bbe>] schedule_hrtimeout_range+0xe/0x10
[  230.009344]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
[  230.014698]  [<ffffffff814c50ce>] ixgbe_release_swfw_sync_X540+0x4e/0x60
[  230.021435]  [<ffffffff814c1531>] ixgbe_read_phy_reg_generic+0x101/0x120
[  230.028171]  [<ffffffff814c16dc>] 
ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
[  230.036117]  [<ffffffffa02964af>] ? bond_enslave+0x4df/0xb50 [bonding]
[  230.042677]  [<ffffffff814b93e4>] ixgbe_get_settings+0x34/0x2b0
[  230.048630]  [<ffffffff81594385>] __ethtool_get_settings+0x85/0x140
[  230.054934]  [<ffffffffa0292303>] bond_update_speed_duplex+0x23/0x60 
[bonding]
[  230.062189]  [<ffffffffa0296518>] bond_enslave+0x548/0xb50 [bonding]
[  230.068580]  [<ffffffffa029e62f>] bonding_store_slaves+0x13f/0x190 
[bonding]
[  230.075660]  [<ffffffff813fe163>] dev_attr_store+0x13/0x30
[  230.081189]  [<ffffffff811acdd4>] sysfs_write_file+0xd4/0x150
[  230.086971]  [<ffffffff81142c01>] vfs_write+0xb1/0x180
[  230.092148]  [<ffffffff81142f28>] sys_write+0x48/0x90
[  230.097245]  [<ffffffff8169b162>] system_call_fastpath+0x16/0x1b
[  230.103427] bonding: bond0: enslaving p2p1 as an active interface 
with a down link.
[  230.120623] bonding: bond0: Adding slave p2p2.
[  230.575194] BUG: scheduling while atomic: ifup-bonding/3711/0x00000002
[  230.581782] 4 locks held by ifup-bonding/3711:
[  230.586262]  #0:  (&buffer->mutex){......}, at: [<ffffffff811acd3f>] 
sysfs_write_file+0x3f/0x150
[  230.595287]  #1:  (s_active#75){......}, at: [<ffffffff811acdbb>] 
sysfs_write_file+0xbb/0x150
[  230.604105]  #2:  (rtnl_mutex){......}, at: [<ffffffff8159e1e0>] 
rtnl_trylock+0x10/0x20
[  230.612393]  #3:  (&bond->lock){......}, at: [<ffffffffa02964af>] 
bond_enslave+0x4df/0xb50 [bonding]
[  230.621801] Modules linked in: bonding fan mousedev kvm_intel 
iTCO_wdt iTCO_vendor_support gpio_ich kvm acpi_cpufreq mperf tpm_tis tpm 
tpm_bios processor button
[  230.636922] Pid: 3711, comm: ifup-bonding Tainted: G        W    
3.6.7-Isht-Van #1
[  230.644516] Call Trace:
[  230.647009]  [<ffffffff8168ead9>] __schedule_bug+0x5e/0x6c
[  230.652537]  [<ffffffff8169893c>] __schedule+0x77c/0x810
[  230.657886]  [<ffffffff81698a54>] schedule+0x24/0x70
[  230.662889]  [<ffffffff81697b6c>] 
schedule_hrtimeout_range_clock+0xfc/0x140
[  230.669884]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
[  230.675320]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
[  230.681622]  [<ffffffff81697bbe>] schedule_hrtimeout_range+0xe/0x10
[  230.687921]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
[  230.693283]  [<ffffffff814c519c>] ixgbe_acquire_swfw_sync_X540+0xbc/0x110
[  230.700113]  [<ffffffff814c146d>] ixgbe_read_phy_reg_generic+0x3d/0x120
[  230.706763]  [<ffffffff814c16dc>] 
ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
[  230.714713]  [<ffffffffa02964af>] ? bond_enslave+0x4df/0xb50 [bonding]
[  230.721275]  [<ffffffff814b93e4>] ixgbe_get_settings+0x34/0x2b0
[  230.727231]  [<ffffffff81594385>] __ethtool_get_settings+0x85/0x140
[  230.733535]  [<ffffffffa0292303>] bond_update_speed_duplex+0x23/0x60 
[bonding]
[  230.740790]  [<ffffffffa0296518>] bond_enslave+0x548/0xb50 [bonding]
[  230.747189]  [<ffffffffa029e62f>] bonding_store_slaves+0x13f/0x190 
[bonding]
[  230.754270]  [<ffffffff813fe163>] dev_attr_store+0x13/0x30
[  230.759792]  [<ffffffff811acdd4>] sysfs_write_file+0xd4/0x150
[  230.765576]  [<ffffffff81142c01>] vfs_write+0xb1/0x180
[  230.770753]  [<ffffffff81142f28>] sys_write+0x48/0x90
[  230.775840]  [<ffffffff8169b162>] system_call_fastpath+0x16/0x1b
[  230.781933] BUG: scheduling while atomic: ifup-bonding/3711/0x00000002
[  230.788499] 4 locks held by ifup-bonding/3711:
[  230.793021]  #0:  (&buffer->mutex){......}, at: [<ffffffff811acd3f>] 
sysfs_write_file+0x3f/0x150
[  230.802051]  #1:  (s_active#75){......}, at: [<ffffffff811acdbb>] 
sysfs_write_file+0xbb/0x150
[  230.810872]  #2:  (rtnl_mutex){......}, at: [<ffffffff8159e1e0>] 
rtnl_trylock+0x10/0x20
[  230.819160]  #3:  (&bond->lock){......}, at: [<ffffffffa02964af>] 
bond_enslave+0x4df/0xb50 [bonding]
[  230.828575] Modules linked in: bonding fan mousedev kvm_intel 
iTCO_wdt iTCO_vendor_support gpio_ich kvm acpi_cpufreq mperf tpm_tis tpm 
tpm_bios processor button
[  230.843673] Pid: 3711, comm: ifup-bonding Tainted: G        W    
3.6.7-Isht-Van #1
[  230.851271] Call Trace:
[  230.853759]  [<ffffffff8168ead9>] __schedule_bug+0x5e/0x6c
[  230.859282]  [<ffffffff8169893c>] __schedule+0x77c/0x810
[  230.864637]  [<ffffffff81698a54>] schedule+0x24/0x70
[  230.869598]  [<ffffffff81697b6c>] 
schedule_hrtimeout_range_clock+0xfc/0x140
[  230.876548]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
[  230.881966]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
[  230.887359]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
[  230.893649]  [<ffffffff81697bbe>] schedule_hrtimeout_range+0xe/0x10
[  230.899907]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
[  230.905213]  [<ffffffff814c50ce>] ixgbe_release_swfw_sync_X540+0x4e/0x60
[  230.911908]  [<ffffffff814c1531>] ixgbe_read_phy_reg_generic+0x101/0x120
[  230.918599]  [<ffffffff814c16dc>] 
ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
[  230.926501]  [<ffffffffa02964af>] ? bond_enslave+0x4df/0xb50 [bonding]
[  230.933018]  [<ffffffff814b93e4>] ixgbe_get_settings+0x34/0x2b0
[  230.938929]  [<ffffffff81594385>] __ethtool_get_settings+0x85/0x140
[  230.945185]  [<ffffffffa0292303>] bond_update_speed_duplex+0x23/0x60 
[bonding]
[  230.952392]  [<ffffffffa0296518>] bond_enslave+0x548/0xb50 [bonding]
[  230.958739]  [<ffffffffa029e62f>] bonding_store_slaves+0x13f/0x190 
[bonding]
[  230.965774]  [<ffffffff813fe163>] dev_attr_store+0x13/0x30
[  230.971251]  [<ffffffff811acdd4>] sysfs_write_file+0xd4/0x150
[  230.976988]  [<ffffffff81142c01>] vfs_write+0xb1/0x180
[  230.982146]  [<ffffffff81142f28>] sys_write+0x48/0x90
[  230.987192]  [<ffffffff8169b162>] system_call_fastpath+0x16/0x1b
[  230.993297] bonding: bond0: enslaving p2p2 as an active interface 
with a down link.
[  231.014761] ixgbe 0000:06:00.0: p2p1: changing MTU from 1500 to 9000
[  231.863728] ixgbe 0000:06:00.1: p2p2: changing MTU from 1500 to 9000


---------- kworker traceback:
[  236.268690] ixgbe 0000:06:00.0: p2p1: NIC Link is Up 10 Gbps, Flow 
Control: None
[  236.305628] BUG: scheduling while atomic: kworker/u:2/106/0x00000002
[  236.312025] 4 locks held by kworker/u:2/106:
[  236.312037]  #0:  ((bond_dev->name)){......}, at: 
[<ffffffff8105a956>] process_one_work+0x146/0x680
[  236.312049]  #1:  ((&(&bond->mii_work)->work)){......}, at: 
[<ffffffff8105a956>] process_one_work+0x146/0x680
[  236.312056]  #2:  (rtnl_mutex){......}, at: [<ffffffff8159e1e0>] 
rtnl_trylock+0x10/0x20
[  236.312065]  #3:  (&bond->lock){......}, at: [<ffffffffa02955ad>] 
bond_mii_monitor+0x2ed/0x640 [bonding]
[  236.312078] Modules linked in: ipv6 bonding fan mousedev kvm_intel 
iTCO_wdt iTCO_vendor_support gpio_ich kvm acpi_cpufreq mperf tpm_tis tpm 
tpm_bios processor button
[  236.312082] Pid: 106, comm: kworker/u:2 Tainted: G        W    
3.6.7-Isht-Van #1
[  236.312083] Call Trace:
[  236.312092]  [<ffffffff8168ead9>] __schedule_bug+0x5e/0x6c
[  236.312102]  [<ffffffff8169893c>] __schedule+0x77c/0x810
[  236.312108]  [<ffffffff81698a54>] schedule+0x24/0x70
[  236.312114]  [<ffffffff81697b6c>] 
schedule_hrtimeout_range_clock+0xfc/0x140
[  236.312121]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
[  236.312129]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
[  236.312134]  [<ffffffff81697bbe>] schedule_hrtimeout_range+0xe/0x10
[  236.312144]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
[  236.312150]  [<ffffffff814c519c>] ixgbe_acquire_swfw_sync_X540+0xbc/0x110
[  236.312157]  [<ffffffff814c146d>] ixgbe_read_phy_reg_generic+0x3d/0x120
[  236.312161]  [<ffffffff814c16dc>] 
ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
[  236.312166]  [<ffffffffa02955ad>] ? bond_mii_monitor+0x2ed/0x640 
[bonding]
[  236.312170]  [<ffffffff814b93e4>] ixgbe_get_settings+0x34/0x2b0
[  236.312177]  [<ffffffff81594385>] __ethtool_get_settings+0x85/0x140
[  236.312182]  [<ffffffffa0292303>] bond_update_speed_duplex+0x23/0x60 
[bonding]
[  236.312188]  [<ffffffffa0295614>] bond_mii_monitor+0x354/0x640 [bonding]
[  236.312198]  [<ffffffff8105a9b7>] process_one_work+0x1a7/0x680
[  236.312203]  [<ffffffff8105a956>] ? process_one_work+0x146/0x680
[  236.312210]  [<ffffffff8108c7ce>] ? put_lock_stats.isra.21+0xe/0x40
[  236.312215]  [<ffffffffa02952c0>] ? 
bond_loadbalance_arp_mon+0x2c0/0x2c0 [bonding]
[  236.312234]  [<ffffffff8105b9ed>] worker_thread+0x18d/0x4f0
[  236.312239]  [<ffffffff81070991>] ? sub_preempt_count+0x51/0x60
[  236.312242]  [<ffffffff8105b860>] ? manage_workers+0x320/0x320
[  236.312247]  [<ffffffff81060f7d>] kthread+0x9d/0xb0
[  236.312250]  [<ffffffff8169c264>] kernel_thread_helper+0x4/0x10
[  236.312254]  [<ffffffff8106c197>] ? finish_task_switch+0x77/0x100
[  236.312262]  [<ffffffff8169a4a6>] ? _raw_spin_unlock_irq+0x36/0x60
[  236.312268]  [<ffffffff8169a9dd>] ? retint_restore_args+0xe/0xe
[  236.312273]  [<ffffffff81060ee0>] ? flush_kthread_worker+0x160/0x160
[  236.312277]  [<ffffffff8169c260>] ? gs_change+0xb/0xb



^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: BUG: scheduling while atomic: ifup-bonding/3711/0x00000002 -- V3.6.7
  2012-11-27 20:37 BUG: scheduling while atomic: ifup-bonding/3711/0x00000002 -- V3.6.7 Linda Walsh
@ 2012-11-28  5:47 ` Cong Wang
       [not found]   ` <50B67F6B.6050008@tlinx.org>
  0 siblings, 1 reply; 7+ messages in thread
From: Cong Wang @ 2012-11-28  5:47 UTC (permalink / raw)
  To: Linda Walsh; +Cc: LKML, Linux Kernel Network Developers

Cc netdev...

On Wed, Nov 28, 2012 at 4:37 AM, Linda Walsh <lkml@tlinx.org> wrote:
>
>
> Is this a known problem / bug, or should I file a bug on it?  It doesn't
> cause a complete failure, and it happens multiple times (~28 times
> in 2.5 days?... so maybe 10x/day?)  about 8 start with ifup, and the rest
> start @ kworker -- both happen upon enabling the bonding driver
> on a 10Gb dual port adapter (trying to get 1 20Gb adapter).
>
> The 2 tracebacks tyeps (ifup-bonding + kworker) follow:


Does this quick fix help?

diff --git a/drivers/net/bonding/bond_main.c b/drivers/net/bonding/bond_main.c
index 5f5b69f..4a4d9eb 100644
--- a/drivers/net/bonding/bond_main.c
+++ b/drivers/net/bonding/bond_main.c
@@ -1785,7 +1785,9 @@ int bond_enslave(struct net_device *bond_dev,
struct net_device *slave_dev)
                new_slave->link == BOND_LINK_DOWN ? "DOWN" :
                        (new_slave->link == BOND_LINK_UP ? "UP" : "BACK"));

+       read_unlock(&bond->lock);
        bond_update_speed_duplex(new_slave);
+       read_lock(&bond->lock);

        if (USES_PRIMARY(bond->params.mode) && bond->params.primary[0]) {
                /* if there is a primary slave, remember it */

Thanks!

>
>
> ----------------- ifup-bonding traceback:
>
> [  229.208603] bonding: bond0: Setting MII monitoring interval to 100.
> [  229.222336] bonding: bond0: Adding slave p2p1.
> [  229.685599] BUG: scheduling while atomic: ifup-bonding/3711/0x00000002
> [  229.692166] 4 locks held by ifup-bonding/3711:
> [  229.696645]  #0:  (&buffer->mutex){......}, at: [<ffffffff811acd3f>]
> sysfs_write_file+0x3f/0x150
> [  229.705721]  #1:  (s_active#75){......}, at: [<ffffffff811acdbb>]
> sysfs_write_file+0xbb/0x150
> [  229.714538]  #2:  (rtnl_mutex){......}, at: [<ffffffff8159e1e0>]
> rtnl_trylock+0x10/0x20
> [  229.722772]  #3:  (&bond->lock){......}, at: [<ffffffffa02964af>]
> bond_enslave+0x4df/0xb50 [bonding]
> [  229.732188] Modules linked in: bonding fan mousedev kvm_intel iTCO_wdt
> iTCO_vendor_support gpio_ich kvm acpi_cpufreq mperf tpm_tis tpm tpm_bios
> processor button
> [  229.747197] Pid: 3711, comm: ifup-bonding Not tainted 3.6.7-Isht-Van #1
> [  229.753843] Call Trace:
> [  229.756333]  [<ffffffff8168ead9>] __schedule_bug+0x5e/0x6c
> [  229.761863]  [<ffffffff8169893c>] __schedule+0x77c/0x810
> [  229.767214]  [<ffffffff81698a54>] schedule+0x24/0x70
> [  229.772214]  [<ffffffff81697b6c>]
> schedule_hrtimeout_range_clock+0xfc/0x140
> [  229.779210]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
> [  229.784645]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
> [  229.790950]  [<ffffffff81697bbe>] schedule_hrtimeout_range+0xe/0x10
> [  229.797254]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
> [  229.802611]  [<ffffffff814c519c>] ixgbe_acquire_swfw_sync_X540+0xbc/0x110
> [  229.809429]  [<ffffffff814c146d>] ixgbe_read_phy_reg_generic+0x3d/0x120
> [  229.816078]  [<ffffffff814c16dc>]
> ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
> [  229.824022]  [<ffffffffa02964af>] ? bond_enslave+0x4df/0xb50 [bonding]
> [  229.830581]  [<ffffffff814b93e4>] ixgbe_get_settings+0x34/0x2b0
> [  229.836534]  [<ffffffff81594385>] __ethtool_get_settings+0x85/0x140
> [  229.842837]  [<ffffffffa0292303>] bond_update_speed_duplex+0x23/0x60
> [bonding]
> [  229.850092]  [<ffffffffa0296518>] bond_enslave+0x548/0xb50 [bonding]
> [  229.856478]  [<ffffffffa029e62f>] bonding_store_slaves+0x13f/0x190
> [bonding]
> [  229.863556]  [<ffffffff813fe163>] dev_attr_store+0x13/0x30
> [  229.869074]  [<ffffffff811acdd4>] sysfs_write_file+0xd4/0x150
> [  229.874856]  [<ffffffff81142c01>] vfs_write+0xb1/0x180
> [  229.880034]  [<ffffffff81142f28>] sys_write+0x48/0x90
> [  229.885125]  [<ffffffff8169b162>] system_call_fastpath+0x16/0x1b
> [  229.891259] BUG: scheduling while atomic: ifup-bonding/3711/0x00000002
> [  229.897839] 4 locks held by ifup-bonding/3711:
> [  229.902320]  #0:  (&buffer->mutex){......}, at: [<ffffffff811acd3f>]
> sysfs_write_file+0x3f/0x150
> [  229.911395]  #1:  (s_active#75){......}, at: [<ffffffff811acdbb>]
> sysfs_write_file+0xbb/0x150
> [  229.920212]  #2:  (rtnl_mutex){......}, at: [<ffffffff8159e1e0>]
> rtnl_trylock+0x10/0x20
> [  229.928449]  #3:  (&bond->lock){......}, at: [<ffffffffa02964af>]
> bond_enslave+0x4df/0xb50 [bonding]
> [  229.937866] Modules linked in: bonding fan mousedev kvm_intel iTCO_wdt
> iTCO_vendor_support gpio_ich kvm acpi_cpufreq mperf tpm_tis tpm tpm_bios
> processor button
> [  229.952904] Pid: 3711, comm: ifup-bonding Tainted: G        W
> 3.6.7-Isht-Van #1
> [  229.960507] Call Trace:
> [  229.962997]  [<ffffffff8168ead9>] __schedule_bug+0x5e/0x6c
> [  229.968526]  [<ffffffff8169893c>] __schedule+0x77c/0x810
> [  229.973875]  [<ffffffff81698a54>] schedule+0x24/0x70
> [  229.978876]  [<ffffffff81697b6c>]
> schedule_hrtimeout_range_clock+0xfc/0x140
> [  229.985871]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
> [  229.991303]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
> [  229.996739]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
> [  230.003040]  [<ffffffff81697bbe>] schedule_hrtimeout_range+0xe/0x10
> [  230.009344]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
> [  230.014698]  [<ffffffff814c50ce>] ixgbe_release_swfw_sync_X540+0x4e/0x60
> [  230.021435]  [<ffffffff814c1531>] ixgbe_read_phy_reg_generic+0x101/0x120
> [  230.028171]  [<ffffffff814c16dc>]
> ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
> [  230.036117]  [<ffffffffa02964af>] ? bond_enslave+0x4df/0xb50 [bonding]
> [  230.042677]  [<ffffffff814b93e4>] ixgbe_get_settings+0x34/0x2b0
> [  230.048630]  [<ffffffff81594385>] __ethtool_get_settings+0x85/0x140
> [  230.054934]  [<ffffffffa0292303>] bond_update_speed_duplex+0x23/0x60
> [bonding]
> [  230.062189]  [<ffffffffa0296518>] bond_enslave+0x548/0xb50 [bonding]
> [  230.068580]  [<ffffffffa029e62f>] bonding_store_slaves+0x13f/0x190
> [bonding]
> [  230.075660]  [<ffffffff813fe163>] dev_attr_store+0x13/0x30
> [  230.081189]  [<ffffffff811acdd4>] sysfs_write_file+0xd4/0x150
> [  230.086971]  [<ffffffff81142c01>] vfs_write+0xb1/0x180
> [  230.092148]  [<ffffffff81142f28>] sys_write+0x48/0x90
> [  230.097245]  [<ffffffff8169b162>] system_call_fastpath+0x16/0x1b
> [  230.103427] bonding: bond0: enslaving p2p1 as an active interface with a
> down link.
> [  230.120623] bonding: bond0: Adding slave p2p2.
> [  230.575194] BUG: scheduling while atomic: ifup-bonding/3711/0x00000002
> [  230.581782] 4 locks held by ifup-bonding/3711:
> [  230.586262]  #0:  (&buffer->mutex){......}, at: [<ffffffff811acd3f>]
> sysfs_write_file+0x3f/0x150
> [  230.595287]  #1:  (s_active#75){......}, at: [<ffffffff811acdbb>]
> sysfs_write_file+0xbb/0x150
> [  230.604105]  #2:  (rtnl_mutex){......}, at: [<ffffffff8159e1e0>]
> rtnl_trylock+0x10/0x20
> [  230.612393]  #3:  (&bond->lock){......}, at: [<ffffffffa02964af>]
> bond_enslave+0x4df/0xb50 [bonding]
> [  230.621801] Modules linked in: bonding fan mousedev kvm_intel iTCO_wdt
> iTCO_vendor_support gpio_ich kvm acpi_cpufreq mperf tpm_tis tpm tpm_bios
> processor button
> [  230.636922] Pid: 3711, comm: ifup-bonding Tainted: G        W
> 3.6.7-Isht-Van #1
> [  230.644516] Call Trace:
> [  230.647009]  [<ffffffff8168ead9>] __schedule_bug+0x5e/0x6c
> [  230.652537]  [<ffffffff8169893c>] __schedule+0x77c/0x810
> [  230.657886]  [<ffffffff81698a54>] schedule+0x24/0x70
> [  230.662889]  [<ffffffff81697b6c>]
> schedule_hrtimeout_range_clock+0xfc/0x140
> [  230.669884]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
> [  230.675320]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
> [  230.681622]  [<ffffffff81697bbe>] schedule_hrtimeout_range+0xe/0x10
> [  230.687921]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
> [  230.693283]  [<ffffffff814c519c>] ixgbe_acquire_swfw_sync_X540+0xbc/0x110
> [  230.700113]  [<ffffffff814c146d>] ixgbe_read_phy_reg_generic+0x3d/0x120
> [  230.706763]  [<ffffffff814c16dc>]
> ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
> [  230.714713]  [<ffffffffa02964af>] ? bond_enslave+0x4df/0xb50 [bonding]
> [  230.721275]  [<ffffffff814b93e4>] ixgbe_get_settings+0x34/0x2b0
> [  230.727231]  [<ffffffff81594385>] __ethtool_get_settings+0x85/0x140
> [  230.733535]  [<ffffffffa0292303>] bond_update_speed_duplex+0x23/0x60
> [bonding]
> [  230.740790]  [<ffffffffa0296518>] bond_enslave+0x548/0xb50 [bonding]
> [  230.747189]  [<ffffffffa029e62f>] bonding_store_slaves+0x13f/0x190
> [bonding]
> [  230.754270]  [<ffffffff813fe163>] dev_attr_store+0x13/0x30
> [  230.759792]  [<ffffffff811acdd4>] sysfs_write_file+0xd4/0x150
> [  230.765576]  [<ffffffff81142c01>] vfs_write+0xb1/0x180
> [  230.770753]  [<ffffffff81142f28>] sys_write+0x48/0x90
> [  230.775840]  [<ffffffff8169b162>] system_call_fastpath+0x16/0x1b
> [  230.781933] BUG: scheduling while atomic: ifup-bonding/3711/0x00000002
> [  230.788499] 4 locks held by ifup-bonding/3711:
> [  230.793021]  #0:  (&buffer->mutex){......}, at: [<ffffffff811acd3f>]
> sysfs_write_file+0x3f/0x150
> [  230.802051]  #1:  (s_active#75){......}, at: [<ffffffff811acdbb>]
> sysfs_write_file+0xbb/0x150
> [  230.810872]  #2:  (rtnl_mutex){......}, at: [<ffffffff8159e1e0>]
> rtnl_trylock+0x10/0x20
> [  230.819160]  #3:  (&bond->lock){......}, at: [<ffffffffa02964af>]
> bond_enslave+0x4df/0xb50 [bonding]
> [  230.828575] Modules linked in: bonding fan mousedev kvm_intel iTCO_wdt
> iTCO_vendor_support gpio_ich kvm acpi_cpufreq mperf tpm_tis tpm tpm_bios
> processor button
> [  230.843673] Pid: 3711, comm: ifup-bonding Tainted: G        W
> 3.6.7-Isht-Van #1
> [  230.851271] Call Trace:
> [  230.853759]  [<ffffffff8168ead9>] __schedule_bug+0x5e/0x6c
> [  230.859282]  [<ffffffff8169893c>] __schedule+0x77c/0x810
> [  230.864637]  [<ffffffff81698a54>] schedule+0x24/0x70
> [  230.869598]  [<ffffffff81697b6c>]
> schedule_hrtimeout_range_clock+0xfc/0x140
> [  230.876548]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
> [  230.881966]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
> [  230.887359]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
> [  230.893649]  [<ffffffff81697bbe>] schedule_hrtimeout_range+0xe/0x10
> [  230.899907]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
> [  230.905213]  [<ffffffff814c50ce>] ixgbe_release_swfw_sync_X540+0x4e/0x60
> [  230.911908]  [<ffffffff814c1531>] ixgbe_read_phy_reg_generic+0x101/0x120
> [  230.918599]  [<ffffffff814c16dc>]
> ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
> [  230.926501]  [<ffffffffa02964af>] ? bond_enslave+0x4df/0xb50 [bonding]
> [  230.933018]  [<ffffffff814b93e4>] ixgbe_get_settings+0x34/0x2b0
> [  230.938929]  [<ffffffff81594385>] __ethtool_get_settings+0x85/0x140
> [  230.945185]  [<ffffffffa0292303>] bond_update_speed_duplex+0x23/0x60
> [bonding]
> [  230.952392]  [<ffffffffa0296518>] bond_enslave+0x548/0xb50 [bonding]
> [  230.958739]  [<ffffffffa029e62f>] bonding_store_slaves+0x13f/0x190
> [bonding]
> [  230.965774]  [<ffffffff813fe163>] dev_attr_store+0x13/0x30
> [  230.971251]  [<ffffffff811acdd4>] sysfs_write_file+0xd4/0x150
> [  230.976988]  [<ffffffff81142c01>] vfs_write+0xb1/0x180
> [  230.982146]  [<ffffffff81142f28>] sys_write+0x48/0x90
> [  230.987192]  [<ffffffff8169b162>] system_call_fastpath+0x16/0x1b
> [  230.993297] bonding: bond0: enslaving p2p2 as an active interface with a
> down link.
> [  231.014761] ixgbe 0000:06:00.0: p2p1: changing MTU from 1500 to 9000
> [  231.863728] ixgbe 0000:06:00.1: p2p2: changing MTU from 1500 to 9000
>
>
> ---------- kworker traceback:
> [  236.268690] ixgbe 0000:06:00.0: p2p1: NIC Link is Up 10 Gbps, Flow
> Control: None
> [  236.305628] BUG: scheduling while atomic: kworker/u:2/106/0x00000002
> [  236.312025] 4 locks held by kworker/u:2/106:
> [  236.312037]  #0:  ((bond_dev->name)){......}, at: [<ffffffff8105a956>]
> process_one_work+0x146/0x680
> [  236.312049]  #1:  ((&(&bond->mii_work)->work)){......}, at:
> [<ffffffff8105a956>] process_one_work+0x146/0x680
> [  236.312056]  #2:  (rtnl_mutex){......}, at: [<ffffffff8159e1e0>]
> rtnl_trylock+0x10/0x20
> [  236.312065]  #3:  (&bond->lock){......}, at: [<ffffffffa02955ad>]
> bond_mii_monitor+0x2ed/0x640 [bonding]
> [  236.312078] Modules linked in: ipv6 bonding fan mousedev kvm_intel
> iTCO_wdt iTCO_vendor_support gpio_ich kvm acpi_cpufreq mperf tpm_tis tpm
> tpm_bios processor button
> [  236.312082] Pid: 106, comm: kworker/u:2 Tainted: G        W
> 3.6.7-Isht-Van #1
> [  236.312083] Call Trace:
> [  236.312092]  [<ffffffff8168ead9>] __schedule_bug+0x5e/0x6c
> [  236.312102]  [<ffffffff8169893c>] __schedule+0x77c/0x810
> [  236.312108]  [<ffffffff81698a54>] schedule+0x24/0x70
> [  236.312114]  [<ffffffff81697b6c>]
> schedule_hrtimeout_range_clock+0xfc/0x140
> [  236.312121]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
> [  236.312129]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
> [  236.312134]  [<ffffffff81697bbe>] schedule_hrtimeout_range+0xe/0x10
> [  236.312144]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
> [  236.312150]  [<ffffffff814c519c>] ixgbe_acquire_swfw_sync_X540+0xbc/0x110
> [  236.312157]  [<ffffffff814c146d>] ixgbe_read_phy_reg_generic+0x3d/0x120
> [  236.312161]  [<ffffffff814c16dc>]
> ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
> [  236.312166]  [<ffffffffa02955ad>] ? bond_mii_monitor+0x2ed/0x640
> [bonding]
> [  236.312170]  [<ffffffff814b93e4>] ixgbe_get_settings+0x34/0x2b0
> [  236.312177]  [<ffffffff81594385>] __ethtool_get_settings+0x85/0x140
> [  236.312182]  [<ffffffffa0292303>] bond_update_speed_duplex+0x23/0x60
> [bonding]
> [  236.312188]  [<ffffffffa0295614>] bond_mii_monitor+0x354/0x640 [bonding]
> [  236.312198]  [<ffffffff8105a9b7>] process_one_work+0x1a7/0x680
> [  236.312203]  [<ffffffff8105a956>] ? process_one_work+0x146/0x680
> [  236.312210]  [<ffffffff8108c7ce>] ? put_lock_stats.isra.21+0xe/0x40
> [  236.312215]  [<ffffffffa02952c0>] ? bond_loadbalance_arp_mon+0x2c0/0x2c0
> [bonding]
> [  236.312234]  [<ffffffff8105b9ed>] worker_thread+0x18d/0x4f0
> [  236.312239]  [<ffffffff81070991>] ? sub_preempt_count+0x51/0x60
> [  236.312242]  [<ffffffff8105b860>] ? manage_workers+0x320/0x320
> [  236.312247]  [<ffffffff81060f7d>] kthread+0x9d/0xb0
> [  236.312250]  [<ffffffff8169c264>] kernel_thread_helper+0x4/0x10
> [  236.312254]  [<ffffffff8106c197>] ? finish_task_switch+0x77/0x100
> [  236.312262]  [<ffffffff8169a4a6>] ? _raw_spin_unlock_irq+0x36/0x60
> [  236.312268]  [<ffffffff8169a9dd>] ? retint_restore_args+0xe/0xe
> [  236.312273]  [<ffffffff81060ee0>] ? flush_kthread_worker+0x160/0x160
> [  236.312277]  [<ffffffff8169c260>] ? gs_change+0xb/0xb
>
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

^ permalink raw reply related	[flat|nested] 7+ messages in thread

* Re: BUG: scheduling while atomic: ifup-bonding/3711/0x00000002 -- V3.6.7
       [not found]   ` <50B67F6B.6050008@tlinx.org>
@ 2012-11-29  1:04     ` Linda Walsh
  2012-11-29  1:57       ` Jay Vosburgh
  0 siblings, 1 reply; 7+ messages in thread
From: Linda Walsh @ 2012-11-29  1:04 UTC (permalink / raw)
  To: Cong Wang; +Cc: LKML, Linux Kernel Network Developers


Cong Wang wrote:
> On Wed, Nov 28, 2012 at 4:37 AM, Linda Walsh <lkml@tlinx.org> wrote:  
>> Is this a known problem / bug, or should I file a bug on it? 
> Does this quick fix help?
> ...
> Thanks!
>   

    Applied:
--- bond_main.c.orig  2012-09-30 16:47:46.000000000 -0700
+++ bond_main.c 2012-11-28 12:58:34.064931997 -0800
@@ -1778,7 +1778,9 @@
    new_slave->link == BOND_LINK_DOWN ? "DOWN" :
      (new_slave->link == BOND_LINK_UP ? "UP" : "BACK"));
 
+ read_unlock(&bond->lock);
  bond_update_speed_duplex(new_slave);
+ read_lock(&bond->lock);
 
  if (USES_PRIMARY(bond->params.mode) && bond->params.primary[0]) {
    /* if there is a primary slave, remember it */
----
Recompile/run:
Linux Ishtar 3.6.8-Isht-Van #4 SMP PREEMPT Wed Nov 28 12:59:13 PST 2012 
x86_64 x86_64 x86_64 GNU/Linux

---

Similar.  The tracebacks are below.

Since I am running in round-robin, trying for RAID0 of the 2 links--
simple bandwidth aggregation, do I even need miimon?  I mean, what load
is there to balance?

Not that this is likely the root of the bug, but it might make it
not happen in my case, if I remove the load-bal stuff...??




[   52.457633] bonding: bond0: Adding slave p2p1.
[   52.941390] bonding: bond0: enslaving p2p1 as an active interface 
with a down link.
[   52.959329] bonding: bond0: Adding slave p2p2.
[   53.442769] bonding: bond0: enslaving p2p2 as an active interface 
with a down link.
[   58.588410] ixgbe 0000:06:00.0: p2p1: NIC Link is Up 10 Gbps, Flow 
Control: None
[   58.666760] BUG: scheduling while atomic: kworker/u:1/103/0x00000002
[   58.673144] 4 locks held by kworker/u:1/103:
[   58.673145]  #0:  ((bond_dev->name)){......}, at: 
[<ffffffff8105a956>] process_one_work+0x146/0x680
[   58.673161]  #1:  ((&(&bond->mii_work)->work)){......}, at: 
[<ffffffff8105a956>] process_one_work+0x146/0x680
[   58.673167]  #2:  (rtnl_mutex){......}, at: [<ffffffff815a4dd0>] 
rtnl_trylock+0x10/0x20
[   58.673175]  #3:  (&bond->lock){......}, at: [<ffffffff81480b5d>] 
bond_mii_monitor+0x2ed/0x640
[   58.673183] Modules linked in: fan kvm_intel mousedev kvm iTCO_wdt 
iTCO_vendor_support acpi_cpufreq tpm_tis tpm tpm_bios mperf processor
[   58.673196] Pid: 103, comm: kworker/u:1 Not tainted 3.6.8-Isht-Van #4
[   58.673198] Call Trace:
[   58.673203]  [<ffffffff8167bb36>] __schedule_bug+0x5e/0x6c
[   58.673208]  [<ffffffff816859bc>] __schedule+0x77c/0x810
[   58.673211]  [<ffffffff81685ad4>] schedule+0x24/0x70
[   58.673214]  [<ffffffff81684bec>] 
schedule_hrtimeout_range_clock+0xfc/0x140
[   58.673218]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
[   58.673222]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
[   58.673225]  [<ffffffff81684c3e>] schedule_hrtimeout_range+0xe/0x10
[   58.673229]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
[   58.673235]  [<ffffffff814d220c>] ixgbe_acquire_swfw_sync_X540+0xbc/0x110
[   58.673238]  [<ffffffff814ce4dd>] ixgbe_read_phy_reg_generic+0x3d/0x120
[   58.673241]  [<ffffffff814ce74c>] 
ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
[   58.673244]  [<ffffffff81480b5d>] ? bond_mii_monitor+0x2ed/0x640
[   58.673248]  [<ffffffff814c6454>] ixgbe_get_settings+0x34/0x2b0
[   58.673253]  [<ffffffff8159af55>] __ethtool_get_settings+0x85/0x140
[   58.673256]  [<ffffffff8147c6e3>] bond_update_speed_duplex+0x23/0x60
[   58.673259]  [<ffffffff81480bc4>] bond_mii_monitor+0x354/0x640
[   58.673262]  [<ffffffff8105a9b7>] process_one_work+0x1a7/0x680
[   58.673264]  [<ffffffff8105a956>] ? process_one_work+0x146/0x680
[   58.673269]  [<ffffffff8108c7ce>] ? put_lock_stats.isra.21+0xe/0x40
[   58.673279]  [<ffffffff81480870>] ? bond_loadbalance_arp_mon+0x2c0/0x2c0
[   58.673286]  [<ffffffff8105b9ed>] worker_thread+0x18d/0x4f0
[   58.673296]  [<ffffffff81070991>] ? sub_preempt_count+0x51/0x60
[   58.673303]  [<ffffffff8105b860>] ? manage_workers+0x320/0x320
[   58.673312]  [<ffffffff81060f7d>] kthread+0x9d/0xb0
[   58.673317]  [<ffffffff816892e4>] kernel_thread_helper+0x4/0x10
[   58.673320]  [<ffffffff8106c197>] ? finish_task_switch+0x77/0x100
[   58.673323]  [<ffffffff81687526>] ? _raw_spin_unlock_irq+0x36/0x60
[   58.673326]  [<ffffffff81687a5d>] ? retint_restore_args+0xe/0xe
[   58.673329]  [<ffffffff81060ee0>] ? flush_kthread_worker+0x160/0x160
[   58.673332]  [<ffffffff816892e0>] ? gs_change+0xb/0xb
[   58.676704] BUG: scheduling while atomic: kworker/u:1/103/0x00000002
[   58.683107] 4 locks held by kworker/u:1/103:
[   58.683109]  #0:  ((bond_dev->name)){......}, at: 
[<ffffffff8105a956>] process_one_work+0x146/0x680
[   58.683120]  #1:  ((&(&bond->mii_work)->work)){......}, at: 
[<ffffffff8105a956>] process_one_work+0x146/0x680
[   58.683128]  #2:  (rtnl_mutex){......}, at: [<ffffffff815a4dd0>] 
rtnl_trylock+0x10/0x20
[   58.683136]  #3:  (&bond->lock){......}, at: [<ffffffff81480b5d>] 
bond_mii_monitor+0x2ed/0x640
[   58.683145] Modules linked in: fan kvm_intel mousedev kvm iTCO_wdt 
iTCO_vendor_support acpi_cpufreq tpm_tis tpm tpm_bios mperf processor
[   58.683162] Pid: 103, comm: kworker/u:1 Tainted: G        W    
3.6.8-Isht-Van #4
[   58.683164] Call Trace:
[   58.683170]  [<ffffffff8167bb36>] __schedule_bug+0x5e/0x6c
[   58.683175]  [<ffffffff816859bc>] __schedule+0x77c/0x810
[   58.683180]  [<ffffffff81685ad4>] schedule+0x24/0x70
[   58.683184]  [<ffffffff81684bec>] 
schedule_hrtimeout_range_clock+0xfc/0x140
[   58.683189]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
[   58.683194]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
[   58.683198]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
[   58.683203]  [<ffffffff81684c3e>] schedule_hrtimeout_range+0xe/0x10
[   58.683208]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
[   58.683213]  [<ffffffff814d213e>] ixgbe_release_swfw_sync_X540+0x4e/0x60
[   58.683217]  [<ffffffff814ce5a1>] ixgbe_read_phy_reg_generic+0x101/0x120
[   58.683222]  [<ffffffff814ce74c>] 
ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
[   58.683227]  [<ffffffff81480b5d>] ? bond_mii_monitor+0x2ed/0x640
[   58.683231]  [<ffffffff814c6454>] ixgbe_get_settings+0x34/0x2b0
[   58.683237]  [<ffffffff8159af55>] __ethtool_get_settings+0x85/0x140
[   58.683241]  [<ffffffff8147c6e3>] bond_update_speed_duplex+0x23/0x60
[   58.683246]  [<ffffffff81480bc4>] bond_mii_monitor+0x354/0x640
[   58.683250]  [<ffffffff8105a9b7>] process_one_work+0x1a7/0x680
[   58.683254]  [<ffffffff8105a956>] ? process_one_work+0x146/0x680
[   58.683259]  [<ffffffff8108c7ce>] ? put_lock_stats.isra.21+0xe/0x40
[   58.683264]  [<ffffffff81480870>] ? bond_loadbalance_arp_mon+0x2c0/0x2c0
[   58.683268]  [<ffffffff8105b9ed>] worker_thread+0x18d/0x4f0
[   58.683273]  [<ffffffff81070991>] ? sub_preempt_count+0x51/0x60
[   58.683278]  [<ffffffff8105b860>] ? manage_workers+0x320/0x320
[   58.683283]  [<ffffffff81060f7d>] kthread+0x9d/0xb0
[   58.683288]  [<ffffffff816892e4>] kernel_thread_helper+0x4/0x10
[   58.683293]  [<ffffffff8106c197>] ? finish_task_switch+0x77/0x100
[   58.683297]  [<ffffffff81687526>] ? _raw_spin_unlock_irq+0x36/0x60
[   58.683301]  [<ffffffff81687a5d>] ? retint_restore_args+0xe/0xe
[   58.683306]  [<ffffffff81060ee0>] ? flush_kthread_worker+0x160/0x160
[   58.683311]  [<ffffffff816892e0>] ? gs_change+0xb/0xb
[   58.686755] bonding: bond0: link status definitely up for interface 
p2p1, 10000 Mbps full duplex.
[   58.943059] e1000e: eth1 NIC Link is Up 1000 Mbps Full Duplex, Flow 
Control: Rx/Tx
[   59.717848] ixgbe 0000:06:00.1: p2p2: NIC Link is Up 10 Gbps, Flow 
Control: None
[   59.784848] BUG: scheduling while atomic: kworker/u:1/103/0x00000002
[   59.791219] 4 locks held by kworker/u:1/103:
[   59.791222]  #0:  ((bond_dev->name)){......}, at: 
[<ffffffff8105a956>] process_one_work+0x146/0x680
[   59.791237]  #1:  ((&(&bond->mii_work)->work)){......}, at: 
[<ffffffff8105a956>] process_one_work+0x146/0x680
[   59.791245]  #2:  (rtnl_mutex){......}, at: [<ffffffff815a4dd0>] 
rtnl_trylock+0x10/0x20
[   59.791256]  #3:  (&bond->lock){......}, at: [<ffffffff81480b5d>] 
bond_mii_monitor+0x2ed/0x640
[   59.791276] Modules linked in: fan kvm_intel mousedev kvm iTCO_wdt 
iTCO_vendor_support acpi_cpufreq tpm_tis tpm tpm_bios mperf processor
[   59.791296] Pid: 103, comm: kworker/u:1 Tainted: G        W    
3.6.8-Isht-Van #4
[   59.791299] Call Trace:
[   59.791306]  [<ffffffff8167bb36>] __schedule_bug+0x5e/0x6c
[   59.791312]  [<ffffffff816859bc>] __schedule+0x77c/0x810
[   59.791317]  [<ffffffff81685ad4>] schedule+0x24/0x70
[   59.791322]  [<ffffffff81684bec>] 
schedule_hrtimeout_range_clock+0xfc/0x140
[   59.791329]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
[   59.791334]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
[   59.791339]  [<ffffffff81684c3e>] schedule_hrtimeout_range+0xe/0x10
[   59.791345]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
[   59.791352]  [<ffffffff814d220c>] ixgbe_acquire_swfw_sync_X540+0xbc/0x110
[   59.791357]  [<ffffffff814ce4dd>] ixgbe_read_phy_reg_generic+0x3d/0x120
[   59.791361]  [<ffffffff814ce74c>] 
ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
[   59.791366]  [<ffffffff81480b5d>] ? bond_mii_monitor+0x2ed/0x640
[   59.791372]  [<ffffffff814c6454>] ixgbe_get_settings+0x34/0x2b0
[   59.791381]  [<ffffffff8159af55>] __ethtool_get_settings+0x85/0x140
[   59.791386]  [<ffffffff8147c6e3>] bond_update_speed_duplex+0x23/0x60
[   59.791389]  [<ffffffff81480bc4>] bond_mii_monitor+0x354/0x640
[   59.791393]  [<ffffffff8105a9b7>] process_one_work+0x1a7/0x680
[   59.791396]  [<ffffffff8105a956>] ? process_one_work+0x146/0x680
[   59.791402]  [<ffffffff8108c7ce>] ? put_lock_stats.isra.21+0xe/0x40
[   59.791411]  [<ffffffff81480870>] ? bond_loadbalance_arp_mon+0x2c0/0x2c0
[   59.791421]  [<ffffffff8105b9ed>] worker_thread+0x18d/0x4f0
[   59.791434]  [<ffffffff81070991>] ? sub_preempt_count+0x51/0x60
[   59.791442]  [<ffffffff8105b860>] ? manage_workers+0x320/0x320
[   59.791453]  [<ffffffff81060f7d>] kthread+0x9d/0xb0
[   59.791460]  [<ffffffff816892e4>] kernel_thread_helper+0x4/0x10
[   59.791464]  [<ffffffff8106c197>] ? finish_task_switch+0x77/0x100
[   59.791468]  [<ffffffff81687526>] ? _raw_spin_unlock_irq+0x36/0x60
[   59.791472]  [<ffffffff81687a5d>] ? retint_restore_args+0xe/0xe
[   59.791476]  [<ffffffff81060ee0>] ? flush_kthread_worker+0x160/0x160
[   59.791480]  [<ffffffff816892e0>] ? gs_change+0xb/0xb
[   59.794932] BUG: scheduling while atomic: kworker/u:1/103/0x00000002
[   59.801333] 4 locks held by kworker/u:1/103:
[   59.801340]  #0:  ((bond_dev->name)){......}, at: 
[<ffffffff8105a956>] process_one_work+0x146/0x680
[   59.801345]  #1:  ((&(&bond->mii_work)->work)){......}, at: 
[<ffffffff8105a956>] process_one_work+0x146/0x680
[   59.801350]  #2:  (rtnl_mutex){......}, at: [<ffffffff815a4dd0>] 
rtnl_trylock+0x10/0x20
[   59.801356]  #3:  (&bond->lock){......}, at: [<ffffffff81480b5d>] 
bond_mii_monitor+0x2ed/0x640
[   59.801365] Modules linked in: fan kvm_intel mousedev kvm iTCO_wdt 
iTCO_vendor_support acpi_cpufreq tpm_tis tpm tpm_bios mperf processor
[   59.801368] Pid: 103, comm: kworker/u:1 Tainted: G        W    
3.6.8-Isht-Van #4
[   59.801369] Call Trace:
[   59.801373]  [<ffffffff8167bb36>] __schedule_bug+0x5e/0x6c
[   59.801380]  [<ffffffff816859bc>] __schedule+0x77c/0x810
[   59.801385]  [<ffffffff81685ad4>] schedule+0x24/0x70
[   59.801391]  [<ffffffff81684bec>] 
schedule_hrtimeout_range_clock+0xfc/0x140
[   59.801395]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
[   59.801399]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
[   59.801404]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
[   59.801409]  [<ffffffff81684c3e>] schedule_hrtimeout_range+0xe/0x10
[   59.801414]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
[   59.801419]  [<ffffffff814d213e>] ixgbe_release_swfw_sync_X540+0x4e/0x60
[   59.801424]  [<ffffffff814ce5a1>] ixgbe_read_phy_reg_generic+0x101/0x120
[   59.801429]  [<ffffffff814ce74c>] 
ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
[   59.801433]  [<ffffffff81480b5d>] ? bond_mii_monitor+0x2ed/0x640
[   59.801441]  [<ffffffff814c6454>] ixgbe_get_settings+0x34/0x2b0
[   59.801446]  [<ffffffff8159af55>] __ethtool_get_settings+0x85/0x140
[   59.801450]  [<ffffffff8147c6e3>] bond_update_speed_duplex+0x23/0x60
[   59.801471]  [<ffffffff81480bc4>] bond_mii_monitor+0x354/0x640
[   59.801475]  [<ffffffff8105a9b7>] process_one_work+0x1a7/0x680
[   59.801477]  [<ffffffff8105a956>] ? process_one_work+0x146/0x680
[   59.801481]  [<ffffffff8108c7ce>] ? put_lock_stats.isra.21+0xe/0x40
[   59.801484]  [<ffffffff81480870>] ? bond_loadbalance_arp_mon+0x2c0/0x2c0
[   59.801489]  [<ffffffff8105b9ed>] worker_thread+0x18d/0x4f0
[   59.801495]  [<ffffffff81070991>] ? sub_preempt_count+0x51/0x60
[   59.801500]  [<ffffffff8105b860>] ? manage_workers+0x320/0x320
[   59.801505]  [<ffffffff81060f7d>] kthread+0x9d/0xb0
[   59.801510]  [<ffffffff816892e4>] kernel_thread_helper+0x4/0x10
[   59.801515]  [<ffffffff8106c197>] ? finish_task_switch+0x77/0x100
[   59.801519]  [<ffffffff81687526>] ? _raw_spin_unlock_irq+0x36/0x60
[   59.801524]  [<ffffffff81687a5d>] ? retint_restore_args+0xe/0xe
[   59.801530]  [<ffffffff81060ee0>] ? flush_kthread_worker+0x160/0x160
[   59.801536]  [<ffffffff816892e0>] ? gs_change+0xb/0xb
[   59.804986] bonding: bond0: link status definitely up for interface 
p2p2, 10000 Mbps full duplex.




^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: BUG: scheduling while atomic: ifup-bonding/3711/0x00000002 -- V3.6.7
  2012-11-29  1:04     ` Linda Walsh
@ 2012-11-29  1:57       ` Jay Vosburgh
  2012-12-07 20:06         ` Linda Walsh
  0 siblings, 1 reply; 7+ messages in thread
From: Jay Vosburgh @ 2012-11-29  1:57 UTC (permalink / raw)
  To: Linda Walsh; +Cc: Cong Wang, LKML, Linux Kernel Network Developers

Linda Walsh <lkml@tlinx.org> wrote:

>
>Cong Wang wrote:
>> On Wed, Nov 28, 2012 at 4:37 AM, Linda Walsh <lkml@tlinx.org> wrote:  
>>> Is this a known problem / bug, or should I file a bug on it? 
>> Does this quick fix help?
>> ...
>> Thanks!
>>   
>
>   Applied:
>--- bond_main.c.orig  2012-09-30 16:47:46.000000000 -0700
>+++ bond_main.c 2012-11-28 12:58:34.064931997 -0800
>@@ -1778,7 +1778,9 @@
>   new_slave->link == BOND_LINK_DOWN ? "DOWN" :
>     (new_slave->link == BOND_LINK_UP ? "UP" : "BACK"));
>
>+ read_unlock(&bond->lock);
> bond_update_speed_duplex(new_slave);
>+ read_lock(&bond->lock);
>
> if (USES_PRIMARY(bond->params.mode) && bond->params.primary[0]) {
>   /* if there is a primary slave, remember it */
>----
>Recompile/run:
>Linux Ishtar 3.6.8-Isht-Van #4 SMP PREEMPT Wed Nov 28 12:59:13 PST 2012
>x86_64 x86_64 x86_64 GNU/Linux
>
>---
>
>Similar.  The tracebacks are below.
>
>Since I am running in round-robin, trying for RAID0 of the 2 links--
>simple bandwidth aggregation, do I even need miimon?  I mean, what load
>is there to balance?
>
>Not that this is likely the root of the bug, but it might make it
>not happen in my case, if I remove the load-bal stuff...??

	The miimon functionality is used to check link state and notice
when slaves lose carrier.  Running without it will not detect failure of
the bonding slaves, which is likely not what you want.  The mode,
balance-rr in your case, is what selects the load balance to use, and is
separate from the miimon.

	That said, the problem you're seeing appears to be caused by two
things: bonding holds a lock (in addition to RTNL) when calling
__ethtool_get_settings, and an ixgbe function in the call path to
retrieve the settings, ixgbe_acquire_swfw_sync_X540, can sleep.

	The test patch above handles one case in bond_enslave, but there
is another case in bond_miimon_commit when a slave changes link state
from down to up, which will occur shortly after the slave is added.

	A similar test patch for the case I describe would be the
following:

diff --git a/drivers/net/bonding/bond_main.c b/drivers/net/bonding/bond_main.c
index 5f5b69f..b25ac47 100644
--- a/drivers/net/bonding/bond_main.c
+++ b/drivers/net/bonding/bond_main.c
@@ -2467,7 +2467,9 @@ static void bond_miimon_commit(struct bonding *bond)
 				bond_set_backup_slave(slave);
 			}
 
+			read_unlock(&bond->lock);
 			bond_update_speed_duplex(slave);
+			read_lock(&bond->lock);
 
 			pr_info("%s: link status definitely up for interface %s, %u Mbps %s duplex.\n",
 				bond->dev->name, slave->dev->name,

	I haven't tested this at all (or even compiled it), but I
suspect it will make the warnings go away.

	-J

>[   52.457633] bonding: bond0: Adding slave p2p1.
>[   52.941390] bonding: bond0: enslaving p2p1 as an active interface with
>a down link.
>[   52.959329] bonding: bond0: Adding slave p2p2.
>[   53.442769] bonding: bond0: enslaving p2p2 as an active interface with
>a down link.
>[   58.588410] ixgbe 0000:06:00.0: p2p1: NIC Link is Up 10 Gbps, Flow
>Control: None
>[   58.666760] BUG: scheduling while atomic: kworker/u:1/103/0x00000002
>[   58.673144] 4 locks held by kworker/u:1/103:
>[   58.673145]  #0:  ((bond_dev->name)){......}, at: [<ffffffff8105a956>]
>process_one_work+0x146/0x680
>[   58.673161]  #1:  ((&(&bond->mii_work)->work)){......}, at:
>[<ffffffff8105a956>] process_one_work+0x146/0x680
>[   58.673167]  #2:  (rtnl_mutex){......}, at: [<ffffffff815a4dd0>]
>rtnl_trylock+0x10/0x20
>[   58.673175]  #3:  (&bond->lock){......}, at: [<ffffffff81480b5d>]
>bond_mii_monitor+0x2ed/0x640
>[   58.673183] Modules linked in: fan kvm_intel mousedev kvm iTCO_wdt
>iTCO_vendor_support acpi_cpufreq tpm_tis tpm tpm_bios mperf processor
>[   58.673196] Pid: 103, comm: kworker/u:1 Not tainted 3.6.8-Isht-Van #4
>[   58.673198] Call Trace:
>[   58.673203]  [<ffffffff8167bb36>] __schedule_bug+0x5e/0x6c
>[   58.673208]  [<ffffffff816859bc>] __schedule+0x77c/0x810
>[   58.673211]  [<ffffffff81685ad4>] schedule+0x24/0x70
>[   58.673214]  [<ffffffff81684bec>]
>schedule_hrtimeout_range_clock+0xfc/0x140
>[   58.673218]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
>[   58.673222]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
>[   58.673225]  [<ffffffff81684c3e>] schedule_hrtimeout_range+0xe/0x10
>[   58.673229]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
>[   58.673235]  [<ffffffff814d220c>] ixgbe_acquire_swfw_sync_X540+0xbc/0x110
>[   58.673238]  [<ffffffff814ce4dd>] ixgbe_read_phy_reg_generic+0x3d/0x120
>[   58.673241]  [<ffffffff814ce74c>]
>ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
>[   58.673244]  [<ffffffff81480b5d>] ? bond_mii_monitor+0x2ed/0x640
>[   58.673248]  [<ffffffff814c6454>] ixgbe_get_settings+0x34/0x2b0
>[   58.673253]  [<ffffffff8159af55>] __ethtool_get_settings+0x85/0x140
>[   58.673256]  [<ffffffff8147c6e3>] bond_update_speed_duplex+0x23/0x60
>[   58.673259]  [<ffffffff81480bc4>] bond_mii_monitor+0x354/0x640
>[   58.673262]  [<ffffffff8105a9b7>] process_one_work+0x1a7/0x680
>[   58.673264]  [<ffffffff8105a956>] ? process_one_work+0x146/0x680
>[   58.673269]  [<ffffffff8108c7ce>] ? put_lock_stats.isra.21+0xe/0x40
>[   58.673279]  [<ffffffff81480870>] ? bond_loadbalance_arp_mon+0x2c0/0x2c0
>[   58.673286]  [<ffffffff8105b9ed>] worker_thread+0x18d/0x4f0
>[   58.673296]  [<ffffffff81070991>] ? sub_preempt_count+0x51/0x60
>[   58.673303]  [<ffffffff8105b860>] ? manage_workers+0x320/0x320
>[   58.673312]  [<ffffffff81060f7d>] kthread+0x9d/0xb0
>[   58.673317]  [<ffffffff816892e4>] kernel_thread_helper+0x4/0x10
>[   58.673320]  [<ffffffff8106c197>] ? finish_task_switch+0x77/0x100
>[   58.673323]  [<ffffffff81687526>] ? _raw_spin_unlock_irq+0x36/0x60
>[   58.673326]  [<ffffffff81687a5d>] ? retint_restore_args+0xe/0xe
>[   58.673329]  [<ffffffff81060ee0>] ? flush_kthread_worker+0x160/0x160
>[   58.673332]  [<ffffffff816892e0>] ? gs_change+0xb/0xb
>[   58.676704] BUG: scheduling while atomic: kworker/u:1/103/0x00000002
>[   58.683107] 4 locks held by kworker/u:1/103:
>[   58.683109]  #0:  ((bond_dev->name)){......}, at: [<ffffffff8105a956>]
>process_one_work+0x146/0x680
>[   58.683120]  #1:  ((&(&bond->mii_work)->work)){......}, at:
>[<ffffffff8105a956>] process_one_work+0x146/0x680
>[   58.683128]  #2:  (rtnl_mutex){......}, at: [<ffffffff815a4dd0>]
>rtnl_trylock+0x10/0x20
>[   58.683136]  #3:  (&bond->lock){......}, at: [<ffffffff81480b5d>]
>bond_mii_monitor+0x2ed/0x640
>[   58.683145] Modules linked in: fan kvm_intel mousedev kvm iTCO_wdt
>iTCO_vendor_support acpi_cpufreq tpm_tis tpm tpm_bios mperf processor
>[   58.683162] Pid: 103, comm: kworker/u:1 Tainted: G        W
>3.6.8-Isht-Van #4
>[   58.683164] Call Trace:
>[   58.683170]  [<ffffffff8167bb36>] __schedule_bug+0x5e/0x6c
>[   58.683175]  [<ffffffff816859bc>] __schedule+0x77c/0x810
>[   58.683180]  [<ffffffff81685ad4>] schedule+0x24/0x70
>[   58.683184]  [<ffffffff81684bec>]
>schedule_hrtimeout_range_clock+0xfc/0x140
>[   58.683189]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
>[   58.683194]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
>[   58.683198]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
>[   58.683203]  [<ffffffff81684c3e>] schedule_hrtimeout_range+0xe/0x10
>[   58.683208]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
>[   58.683213]  [<ffffffff814d213e>] ixgbe_release_swfw_sync_X540+0x4e/0x60
>[   58.683217]  [<ffffffff814ce5a1>] ixgbe_read_phy_reg_generic+0x101/0x120
>[   58.683222]  [<ffffffff814ce74c>]
>ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
>[   58.683227]  [<ffffffff81480b5d>] ? bond_mii_monitor+0x2ed/0x640
>[   58.683231]  [<ffffffff814c6454>] ixgbe_get_settings+0x34/0x2b0
>[   58.683237]  [<ffffffff8159af55>] __ethtool_get_settings+0x85/0x140
>[   58.683241]  [<ffffffff8147c6e3>] bond_update_speed_duplex+0x23/0x60
>[   58.683246]  [<ffffffff81480bc4>] bond_mii_monitor+0x354/0x640
>[   58.683250]  [<ffffffff8105a9b7>] process_one_work+0x1a7/0x680
>[   58.683254]  [<ffffffff8105a956>] ? process_one_work+0x146/0x680
>[   58.683259]  [<ffffffff8108c7ce>] ? put_lock_stats.isra.21+0xe/0x40
>[   58.683264]  [<ffffffff81480870>] ? bond_loadbalance_arp_mon+0x2c0/0x2c0
>[   58.683268]  [<ffffffff8105b9ed>] worker_thread+0x18d/0x4f0
>[   58.683273]  [<ffffffff81070991>] ? sub_preempt_count+0x51/0x60
>[   58.683278]  [<ffffffff8105b860>] ? manage_workers+0x320/0x320
>[   58.683283]  [<ffffffff81060f7d>] kthread+0x9d/0xb0
>[   58.683288]  [<ffffffff816892e4>] kernel_thread_helper+0x4/0x10
>[   58.683293]  [<ffffffff8106c197>] ? finish_task_switch+0x77/0x100
>[   58.683297]  [<ffffffff81687526>] ? _raw_spin_unlock_irq+0x36/0x60
>[   58.683301]  [<ffffffff81687a5d>] ? retint_restore_args+0xe/0xe
>[   58.683306]  [<ffffffff81060ee0>] ? flush_kthread_worker+0x160/0x160
>[   58.683311]  [<ffffffff816892e0>] ? gs_change+0xb/0xb
>[   58.686755] bonding: bond0: link status definitely up for interface
>p2p1, 10000 Mbps full duplex.
>[   58.943059] e1000e: eth1 NIC Link is Up 1000 Mbps Full Duplex, Flow
>Control: Rx/Tx
>[   59.717848] ixgbe 0000:06:00.1: p2p2: NIC Link is Up 10 Gbps, Flow
>Control: None
>[   59.784848] BUG: scheduling while atomic: kworker/u:1/103/0x00000002
>[   59.791219] 4 locks held by kworker/u:1/103:
>[   59.791222]  #0:  ((bond_dev->name)){......}, at: [<ffffffff8105a956>]
>process_one_work+0x146/0x680
>[   59.791237]  #1:  ((&(&bond->mii_work)->work)){......}, at:
>[<ffffffff8105a956>] process_one_work+0x146/0x680
>[   59.791245]  #2:  (rtnl_mutex){......}, at: [<ffffffff815a4dd0>]
>rtnl_trylock+0x10/0x20
>[   59.791256]  #3:  (&bond->lock){......}, at: [<ffffffff81480b5d>]
>bond_mii_monitor+0x2ed/0x640
>[   59.791276] Modules linked in: fan kvm_intel mousedev kvm iTCO_wdt
>iTCO_vendor_support acpi_cpufreq tpm_tis tpm tpm_bios mperf processor
>[   59.791296] Pid: 103, comm: kworker/u:1 Tainted: G        W
>3.6.8-Isht-Van #4
>[   59.791299] Call Trace:
>[   59.791306]  [<ffffffff8167bb36>] __schedule_bug+0x5e/0x6c
>[   59.791312]  [<ffffffff816859bc>] __schedule+0x77c/0x810
>[   59.791317]  [<ffffffff81685ad4>] schedule+0x24/0x70
>[   59.791322]  [<ffffffff81684bec>]
>schedule_hrtimeout_range_clock+0xfc/0x140
>[   59.791329]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
>[   59.791334]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
>[   59.791339]  [<ffffffff81684c3e>] schedule_hrtimeout_range+0xe/0x10
>[   59.791345]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
>[   59.791352]  [<ffffffff814d220c>] ixgbe_acquire_swfw_sync_X540+0xbc/0x110
>[   59.791357]  [<ffffffff814ce4dd>] ixgbe_read_phy_reg_generic+0x3d/0x120
>[   59.791361]  [<ffffffff814ce74c>]
>ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
>[   59.791366]  [<ffffffff81480b5d>] ? bond_mii_monitor+0x2ed/0x640
>[   59.791372]  [<ffffffff814c6454>] ixgbe_get_settings+0x34/0x2b0
>[   59.791381]  [<ffffffff8159af55>] __ethtool_get_settings+0x85/0x140
>[   59.791386]  [<ffffffff8147c6e3>] bond_update_speed_duplex+0x23/0x60
>[   59.791389]  [<ffffffff81480bc4>] bond_mii_monitor+0x354/0x640
>[   59.791393]  [<ffffffff8105a9b7>] process_one_work+0x1a7/0x680
>[   59.791396]  [<ffffffff8105a956>] ? process_one_work+0x146/0x680
>[   59.791402]  [<ffffffff8108c7ce>] ? put_lock_stats.isra.21+0xe/0x40
>[   59.791411]  [<ffffffff81480870>] ? bond_loadbalance_arp_mon+0x2c0/0x2c0
>[   59.791421]  [<ffffffff8105b9ed>] worker_thread+0x18d/0x4f0
>[   59.791434]  [<ffffffff81070991>] ? sub_preempt_count+0x51/0x60
>[   59.791442]  [<ffffffff8105b860>] ? manage_workers+0x320/0x320
>[   59.791453]  [<ffffffff81060f7d>] kthread+0x9d/0xb0
>[   59.791460]  [<ffffffff816892e4>] kernel_thread_helper+0x4/0x10
>[   59.791464]  [<ffffffff8106c197>] ? finish_task_switch+0x77/0x100
>[   59.791468]  [<ffffffff81687526>] ? _raw_spin_unlock_irq+0x36/0x60
>[   59.791472]  [<ffffffff81687a5d>] ? retint_restore_args+0xe/0xe
>[   59.791476]  [<ffffffff81060ee0>] ? flush_kthread_worker+0x160/0x160
>[   59.791480]  [<ffffffff816892e0>] ? gs_change+0xb/0xb
>[   59.794932] BUG: scheduling while atomic: kworker/u:1/103/0x00000002
>[   59.801333] 4 locks held by kworker/u:1/103:
>[   59.801340]  #0:  ((bond_dev->name)){......}, at: [<ffffffff8105a956>]
>process_one_work+0x146/0x680
>[   59.801345]  #1:  ((&(&bond->mii_work)->work)){......}, at:
>[<ffffffff8105a956>] process_one_work+0x146/0x680
>[   59.801350]  #2:  (rtnl_mutex){......}, at: [<ffffffff815a4dd0>]
>rtnl_trylock+0x10/0x20
>[   59.801356]  #3:  (&bond->lock){......}, at: [<ffffffff81480b5d>]
>bond_mii_monitor+0x2ed/0x640
>[   59.801365] Modules linked in: fan kvm_intel mousedev kvm iTCO_wdt
>iTCO_vendor_support acpi_cpufreq tpm_tis tpm tpm_bios mperf processor
>[   59.801368] Pid: 103, comm: kworker/u:1 Tainted: G        W
>3.6.8-Isht-Van #4
>[   59.801369] Call Trace:
>[   59.801373]  [<ffffffff8167bb36>] __schedule_bug+0x5e/0x6c
>[   59.801380]  [<ffffffff816859bc>] __schedule+0x77c/0x810
>[   59.801385]  [<ffffffff81685ad4>] schedule+0x24/0x70
>[   59.801391]  [<ffffffff81684bec>]
>schedule_hrtimeout_range_clock+0xfc/0x140
>[   59.801395]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
>[   59.801399]  [<ffffffff81064c80>] ? update_rmtp+0x60/0x60
>[   59.801404]  [<ffffffff81065a1f>] ? hrtimer_start_range_ns+0xf/0x20
>[   59.801409]  [<ffffffff81684c3e>] schedule_hrtimeout_range+0xe/0x10
>[   59.801414]  [<ffffffff8104bddb>] usleep_range+0x3b/0x40
>[   59.801419]  [<ffffffff814d213e>] ixgbe_release_swfw_sync_X540+0x4e/0x60
>[   59.801424]  [<ffffffff814ce5a1>] ixgbe_read_phy_reg_generic+0x101/0x120
>[   59.801429]  [<ffffffff814ce74c>]
>ixgbe_get_copper_link_capabilities_generic+0x2c/0x60
>[   59.801433]  [<ffffffff81480b5d>] ? bond_mii_monitor+0x2ed/0x640
>[   59.801441]  [<ffffffff814c6454>] ixgbe_get_settings+0x34/0x2b0
>[   59.801446]  [<ffffffff8159af55>] __ethtool_get_settings+0x85/0x140
>[   59.801450]  [<ffffffff8147c6e3>] bond_update_speed_duplex+0x23/0x60
>[   59.801471]  [<ffffffff81480bc4>] bond_mii_monitor+0x354/0x640
>[   59.801475]  [<ffffffff8105a9b7>] process_one_work+0x1a7/0x680
>[   59.801477]  [<ffffffff8105a956>] ? process_one_work+0x146/0x680
>[   59.801481]  [<ffffffff8108c7ce>] ? put_lock_stats.isra.21+0xe/0x40
>[   59.801484]  [<ffffffff81480870>] ? bond_loadbalance_arp_mon+0x2c0/0x2c0
>[   59.801489]  [<ffffffff8105b9ed>] worker_thread+0x18d/0x4f0
>[   59.801495]  [<ffffffff81070991>] ? sub_preempt_count+0x51/0x60
>[   59.801500]  [<ffffffff8105b860>] ? manage_workers+0x320/0x320
>[   59.801505]  [<ffffffff81060f7d>] kthread+0x9d/0xb0
>[   59.801510]  [<ffffffff816892e4>] kernel_thread_helper+0x4/0x10
>[   59.801515]  [<ffffffff8106c197>] ? finish_task_switch+0x77/0x100
>[   59.801519]  [<ffffffff81687526>] ? _raw_spin_unlock_irq+0x36/0x60
>[   59.801524]  [<ffffffff81687a5d>] ? retint_restore_args+0xe/0xe
>[   59.801530]  [<ffffffff81060ee0>] ? flush_kthread_worker+0x160/0x160
>[   59.801536]  [<ffffffff816892e0>] ? gs_change+0xb/0xb
>[   59.804986] bonding: bond0: link status definitely up for interface
>p2p2, 10000 Mbps full duplex.

---
	-Jay Vosburgh, IBM Linux Technology Center, fubar@us.ibm.com


^ permalink raw reply related	[flat|nested] 7+ messages in thread

* Re: BUG: scheduling while atomic: ifup-bonding/3711/0x00000002 -- V3.6.7
  2012-11-29  1:57       ` Jay Vosburgh
@ 2012-12-07 20:06         ` Linda Walsh
  2012-12-07 21:00           ` Jay Vosburgh
  0 siblings, 1 reply; 7+ messages in thread
From: Linda Walsh @ 2012-12-07 20:06 UTC (permalink / raw)
  To: Jay Vosburgh; +Cc: Cong Wang, LKML, Linux Kernel Network Developers

Sorry for the delay.... my distro (Suse) has made rebooting my system
a chore (have to often boot from rescue to get it to come up because
they put mount libs in /usr/lib expecting they will always boot
from their ram disk -- preventing those of use who boot directly
from disk from doing so easily...grrr.

Jay Vosburgh wrote:
> 	The miimon functionality is used to check link state and notice
> when slaves lose carrier.
---
    If I am running 'rr' on 2 channels -- specifically for the purpose
of link speed aggregation (getting 1 20Gb channel out of 2 10Gb channels)
I'm not sure I see how miimon would provide benefit.  -- if 1 link dies,
the other, being on the same card is likely to be dead too, so would
it really serve a purpose?


>   Running without it will not detect failure of
> the bonding slaves, which is likely not what you want.  The mode,
> balance-rr in your case, is what selects the load balance to use, and is
> separate from the miimon.
>   
----
    Wouldn't the entire link die if a slave dies -- like RAID0, 1 disk
dies, the entire link goes down? 

    The other end (windows) doesn't dynamically config for a static-link
aggregation, so I don't think it would provide benefit.

> 	That said, the problem you're seeing appears to be caused by two
> things: bonding holds a lock (in addition to RTNL) when calling
> __ethtool_get_settings, and an ixgbe function in the call path to
> retrieve the settings, ixgbe_acquire_swfw_sync_X540, can sleep.
>
> 	The test patch above handles one case in bond_enslave, but there
> is another case in bond_miimon_commit when a slave changes link state
> from down to up, which will occur shortly after the slave is added.
>   
----
    Added your 2nd patch -- no more error messages...

    however -- likely unrelated, the max speed read or write I am seeing
is about 500MB/s, and that is rare -- usually it's barely <3x a 1Gb 
network speed. (119/125 MB R/W).  I'm not at all sure it's really 
combining the links
properly.  Anyway to verify that?


    On the windows side it shows the bond-link as a 20Gb connection, but
I don't see anyplace for something similar on linux. 




^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: BUG: scheduling while atomic: ifup-bonding/3711/0x00000002 -- V3.6.7
  2012-12-07 20:06         ` Linda Walsh
@ 2012-12-07 21:00           ` Jay Vosburgh
  2012-12-09  7:48             ` Linda Walsh
  0 siblings, 1 reply; 7+ messages in thread
From: Jay Vosburgh @ 2012-12-07 21:00 UTC (permalink / raw)
  To: Linda Walsh; +Cc: Cong Wang, LKML, Linux Kernel Network Developers

Linda Walsh <lkml@tlinx.org> wrote:

>Sorry for the delay.... my distro (Suse) has made rebooting my system
>a chore (have to often boot from rescue to get it to come up because
>they put mount libs in /usr/lib expecting they will always boot
>from their ram disk -- preventing those of use who boot directly
>from disk from doing so easily...grrr.
>
>Jay Vosburgh wrote:
>> 	The miimon functionality is used to check link state and notice
>> when slaves lose carrier.
>---
>   If I am running 'rr' on 2 channels -- specifically for the purpose
>of link speed aggregation (getting 1 20Gb channel out of 2 10Gb channels)
>I'm not sure I see how miimon would provide benefit.  -- if 1 link dies,
>the other, being on the same card is likely to be dead too, so would
>it really serve a purpose?

	Perhaps, but if the link partner experiences a failure, that may
be a different situation.  Not all failures will necessarily cause both
links to fail simultaneously.

>>   Running without it will not detect failure of
>> the bonding slaves, which is likely not what you want.  The mode,
>> balance-rr in your case, is what selects the load balance to use, and is
>> separate from the miimon.
>>   
>----
>   Wouldn't the entire link die if a slave dies -- like RAID0, 1 disk
>dies, the entire link goes down? 

	No; failure of a single slave does not cause the entire bond to
fail (unless that is the last available slave).  For round robin, a
failed slave is taken out of the set used to transmit traffic, and any
remaining slaves continue to round robin amongst themselves.

>   The other end (windows) doesn't dynamically config for a static-link
>aggregation, so I don't think it would provide benefit.

	So it (windows) has no means to disable (and discontinue use of)
one channel of the aggregation should it fail, even in a static link
aggregation?

>> 	That said, the problem you're seeing appears to be caused by two
>> things: bonding holds a lock (in addition to RTNL) when calling
>> __ethtool_get_settings, and an ixgbe function in the call path to
>> retrieve the settings, ixgbe_acquire_swfw_sync_X540, can sleep.
>>
>> 	The test patch above handles one case in bond_enslave, but there
>> is another case in bond_miimon_commit when a slave changes link state
>> from down to up, which will occur shortly after the slave is added.
>>   
>----
>   Added your 2nd patch -- no more error messages...
>
>   however -- likely unrelated, the max speed read or write I am seeing
>is about 500MB/s, and that is rare -- usually it's barely <3x a 1Gb
>network speed. (119/125 MB R/W).  I'm not at all sure it's really
>combining the links
>properly.  Anyway to verify that?

	How are you testing the throughput?  If you configure the
aggregation with just one link, how does the throughput compare to the
aggregation with both links?

	It most likely is combining links properly, but any link
aggregation scheme has tradeoffs, and the best load balance algorithm to
use depends upon the work load.  Two aggregated 10G links are not
interchangable with a single 20G link.

	For a round robin transmission scheme, issues arise because
packets are delivered at the other end out of order.  This in turn
triggers various TCP behaviors to deal with what is perceived to be
transmission errors or lost packets (TCP fast retransmit being the most
notable).  This usually results in a single TCP connection being unable
to completely saturate a round-robin aggregated set of links.

	There are a few parameters on linux that can be adjusted.  I
don't know what the windows equivalents might be.

	On linux, adjusting the net.ipv4.tcp_reordering sysctl value
will increase the tolerance for out of order delivery.  

	The sysctl is adjusted via something like

sysctl -w net.ipv4.tcp_reordering=10

	the default value is 3, and higher values increase the tolerance
for out of order delivery.  If memory serves, the setting is applied to
connections as they are created, so existing connections will not see
changes.

	Also, adjusting the packet coalescing setting for the receiving
devices may also permit higher throughput. The packet coalescing setting
is adjusted via ethtool; the current settings can be viewed via

ethtool -c eth0

	and then adjusted via something like

ethtool -C eth0 rx-usecs 30

	I've seen reports that raising the "rx-usecs" parameter at the
receiver can increase the round-robin throughput.  My recollection is
that the value used was 30, but the best settings will likely be
dependent upon your particular hardware and configuration.

>   On the windows side it shows the bond-link as a 20Gb connection, but
>I don't see anyplace for something similar on linux. 

	There isn't any such indicator; bonding does not advertise its
link speed as the sum of its slaves link speeds.

	-J

---
	-Jay Vosburgh, IBM Linux Technology Center, fubar@us.ibm.com


^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: BUG: scheduling while atomic: ifup-bonding/3711/0x00000002 -- V3.6.7
  2012-12-07 21:00           ` Jay Vosburgh
@ 2012-12-09  7:48             ` Linda Walsh
  0 siblings, 0 replies; 7+ messages in thread
From: Linda Walsh @ 2012-12-09  7:48 UTC (permalink / raw)
  To: Jay Vosburgh; +Cc: Cong Wang, LKML, Linux Kernel Network Developers

Jay Vosburgh wrote:
>> ---
>>   If I am running 'rr' on 2 channels -- specifically for the purpose
>> of link speed aggregation (getting 1 20Gb channel out of 2 10Gb channels)
>> I'm not sure I see how miimon would provide benefit.  -- if 1 link dies,
>> the other, being on the same card is likely to be dead too, so would
>> it really serve a purpose?
>>     
>
> 	Perhaps, but if the link partner experiences a failure, that may
> be a different situation.  Not all failures will necessarily cause both
> links to fail simultaneously.
>
>   
>>>   Running without it will not detect failure of
>>> the bonding slaves, which is likely not what you want.  The mode,
>>> balance-rr in your case, is what selects the load balance to use, and is
>>> separate from the miimon.
>>>   
>>>       
>> ----
>>   Wouldn't the entire link die if a slave dies -- like RAID0, 1 disk
>> dies, the entire link goes down? 
>>     
> 	No; failure of a single slave does not cause the entire bond to
> fail (unless that is the last available slave).  For round robin, a
> failed slave is taken out of the set used to transmit traffic, and any
> remaining slaves continue to round robin amongst themselves.
>
>   
>>   The other end (windows) doesn't dynamically config for a static-link
>> aggregation, so I don't think it would provide benefit.
>>     
> 	So it (windows) has no means to disable (and discontinue use of)
> one channel of the aggregation should it fail, even in a static link
> aggregation?
>   
-----------------
   Actually in rereading the docs again, it should, but not w/o packet loss.

It has a static and a dynamic link aggregation, and though only the dynamic
link aggregation had that -- but both do and both claim to balance all 
traffic.

    FWIW, my cables are direct connect, so only the capabilities of the
end cards (both Intel X540-T2 cards) are at issue, I believe.
I don't know if that is a problem or not, as each of the two ports
on the cards will only see half the traffic (from the wire
that is directly connected to it).

>
> 	How are you testing the throughput?  If you configure the
> aggregation with just one link, how does the throughput compare to the
> aggregation with both links?
>   
----
    When I did 1 link, I got about 2x faster writes, and reads that were
no faster, but I didn't do extensive testing...not sure how reliable those
figures were -- but they were sufficiently disappointing that I didn't
bother doing more testing and went immediately to trying teaming/bonding.


> 	It most likely is combining links properly, but any link
> aggregation scheme has tradeoffs, and the best load balance algorithm to
> use depends upon the work load.  Two aggregated 10G links are not
> interchangable with a single 20G link.
>   
---
    Not exactly, but for TCP streams, they mostly should be.

have tried a few TCP bench tests, and they got slower speeds than
my file R/W speeds through samba.  So use samba for testings, as
it seems to provide fairly low overhead such that I can get
line-speed writes w/1Gb ethers and >97% line speed reads.

    I'm not sure, but I think the scheduler may be coming into play
more on linux (though I would have thought it would have been Windows
slowing things down -- but I guess they got lots of grief over
their perf in WinXP and Vista... As Win7 seems to be better in that
regard.  Both cards are using 9k packets, and all possible offloading.
(udp/tcp..send/receive in addition to standard chksum offloading).

> 	For a round robin transmission scheme, issues arise because
> packets are delivered at the other end out of order.  This in turn
> triggers various TCP behaviors to deal with what is perceived to be
> transmission errors or lost packets (TCP fast retransmit being the most
> notable).  This usually results in a single TCP connection being unable
> to completely saturate a round-robin aggregated set of links.
>   
----
    I don't see that much retry traffic ... What appears maybe to be
a period drop -- like some period tic(?)...I do have tpc-low-latency,
but a 10Gb connection should low latency.  Have the tcp_reordering set
to 16...which isn't a new change -- had stack tuned for optimal perf
on 1Gb....but 10gb/20gb... -- not really sure where to start...
> 	There are a few parameters on linux that can be adjusted.  I
> don't know what the windows equivalents might be.
>
> 	On linux, adjusting the net.ipv4.tcp_reordering sysctl value
> will increase the tolerance for out of order delivery.  
>
> 	The sysctl is adjusted via something like
>
> sysctl -w net.ipv4.tcp_reordering=10
>   
---
    yeah... already got that.
> 	the default value is 3, and higher values increase the tolerance
> for out of order delivery.  If memory serves, the setting is applied to
> connections as they are created, so existing connections will not see
> changes.
>
> 	Also, adjusting the packet coalescing setting for the receiving
> devices may also permit higher throughput. The packet coalescing setting
> is adjusted via ethtool; the current settings can be viewed via
>
> ethtool -c eth0
>
> 	and then adjusted via something like
>
> ethtool -C eth0 rx-usecs 30
>   
---
    Had no clue what to set there....
Besides, wouldn't I need to set it on the bond interface, as
it is the stream coming from the bond interface that need coalescing?

    When i try it with the bond interface, I get 'not supported'
(it is on the slave interfaces, but seems like those wouldn't
"fit", as there wouldn't be contiguous i/o to either slave as
they alternate packets...  (?)

> 	I've seen reports that raising the "rx-usecs" parameter at the
> receiver can increase the round-robin throughput.  My recollection is
> that the value used was 30, but the best settings will likely be
> dependent upon your particular hardware and configuration.
>   
---
    Will have to play w/those...  right now, all '0's.

    Thanks for the patch(s)...and hints on ethtool..

    FWIW, windows has 2 timers -- a 1 once/sec status timer and a 1/10sec
load tick -- but I don't see the load tick doing anything on
static aggregation.

Linda W.


^ permalink raw reply	[flat|nested] 7+ messages in thread

end of thread, other threads:[~2012-12-09  7:50 UTC | newest]

Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2012-11-27 20:37 BUG: scheduling while atomic: ifup-bonding/3711/0x00000002 -- V3.6.7 Linda Walsh
2012-11-28  5:47 ` Cong Wang
     [not found]   ` <50B67F6B.6050008@tlinx.org>
2012-11-29  1:04     ` Linda Walsh
2012-11-29  1:57       ` Jay Vosburgh
2012-12-07 20:06         ` Linda Walsh
2012-12-07 21:00           ` Jay Vosburgh
2012-12-09  7:48             ` Linda Walsh

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).