Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752055Ab2K2B5Y (ORCPT ); Wed, 28 Nov 2012 20:57:24 -0500 Received: from e33.co.us.ibm.com ([32.97.110.151]:39454 "EHLO e33.co.us.ibm.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1750713Ab2K2B5W (ORCPT ); Wed, 28 Nov 2012 20:57:22 -0500 From: Jay Vosburgh To: Linda Walsh cc: Cong Wang , LKML , Linux Kernel Network Developers Subject: Re: BUG: scheduling while atomic: ifup-bonding/3711/0x00000002 -- V3.6.7 In-reply-to: <50B6B4B6.3070304@tlinx.org> References: <50B5248A.5010908@tlinx.org> <50B67F6B.6050008@tlinx.org> <50B6B4B6.3070304@tlinx.org> Comments: In-reply-to Linda Walsh message dated "Wed, 28 Nov 2012 17:04:54 -0800." X-Mailer: MH-E 8.2; nmh 1.4; GNU Emacs 23.4.1 Date: Wed, 28 Nov 2012 17:57:16 -0800 Message-ID: <4913.1354154236@death.nxdomain> X-Content-Scanned: Fidelis XPS MAILER x-cbid: 12112901-2398-0000-0000-00000E4D465F Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 15283 Lines: 292 Linda Walsh wrote: > >Cong Wang wrote: >> On Wed, Nov 28, 2012 at 4:37 AM, Linda Walsh 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: [] >process_one_work+0x146/0x680 >[ 58.673161] #1: ((&(&bond->mii_work)->work)){......}, at: >[] process_one_work+0x146/0x680 >[ 58.673167] #2: (rtnl_mutex){......}, at: [] >rtnl_trylock+0x10/0x20 >[ 58.673175] #3: (&bond->lock){......}, at: [] >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] [] __schedule_bug+0x5e/0x6c >[ 58.673208] [] __schedule+0x77c/0x810 >[ 58.673211] [] schedule+0x24/0x70 >[ 58.673214] [] >schedule_hrtimeout_range_clock+0xfc/0x140 >[ 58.673218] [] ? update_rmtp+0x60/0x60 >[ 58.673222] [] ? hrtimer_start_range_ns+0xf/0x20 >[ 58.673225] [] schedule_hrtimeout_range+0xe/0x10 >[ 58.673229] [] usleep_range+0x3b/0x40 >[ 58.673235] [] ixgbe_acquire_swfw_sync_X540+0xbc/0x110 >[ 58.673238] [] ixgbe_read_phy_reg_generic+0x3d/0x120 >[ 58.673241] [] >ixgbe_get_copper_link_capabilities_generic+0x2c/0x60 >[ 58.673244] [] ? bond_mii_monitor+0x2ed/0x640 >[ 58.673248] [] ixgbe_get_settings+0x34/0x2b0 >[ 58.673253] [] __ethtool_get_settings+0x85/0x140 >[ 58.673256] [] bond_update_speed_duplex+0x23/0x60 >[ 58.673259] [] bond_mii_monitor+0x354/0x640 >[ 58.673262] [] process_one_work+0x1a7/0x680 >[ 58.673264] [] ? process_one_work+0x146/0x680 >[ 58.673269] [] ? put_lock_stats.isra.21+0xe/0x40 >[ 58.673279] [] ? bond_loadbalance_arp_mon+0x2c0/0x2c0 >[ 58.673286] [] worker_thread+0x18d/0x4f0 >[ 58.673296] [] ? sub_preempt_count+0x51/0x60 >[ 58.673303] [] ? manage_workers+0x320/0x320 >[ 58.673312] [] kthread+0x9d/0xb0 >[ 58.673317] [] kernel_thread_helper+0x4/0x10 >[ 58.673320] [] ? finish_task_switch+0x77/0x100 >[ 58.673323] [] ? _raw_spin_unlock_irq+0x36/0x60 >[ 58.673326] [] ? retint_restore_args+0xe/0xe >[ 58.673329] [] ? flush_kthread_worker+0x160/0x160 >[ 58.673332] [] ? 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: [] >process_one_work+0x146/0x680 >[ 58.683120] #1: ((&(&bond->mii_work)->work)){......}, at: >[] process_one_work+0x146/0x680 >[ 58.683128] #2: (rtnl_mutex){......}, at: [] >rtnl_trylock+0x10/0x20 >[ 58.683136] #3: (&bond->lock){......}, at: [] >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] [] __schedule_bug+0x5e/0x6c >[ 58.683175] [] __schedule+0x77c/0x810 >[ 58.683180] [] schedule+0x24/0x70 >[ 58.683184] [] >schedule_hrtimeout_range_clock+0xfc/0x140 >[ 58.683189] [] ? update_rmtp+0x60/0x60 >[ 58.683194] [] ? update_rmtp+0x60/0x60 >[ 58.683198] [] ? hrtimer_start_range_ns+0xf/0x20 >[ 58.683203] [] schedule_hrtimeout_range+0xe/0x10 >[ 58.683208] [] usleep_range+0x3b/0x40 >[ 58.683213] [] ixgbe_release_swfw_sync_X540+0x4e/0x60 >[ 58.683217] [] ixgbe_read_phy_reg_generic+0x101/0x120 >[ 58.683222] [] >ixgbe_get_copper_link_capabilities_generic+0x2c/0x60 >[ 58.683227] [] ? bond_mii_monitor+0x2ed/0x640 >[ 58.683231] [] ixgbe_get_settings+0x34/0x2b0 >[ 58.683237] [] __ethtool_get_settings+0x85/0x140 >[ 58.683241] [] bond_update_speed_duplex+0x23/0x60 >[ 58.683246] [] bond_mii_monitor+0x354/0x640 >[ 58.683250] [] process_one_work+0x1a7/0x680 >[ 58.683254] [] ? process_one_work+0x146/0x680 >[ 58.683259] [] ? put_lock_stats.isra.21+0xe/0x40 >[ 58.683264] [] ? bond_loadbalance_arp_mon+0x2c0/0x2c0 >[ 58.683268] [] worker_thread+0x18d/0x4f0 >[ 58.683273] [] ? sub_preempt_count+0x51/0x60 >[ 58.683278] [] ? manage_workers+0x320/0x320 >[ 58.683283] [] kthread+0x9d/0xb0 >[ 58.683288] [] kernel_thread_helper+0x4/0x10 >[ 58.683293] [] ? finish_task_switch+0x77/0x100 >[ 58.683297] [] ? _raw_spin_unlock_irq+0x36/0x60 >[ 58.683301] [] ? retint_restore_args+0xe/0xe >[ 58.683306] [] ? flush_kthread_worker+0x160/0x160 >[ 58.683311] [] ? 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: [] >process_one_work+0x146/0x680 >[ 59.791237] #1: ((&(&bond->mii_work)->work)){......}, at: >[] process_one_work+0x146/0x680 >[ 59.791245] #2: (rtnl_mutex){......}, at: [] >rtnl_trylock+0x10/0x20 >[ 59.791256] #3: (&bond->lock){......}, at: [] >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] [] __schedule_bug+0x5e/0x6c >[ 59.791312] [] __schedule+0x77c/0x810 >[ 59.791317] [] schedule+0x24/0x70 >[ 59.791322] [] >schedule_hrtimeout_range_clock+0xfc/0x140 >[ 59.791329] [] ? update_rmtp+0x60/0x60 >[ 59.791334] [] ? hrtimer_start_range_ns+0xf/0x20 >[ 59.791339] [] schedule_hrtimeout_range+0xe/0x10 >[ 59.791345] [] usleep_range+0x3b/0x40 >[ 59.791352] [] ixgbe_acquire_swfw_sync_X540+0xbc/0x110 >[ 59.791357] [] ixgbe_read_phy_reg_generic+0x3d/0x120 >[ 59.791361] [] >ixgbe_get_copper_link_capabilities_generic+0x2c/0x60 >[ 59.791366] [] ? bond_mii_monitor+0x2ed/0x640 >[ 59.791372] [] ixgbe_get_settings+0x34/0x2b0 >[ 59.791381] [] __ethtool_get_settings+0x85/0x140 >[ 59.791386] [] bond_update_speed_duplex+0x23/0x60 >[ 59.791389] [] bond_mii_monitor+0x354/0x640 >[ 59.791393] [] process_one_work+0x1a7/0x680 >[ 59.791396] [] ? process_one_work+0x146/0x680 >[ 59.791402] [] ? put_lock_stats.isra.21+0xe/0x40 >[ 59.791411] [] ? bond_loadbalance_arp_mon+0x2c0/0x2c0 >[ 59.791421] [] worker_thread+0x18d/0x4f0 >[ 59.791434] [] ? sub_preempt_count+0x51/0x60 >[ 59.791442] [] ? manage_workers+0x320/0x320 >[ 59.791453] [] kthread+0x9d/0xb0 >[ 59.791460] [] kernel_thread_helper+0x4/0x10 >[ 59.791464] [] ? finish_task_switch+0x77/0x100 >[ 59.791468] [] ? _raw_spin_unlock_irq+0x36/0x60 >[ 59.791472] [] ? retint_restore_args+0xe/0xe >[ 59.791476] [] ? flush_kthread_worker+0x160/0x160 >[ 59.791480] [] ? 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: [] >process_one_work+0x146/0x680 >[ 59.801345] #1: ((&(&bond->mii_work)->work)){......}, at: >[] process_one_work+0x146/0x680 >[ 59.801350] #2: (rtnl_mutex){......}, at: [] >rtnl_trylock+0x10/0x20 >[ 59.801356] #3: (&bond->lock){......}, at: [] >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] [] __schedule_bug+0x5e/0x6c >[ 59.801380] [] __schedule+0x77c/0x810 >[ 59.801385] [] schedule+0x24/0x70 >[ 59.801391] [] >schedule_hrtimeout_range_clock+0xfc/0x140 >[ 59.801395] [] ? update_rmtp+0x60/0x60 >[ 59.801399] [] ? update_rmtp+0x60/0x60 >[ 59.801404] [] ? hrtimer_start_range_ns+0xf/0x20 >[ 59.801409] [] schedule_hrtimeout_range+0xe/0x10 >[ 59.801414] [] usleep_range+0x3b/0x40 >[ 59.801419] [] ixgbe_release_swfw_sync_X540+0x4e/0x60 >[ 59.801424] [] ixgbe_read_phy_reg_generic+0x101/0x120 >[ 59.801429] [] >ixgbe_get_copper_link_capabilities_generic+0x2c/0x60 >[ 59.801433] [] ? bond_mii_monitor+0x2ed/0x640 >[ 59.801441] [] ixgbe_get_settings+0x34/0x2b0 >[ 59.801446] [] __ethtool_get_settings+0x85/0x140 >[ 59.801450] [] bond_update_speed_duplex+0x23/0x60 >[ 59.801471] [] bond_mii_monitor+0x354/0x640 >[ 59.801475] [] process_one_work+0x1a7/0x680 >[ 59.801477] [] ? process_one_work+0x146/0x680 >[ 59.801481] [] ? put_lock_stats.isra.21+0xe/0x40 >[ 59.801484] [] ? bond_loadbalance_arp_mon+0x2c0/0x2c0 >[ 59.801489] [] worker_thread+0x18d/0x4f0 >[ 59.801495] [] ? sub_preempt_count+0x51/0x60 >[ 59.801500] [] ? manage_workers+0x320/0x320 >[ 59.801505] [] kthread+0x9d/0xb0 >[ 59.801510] [] kernel_thread_helper+0x4/0x10 >[ 59.801515] [] ? finish_task_switch+0x77/0x100 >[ 59.801519] [] ? _raw_spin_unlock_irq+0x36/0x60 >[ 59.801524] [] ? retint_restore_args+0xe/0xe >[ 59.801530] [] ? flush_kthread_worker+0x160/0x160 >[ 59.801536] [] ? 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 -- 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/