Fw: [Bug 102181] New: kernel soft lockup when using tcp_keepalive_timer

Fw: [Bug 102181] New: kernel soft lockup when using tcp_keepalive_timer

[Stephen Hemminger]

Begin forwarded message:

Date: Sat, 1 Aug 2015 09:43:46 +0000
From: "bugzilla-daemon@bugzilla.kernel.org" <bugzilla-daemon@bugzilla.kernel.org>
To: "shemminger@linux-foundation.org" <shemminger@linux-foundation.org>
Subject: [Bug 102181] New: kernel soft lockup when using tcp_keepalive_timer


https://bugzilla.kernel.org/show_bug.cgi?id=102181

            Bug ID: 102181
           Summary: kernel soft lockup when using tcp_keepalive_timer
           Product: Networking
           Version: 2.5
    Kernel Version: 3.0.93
          Hardware: All
                OS: Linux
              Tree: Mainline
            Status: NEW
          Severity: normal
          Priority: P1
         Component: IPV4
          Assignee: shemminger@linux-foundation.org
          Reporter: 13806511171@163.com
        Regression: No

Kernel report soft lockup when call the timer function tcp_keepalive_timer.
Only one cpu dead lock in bh_lock_sock(sk);
And all the other CPUs are idle.
The kernel version is 3.0.93.
And the messages:

[73136.797013] BUG: soft lockup - CPU#3 stuck for 22s! [neutron-server:5728]
[73136.804090] Modules linked in: ip6table_filter ip6table_raw ip6_tables
iptable_raw iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi xt_tcpudp
iptable_mangle iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 edd joydev
st sr_mod ide_gd_mod(N) ide_cd_mod ide_core cdrom xfs 8021q garp stp llc
sch_htb af_packet softdog signo_catch(N) ipmi_devintf ipmi_si ipmi_msghandler
kbox(F) iptable_filter ip_tables x_tables openvswitch nf_conntrack crc32c
libcrc32c gre mperf uio nbd bonding vhost_scsi target_core_mod configfs ext4(N)
jbd2 crc16 loop vhost_net macvtap macvlan tun kvm_intel kvm ipv6 ipv6_lib ahci
libahci libata i2c_i801 ixgbe(X) pcspkr hio(FN) i2c_core ses dca enclosure sg
rtc_cmos acpi_power_meter button container ext3 jbd mbcache dm_mirror
dm_region_hash dm_log linear sd_mod crc_t10dif ehci_hcd usbcore mpt3sas
usb_common scsi_transport_sas raid_class processor thermal_sys hwmon
scsi_dh_emc scsi_dh_alua scsi_dh_rdac scsi_dh_hp_sw scsi_dh scsi_mod
dm_snapshot dm_mod [last unloaded: iTCO_vendor_support]
[73136.899222] Supported: No, Unsupported modules are loaded
[73136.904927] CPU 3 
[73136.906762] Modules linked in: ip6table_filter ip6table_raw ip6_tables
iptable_raw iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi xt_tcpudp
iptable_mangle iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 edd joydev
st sr_mod ide_gd_mod(N) ide_cd_mod ide_core cdrom xfs 8021q garp stp llc
sch_htb af_packet softdog signo_catch(N) ipmi_devintf ipmi_si ipmi_msghandler
kbox(F) iptable_filter ip_tables x_tables openvswitch nf_conntrack crc32c
libcrc32c gre mperf uio nbd bonding vhost_scsi target_core_mod configfs ext4(N)
jbd2 crc16 loop vhost_net macvtap macvlan tun kvm_intel kvm ipv6 ipv6_lib ahci
libahci libata i2c_i801 ixgbe(X) pcspkr hio(FN) i2c_core ses dca enclosure sg
rtc_cmos acpi_power_meter button container ext3 jbd mbcache dm_mirror
dm_region_hash dm_log linear sd_mod crc_t10dif ehci_hcd usbcore mpt3sas
usb_common scsi_transport_sas raid_class processor thermal_sys hwmon
scsi_dh_emc scsi_dh_alua scsi_dh_rdac scsi_dh_hp_sw scsi_dh scsi_mod
dm_snapshot dm_mod [last unloaded: iTCO_vendor_support]
[73137.009680] Supported: No, Unsupported modules are loaded
[73137.015376] 
[73137.017177] Pid: 5728, comm: neutron-server Tainted: GF       W  NX
3.0.93-0.8-default #1 To be filled by O.E.M. RH2288H V3/BC11HGSA0
[73137.029814] RIP: 0010:[<ffffffff81460158>]  [<ffffffff81460158>]
_raw_spin_lock+0x18/0x20
[73137.038619] RSP: 0000:ffff88307fc63e28  EFLAGS: 00000297
[73137.044212] RAX: 0000000000000001 RBX: ffff882f5d7e87d0 RCX:
ffff882f5f288020
[73137.051642] RDX: 0000000000000000 RSI: ffffffff813f40d0 RDI:
ffff882d351e2850
[73137.059020] RBP: ffff882d351e29b0 R08: dead000000200200 R09:
ffff8828a33fa348
[73137.066441] R10: 00000000000007c7 R11: ffffffff81025b00 R12:
ffffffff81468a73
[73137.073823] R13: ffff88307fc63d98 R14: ffff882d351e2800 R15:
ffff882d351e2800
[73137.081255] FS:  00002b3127ea2b20(0000) GS:ffff88307fc60000(0000)
knlGS:0000000000000000
[73137.089952] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[73137.095996] CR2: 00002b8ab967fb90 CR3: 00000028a3674000 CR4:
00000000001407e0
[73137.103372] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
0000000000000000
[73137.110811] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7:
0000000000000400
[73137.118241] Process neutron-server (pid: 5728, threadinfo ffff8828a368a000,
task ffff8828a33fa300)
[73137.127806] Stack:
[73137.130133]  ffffffff813f40f1 ffff882d351e29b0 ffff882d351e29b0
0000000000000100
[73137.138221]  ffffffff8106f45b ffff882d351e29b0 ffff882f5f288000
0000000000000008
[73137.146199]  ffff88307fc63ea0 ffffffff813f40d0 ffffffff81070873
ffff882f5f289c20
[73137.154287] Call Trace:
[73137.157049]  [<ffffffff813f40f1>] tcp_keepalive_timer+0x21/0x270
[73137.163364]  [<ffffffff8106f45b>] call_timer_fn+0x6b/0x120
[73137.169148]  [<ffffffff81070873>] run_timer_softirq+0x173/0x240
[73137.175315]  [<ffffffff8106769f>] __do_softirq+0xef/0x220
[73137.181014]  [<ffffffff814692dc>] call_softirq+0x1c/0x30
[73137.186631]  [<ffffffff810044d5>] do_softirq+0x65/0xa0
[73137.192078]  [<ffffffff81067495>] irq_exit+0xc5/0xe0
[73137.197349]  [<ffffffff810268f8>] smp_apic_timer_interrupt+0x68/0xa0
[73137.203956]  [<ffffffff81468a73>] apic_timer_interrupt+0x13/0x20
[73137.210261]  [<00002b3126f9dee5>] 0x2b3126f9dee4

-- 
You are receiving this mail because:
You are the assignee for the bug.

[PATCH net] bonding: fix bond_poll_controller bh_enable warning

[Nikolay Aleksandrov]

From: Nikolay Aleksandrov <nikolay@cumulusnetworks.com>

The problem is rcu_read_unlock_bh() which triggers a warning.
ndo_poll_controller is supposed to be running with either irqs disabled
or bh disabled already, so we don't need to take rcu_read_lock_bh.
Use the standard rcu_read_lock/unlock to make the non-bh rcu_dereference
happy.

This patch fixes https://bugzilla.kernel.org/show_bug.cgi?id=102181

[   98.502922] bond0: making interface eth1 the new active one
[   98.503039] ------------[ cut here ]------------
[   98.503039] WARNING: CPU: 0 PID: 1744 at kernel/softirq.c:150 __local_bh_enable_ip+0x96/0xc0()
[   98.503039] Modules linked in: bonding(OE) rpcsec_gss_krb5 nfsv4 dns_resolver nfs fscache netconsole ppdev joydev parport_pc serio_raw parport i2c_piix4 video acpi_cpufreq nfsd auth_rpcgss nfs_acl lockd grace sunrpc virtio_net e1000 ata_generic pcnet32 mii virtio_pci virtio_ring virtio pata_acpi
[   98.503039] CPU: 0 PID: 1744 Comm: ifenslave Tainted: G           OE   4.2.0-rc7+ #56
[   98.503039] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[   98.503039]  0000000000000000 00000000e96ba230 ffff880020c236b8 ffffffff8183f105
[   98.503039]  0000000000000000 0000000000000000 ffff880020c236f8 ffffffff810a9496
[   98.503039]  ffff88002ea99e08 0000000000000200 ffffffffa02a8e06 ffff88002ea99e08
[   98.503039] Call Trace:
[   98.503039]  [<ffffffff8183f105>] dump_stack+0x4c/0x65
[   98.503039]  [<ffffffff810a9496>] warn_slowpath_common+0x86/0xc0
[   98.503039]  [<ffffffffa02a8e06>] ? bond_poll_controller+0x146/0x250 [bonding]
[   98.503039]  [<ffffffff810a95ca>] warn_slowpath_null+0x1a/0x20
[   98.503039]  [<ffffffff810ae376>] __local_bh_enable_ip+0x96/0xc0
[   98.503039]  [<ffffffffa02a8e2f>] bond_poll_controller+0x16f/0x250 [bonding]
[   98.503039]  [<ffffffffa02a8cf3>] ? bond_poll_controller+0x33/0x250 [bonding]
[   98.503039]  [<ffffffff810feaed>] ? trace_hardirqs_off+0xd/0x10
[   98.503039]  [<ffffffff81848afb>] ? _raw_spin_unlock_irqrestore+0x5b/0x60
[   98.503039]  [<ffffffff816ec48e>] netpoll_poll_dev+0x6e/0x350
[   98.503039]  [<ffffffff816eb977>] ? netpoll_start_xmit+0x137/0x1d0
[   98.503039]  [<ffffffff816b2e8b>] ? __alloc_skb+0x5b/0x210
[   98.503039]  [<ffffffff816ec89d>] netpoll_send_skb_on_dev+0x12d/0x2a0
[   98.503039]  [<ffffffff816eccde>] netpoll_send_udp+0x2ce/0x430
[   98.503039]  [<ffffffffa0190850>] write_msg+0xb0/0xf0 [netconsole]
[   98.503039]  [<ffffffff81116b63>] call_console_drivers.constprop.25+0x133/0x260
[   98.503039]  [<ffffffff81117934>] console_unlock+0x2f4/0x580
[   98.503039]  [<ffffffff81117ea5>] ? vprintk_emit+0x2e5/0x630
[   98.503039]  [<ffffffff81117ee5>] vprintk_emit+0x325/0x630
[   98.503039]  [<ffffffff81118379>] vprintk_default+0x29/0x40
[   98.503039]  [<ffffffff8183de4f>] printk+0x55/0x6b
[   98.503039]  [<ffffffff816c754c>] __netdev_printk+0x16c/0x260
[   98.503039]  [<ffffffff816c7a12>] netdev_info+0x62/0x80
[   98.503039]  [<ffffffffa02ab464>] bond_change_active_slave+0x134/0x6a0 [bonding]
[   98.503039]  [<ffffffffa02aba95>] bond_select_active_slave+0xc5/0x310 [bonding]
[   98.503039]  [<ffffffffa02aeb78>] bond_enslave+0x1088/0x10c0 [bonding]
[   98.503039]  [<ffffffffa02af46b>] bond_do_ioctl+0x37b/0x400 [bonding]
[   98.503039]  [<ffffffff81101d8d>] ? trace_hardirqs_on+0xd/0x10
[   98.503039]  [<ffffffff816dc437>] ? rtnl_lock+0x17/0x20
[   98.503039]  [<ffffffff816e5fd1>] dev_ifsioc+0x331/0x3e0
[   98.503039]  [<ffffffff816e62dc>] dev_ioctl+0xec/0x6c0
[   98.503039]  [<ffffffff816a6c6a>] sock_do_ioctl+0x4a/0x60
[   98.503039]  [<ffffffff816a7300>] sock_ioctl+0x1c0/0x250
[   98.503039]  [<ffffffff81271bfe>] do_vfs_ioctl+0x2ee/0x540
[   98.503039]  [<ffffffff810fd943>] ? up_read+0x23/0x40
[   98.503039]  [<ffffffff81070993>] ? __do_page_fault+0x1d3/0x420
[   98.503039]  [<ffffffff8127e246>] ? __fget_light+0x66/0x90
[   98.503039]  [<ffffffff81271ec9>] SyS_ioctl+0x79/0x90
[   98.503039]  [<ffffffff8184936e>] entry_SYSCALL_64_fastpath+0x12/0x76
[   98.503039] ---[ end trace 00cfa804b0670051 ]---

Fixes: 616f45416ca0 ("bonding: implement bond_poll_controller()")
Signed-off-by: Nikolay Aleksandrov <nikolay@cumulusnetworks.com>
---
 drivers/net/bonding/bond_main.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/drivers/net/bonding/bond_main.c b/drivers/net/bonding/bond_main.c
index a98dd4f1b0e3..1b4b24218807 100644
--- a/drivers/net/bonding/bond_main.c
+++ b/drivers/net/bonding/bond_main.c
@@ -979,7 +979,7 @@ static void bond_poll_controller(struct net_device *bond_dev)
 		if (bond_3ad_get_active_agg_info(bond, &ad_info))
 			return;
 
-	rcu_read_lock_bh();
+	rcu_read_lock();
 	bond_for_each_slave_rcu(bond, slave, iter) {
 		ops = slave->dev->netdev_ops;
 		if (!bond_slave_is_up(slave) || !ops->ndo_poll_controller)
@@ -1000,7 +1000,7 @@ static void bond_poll_controller(struct net_device *bond_dev)
 		ops->ndo_poll_controller(slave->dev);
 		up(&ni->dev_lock);
 	}
-	rcu_read_unlock_bh();
+	rcu_read_unlock();
 }
 
 static void bond_netpoll_cleanup(struct net_device *bond_dev)
-- 
2.4.3

Re: [PATCH net] bonding: fix bond_poll_controller bh_enable warning

[Nikolay Aleksandrov]

> On Aug 27, 2015, at 6:54 PM, Nikolay Aleksandrov <razor@blackwall.org> wrote:
> 
> From: Nikolay Aleksandrov <nikolay@cumulusnetworks.com>
> 
> The problem is rcu_read_unlock_bh() which triggers a warning.
> ndo_poll_controller is supposed to be running with either irqs disabled
> or bh disabled already, so we don't need to take rcu_read_lock_bh.
> Use the standard rcu_read_lock/unlock to make the non-bh rcu_dereference
> happy.
> 

Actually I was wrong here, e.g. netpoll_send_udp(). It is currently only used by netconsole
with irqs disabled but that doesn’t have to be true for future users.
I wanted to avoid conditional lock acquiring but we may have to go that way.
I’ll post a v2 in a few hours.

Please drop this patch.

Thanks,
 Nik

> This patch fixes https://bugzilla.kernel.org/show_bug.cgi?id=102181
> 
> [   98.502922] bond0: making interface eth1 the new active one
> [   98.503039] ------------[ cut here ]------------
> [   98.503039] WARNING: CPU: 0 PID: 1744 at kernel/softirq.c:150 __local_bh_enable_ip+0x96/0xc0()
> [   98.503039] Modules linked in: bonding(OE) rpcsec_gss_krb5 nfsv4 dns_resolver nfs fscache netconsole ppdev joydev parport_pc serio_raw parport i2c_piix4 video acpi_cpufreq nfsd auth_rpcgss nfs_acl lockd grace sunrpc virtio_net e1000 ata_generic pcnet32 mii virtio_pci virtio_ring virtio pata_acpi
> [   98.503039] CPU: 0 PID: 1744 Comm: ifenslave Tainted: G           OE   4.2.0-rc7+ #56
> [   98.503039] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [   98.503039]  0000000000000000 00000000e96ba230 ffff880020c236b8 ffffffff8183f105
> [   98.503039]  0000000000000000 0000000000000000 ffff880020c236f8 ffffffff810a9496
> [   98.503039]  ffff88002ea99e08 0000000000000200 ffffffffa02a8e06 ffff88002ea99e08
> [   98.503039] Call Trace:
> [   98.503039]  [<ffffffff8183f105>] dump_stack+0x4c/0x65
> [   98.503039]  [<ffffffff810a9496>] warn_slowpath_common+0x86/0xc0
> [   98.503039]  [<ffffffffa02a8e06>] ? bond_poll_controller+0x146/0x250 [bonding]
> [   98.503039]  [<ffffffff810a95ca>] warn_slowpath_null+0x1a/0x20
> [   98.503039]  [<ffffffff810ae376>] __local_bh_enable_ip+0x96/0xc0
> [   98.503039]  [<ffffffffa02a8e2f>] bond_poll_controller+0x16f/0x250 [bonding]
> [   98.503039]  [<ffffffffa02a8cf3>] ? bond_poll_controller+0x33/0x250 [bonding]
> [   98.503039]  [<ffffffff810feaed>] ? trace_hardirqs_off+0xd/0x10
> [   98.503039]  [<ffffffff81848afb>] ? _raw_spin_unlock_irqrestore+0x5b/0x60
> [   98.503039]  [<ffffffff816ec48e>] netpoll_poll_dev+0x6e/0x350
> [   98.503039]  [<ffffffff816eb977>] ? netpoll_start_xmit+0x137/0x1d0
> [   98.503039]  [<ffffffff816b2e8b>] ? __alloc_skb+0x5b/0x210
> [   98.503039]  [<ffffffff816ec89d>] netpoll_send_skb_on_dev+0x12d/0x2a0
> [   98.503039]  [<ffffffff816eccde>] netpoll_send_udp+0x2ce/0x430
> [   98.503039]  [<ffffffffa0190850>] write_msg+0xb0/0xf0 [netconsole]
> [   98.503039]  [<ffffffff81116b63>] call_console_drivers.constprop.25+0x133/0x260
> [   98.503039]  [<ffffffff81117934>] console_unlock+0x2f4/0x580
> [   98.503039]  [<ffffffff81117ea5>] ? vprintk_emit+0x2e5/0x630
> [   98.503039]  [<ffffffff81117ee5>] vprintk_emit+0x325/0x630
> [   98.503039]  [<ffffffff81118379>] vprintk_default+0x29/0x40
> [   98.503039]  [<ffffffff8183de4f>] printk+0x55/0x6b
> [   98.503039]  [<ffffffff816c754c>] __netdev_printk+0x16c/0x260
> [   98.503039]  [<ffffffff816c7a12>] netdev_info+0x62/0x80
> [   98.503039]  [<ffffffffa02ab464>] bond_change_active_slave+0x134/0x6a0 [bonding]
> [   98.503039]  [<ffffffffa02aba95>] bond_select_active_slave+0xc5/0x310 [bonding]
> [   98.503039]  [<ffffffffa02aeb78>] bond_enslave+0x1088/0x10c0 [bonding]
> [   98.503039]  [<ffffffffa02af46b>] bond_do_ioctl+0x37b/0x400 [bonding]
> [   98.503039]  [<ffffffff81101d8d>] ? trace_hardirqs_on+0xd/0x10
> [   98.503039]  [<ffffffff816dc437>] ? rtnl_lock+0x17/0x20
> [   98.503039]  [<ffffffff816e5fd1>] dev_ifsioc+0x331/0x3e0
> [   98.503039]  [<ffffffff816e62dc>] dev_ioctl+0xec/0x6c0
> [   98.503039]  [<ffffffff816a6c6a>] sock_do_ioctl+0x4a/0x60
> [   98.503039]  [<ffffffff816a7300>] sock_ioctl+0x1c0/0x250
> [   98.503039]  [<ffffffff81271bfe>] do_vfs_ioctl+0x2ee/0x540
> [   98.503039]  [<ffffffff810fd943>] ? up_read+0x23/0x40
> [   98.503039]  [<ffffffff81070993>] ? __do_page_fault+0x1d3/0x420
> [   98.503039]  [<ffffffff8127e246>] ? __fget_light+0x66/0x90
> [   98.503039]  [<ffffffff81271ec9>] SyS_ioctl+0x79/0x90
> [   98.503039]  [<ffffffff8184936e>] entry_SYSCALL_64_fastpath+0x12/0x76
> [   98.503039] ---[ end trace 00cfa804b0670051 ]---
> 
> Fixes: 616f45416ca0 ("bonding: implement bond_poll_controller()")
> Signed-off-by: Nikolay Aleksandrov <nikolay@cumulusnetworks.com>
> ---
> drivers/net/bonding/bond_main.c | 4 ++--
> 1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/drivers/net/bonding/bond_main.c b/drivers/net/bonding/bond_main.c
> index a98dd4f1b0e3..1b4b24218807 100644
> --- a/drivers/net/bonding/bond_main.c
> +++ b/drivers/net/bonding/bond_main.c
> @@ -979,7 +979,7 @@ static void bond_poll_controller(struct net_device *bond_dev)
> 		if (bond_3ad_get_active_agg_info(bond, &ad_info))
> 			return;
> 
> -	rcu_read_lock_bh();
> +	rcu_read_lock();
> 	bond_for_each_slave_rcu(bond, slave, iter) {
> 		ops = slave->dev->netdev_ops;
> 		if (!bond_slave_is_up(slave) || !ops->ndo_poll_controller)
> @@ -1000,7 +1000,7 @@ static void bond_poll_controller(struct net_device *bond_dev)
> 		ops->ndo_poll_controller(slave->dev);
> 		up(&ni->dev_lock);
> 	}
> -	rcu_read_unlock_bh();
> +	rcu_read_unlock();
> }
> 
> static void bond_netpoll_cleanup(struct net_device *bond_dev)
> -- 
> 2.4.3
> 

[PATCH net v2] bonding: fix bond_poll_controller bh_enable warning

[Nikolay Aleksandrov]

From: Nikolay Aleksandrov <nikolay@cumulusnetworks.com>

The problem is rcu_read_unlock_bh() which triggers a warning when irqs are
disabled.
ndo_poll_controller can run with bh enabled, disabled or irqs disabled
so check if that is the case and acquire rcu_read_lock_bh only when not
running with disabled irqs. The only potential problem is with
netpoll_send_udp() currently because it can call find_skb() which may
invoke ndo_poll_controller.
We're okay w.r.t to rcu_bh when irqs are disabled so no need to acquire it.
Use the standard rcu_read_lock/unlock to make the non-bh rcu_dereference
happy.
To clarify currently the only user of netpoll_send_udp() is netconsole and
calls it with irqs disabled so we're fine.

[   98.502922] bond0: making interface eth1 the new active one
[   98.503039] ------------[ cut here ]------------
[   98.503039] WARNING: CPU: 0 PID: 1744 at kernel/softirq.c:150 __local_bh_enable_ip+0x96/0xc0()
[   98.503039] Modules linked in: bonding(OE) rpcsec_gss_krb5 nfsv4 dns_resolver nfs fscache netconsole ppdev joydev parport_pc serio_raw parport i2c_piix4 video acpi_cpufreq nfsd auth_rpcgss nfs_acl lockd grace sunrpc virtio_net e1000 ata_generic pcnet32 mii virtio_pci virtio_ring virtio pata_acpi
[   98.503039] CPU: 0 PID: 1744 Comm: ifenslave Tainted: G           OE   4.2.0-rc7+ #56
[   98.503039] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[   98.503039]  0000000000000000 00000000e96ba230 ffff880020c236b8 ffffffff8183f105
[   98.503039]  0000000000000000 0000000000000000 ffff880020c236f8 ffffffff810a9496
[   98.503039]  ffff88002ea99e08 0000000000000200 ffffffffa02a8e06 ffff88002ea99e08
[   98.503039] Call Trace:
[   98.503039]  [<ffffffff8183f105>] dump_stack+0x4c/0x65
[   98.503039]  [<ffffffff810a9496>] warn_slowpath_common+0x86/0xc0
[   98.503039]  [<ffffffffa02a8e06>] ? bond_poll_controller+0x146/0x250 [bonding]
[   98.503039]  [<ffffffff810a95ca>] warn_slowpath_null+0x1a/0x20
[   98.503039]  [<ffffffff810ae376>] __local_bh_enable_ip+0x96/0xc0
[   98.503039]  [<ffffffffa02a8e2f>] bond_poll_controller+0x16f/0x250 [bonding]
[   98.503039]  [<ffffffffa02a8cf3>] ? bond_poll_controller+0x33/0x250 [bonding]
[   98.503039]  [<ffffffff810feaed>] ? trace_hardirqs_off+0xd/0x10
[   98.503039]  [<ffffffff81848afb>] ? _raw_spin_unlock_irqrestore+0x5b/0x60
[   98.503039]  [<ffffffff816ec48e>] netpoll_poll_dev+0x6e/0x350
[   98.503039]  [<ffffffff816eb977>] ? netpoll_start_xmit+0x137/0x1d0
[   98.503039]  [<ffffffff816b2e8b>] ? __alloc_skb+0x5b/0x210
[   98.503039]  [<ffffffff816ec89d>] netpoll_send_skb_on_dev+0x12d/0x2a0
[   98.503039]  [<ffffffff816eccde>] netpoll_send_udp+0x2ce/0x430
[   98.503039]  [<ffffffffa0190850>] write_msg+0xb0/0xf0 [netconsole]
[   98.503039]  [<ffffffff81116b63>] call_console_drivers.constprop.25+0x133/0x260
[   98.503039]  [<ffffffff81117934>] console_unlock+0x2f4/0x580
[   98.503039]  [<ffffffff81117ea5>] ? vprintk_emit+0x2e5/0x630
[   98.503039]  [<ffffffff81117ee5>] vprintk_emit+0x325/0x630
[   98.503039]  [<ffffffff81118379>] vprintk_default+0x29/0x40
[   98.503039]  [<ffffffff8183de4f>] printk+0x55/0x6b
[   98.503039]  [<ffffffff816c754c>] __netdev_printk+0x16c/0x260
[   98.503039]  [<ffffffff816c7a12>] netdev_info+0x62/0x80
[   98.503039]  [<ffffffffa02ab464>] bond_change_active_slave+0x134/0x6a0 [bonding]
[   98.503039]  [<ffffffffa02aba95>] bond_select_active_slave+0xc5/0x310 [bonding]
[   98.503039]  [<ffffffffa02aeb78>] bond_enslave+0x1088/0x10c0 [bonding]
[   98.503039]  [<ffffffffa02af46b>] bond_do_ioctl+0x37b/0x400 [bonding]
[   98.503039]  [<ffffffff81101d8d>] ? trace_hardirqs_on+0xd/0x10
[   98.503039]  [<ffffffff816dc437>] ? rtnl_lock+0x17/0x20
[   98.503039]  [<ffffffff816e5fd1>] dev_ifsioc+0x331/0x3e0
[   98.503039]  [<ffffffff816e62dc>] dev_ioctl+0xec/0x6c0
[   98.503039]  [<ffffffff816a6c6a>] sock_do_ioctl+0x4a/0x60
[   98.503039]  [<ffffffff816a7300>] sock_ioctl+0x1c0/0x250
[   98.503039]  [<ffffffff81271bfe>] do_vfs_ioctl+0x2ee/0x540
[   98.503039]  [<ffffffff810fd943>] ? up_read+0x23/0x40
[   98.503039]  [<ffffffff81070993>] ? __do_page_fault+0x1d3/0x420
[   98.503039]  [<ffffffff8127e246>] ? __fget_light+0x66/0x90
[   98.503039]  [<ffffffff81271ec9>] SyS_ioctl+0x79/0x90
[   98.503039]  [<ffffffff8184936e>] entry_SYSCALL_64_fastpath+0x12/0x76
[   98.503039] ---[ end trace 00cfa804b0670051 ]---

Fixes: 616f45416ca0 ("bonding: implement bond_poll_controller()")
Signed-off-by: Nikolay Aleksandrov <nikolay@cumulusnetworks.com>
---
v2: make sure we're either running with irqs disabled or have rcu_bh
Making it this way to protect against future potential users of
netpoll_send_udp() which may not disable interrupts, if we agree that
it can't be called without disabling interrupts then I can resubmit this
patch without the conditional rcu_bh and possibly add a warn to catch any
future offenders that use it without disabling interrupts.

 drivers/net/bonding/bond_main.c | 11 +++++++++--
 1 file changed, 9 insertions(+), 2 deletions(-)

diff --git a/drivers/net/bonding/bond_main.c b/drivers/net/bonding/bond_main.c
index a98dd4f1b0e3..3197a2180978 100644
--- a/drivers/net/bonding/bond_main.c
+++ b/drivers/net/bonding/bond_main.c
@@ -974,12 +974,17 @@ static void bond_poll_controller(struct net_device *bond_dev)
 	struct ad_info ad_info;
 	struct netpoll_info *ni;
 	const struct net_device_ops *ops;
+	bool rcubh_taken = false;
 
 	if (BOND_MODE(bond) == BOND_MODE_8023AD)
 		if (bond_3ad_get_active_agg_info(bond, &ad_info))
 			return;
 
-	rcu_read_lock_bh();
+	if (!in_irq() && !irqs_disabled()) {
+		rcu_read_lock_bh();
+		rcubh_taken = true;
+	}
+	rcu_read_lock();
 	bond_for_each_slave_rcu(bond, slave, iter) {
 		ops = slave->dev->netdev_ops;
 		if (!bond_slave_is_up(slave) || !ops->ndo_poll_controller)
@@ -1000,7 +1005,9 @@ static void bond_poll_controller(struct net_device *bond_dev)
 		ops->ndo_poll_controller(slave->dev);
 		up(&ni->dev_lock);
 	}
-	rcu_read_unlock_bh();
+	rcu_read_unlock();
+	if (rcubh_taken)
+		rcu_read_unlock_bh();
 }
 
 static void bond_netpoll_cleanup(struct net_device *bond_dev)
-- 
2.4.3

Re: [PATCH net v2] bonding: fix bond_poll_controller bh_enable warning

[David Miller]

From: Nikolay Aleksandrov <razor@blackwall.org>
Date: Fri, 28 Aug 2015 10:22:20 -0700

> The problem is rcu_read_unlock_bh() which triggers a warning when
> irqs are disabled.  ndo_poll_controller can run with bh enabled,
> disabled or irqs disabled so check if that is the case and acquire
> rcu_read_lock_bh only when not running with disabled irqs.

I would say that having hard irqs disabled is a strict requirement, as
per the debugging test in netpoll_send_skb_on_dev():

	WARN_ON_ONCE(!irqs_disabled());

If you want to add the same check to netpoll_send_udp(), that's fine.

But what isn't fine is adding all of this conditional locking, we want
->poll_controller() implementations to be able to depend upon the IRQ
environment they execute in, otherwise every single implementation
might need to have ugly conditional locking as well.

Re: [PATCH net v2] bonding: fix bond_poll_controller bh_enable warning

[Nikolay Aleksandrov]

> On Aug 28, 2015, at 2:13 PM, David Miller <davem@davemloft.net> wrote:
> 
> From: Nikolay Aleksandrov <razor@blackwall.org>
> Date: Fri, 28 Aug 2015 10:22:20 -0700
> 
>> The problem is rcu_read_unlock_bh() which triggers a warning when
>> irqs are disabled.  ndo_poll_controller can run with bh enabled,
>> disabled or irqs disabled so check if that is the case and acquire
>> rcu_read_lock_bh only when not running with disabled irqs.
> 
> I would say that having hard irqs disabled is a strict requirement, as
> per the debugging test in netpoll_send_skb_on_dev():
> 
> 	WARN_ON_ONCE(!irqs_disabled());
> 
> If you want to add the same check to netpoll_send_udp(), that's fine.
> 
> But what isn't fine is adding all of this conditional locking, we want
> ->poll_controller() implementations to be able to depend upon the IRQ
> environment they execute in, otherwise every single implementation
> might need to have ugly conditional locking as well.

Great, that is what I wanted to know because I got confused by some older
commits. This will simplify the fix and I will add the warn_on in netpoll_send_udp().
v3 coming up

Thank you,
 Nik

[PATCH net v3] bonding: fix bond_poll_controller bh_enable warning

[Nikolay Aleksandrov]

From: Nikolay Aleksandrov <nikolay@cumulusnetworks.com>

The problem is rcu_read_unlock_bh() which triggers a warning when irqs are
disabled. ndo_poll_controller should run with irqs disabled always so we
can drop the rcu_read_lock_bh.

[   98.502922] bond0: making interface eth1 the new active one
[   98.503039] ------------[ cut here ]------------
[   98.503039] WARNING: CPU: 0 PID: 1744 at kernel/softirq.c:150 __local_bh_enable_ip+0x96/0xc0()
[   98.503039] Modules linked in: bonding(OE) rpcsec_gss_krb5 nfsv4 dns_resolver nfs fscache netconsole ppdev joydev parport_pc serio_raw parport i2c_piix4 video acpi_cpufreq nfsd auth_rpcgss nfs_acl lockd grace sunrpc virtio_net e1000 ata_generic pcnet32 mii virtio_pci virtio_ring virtio pata_acpi
[   98.503039] CPU: 0 PID: 1744 Comm: ifenslave Tainted: G           OE   4.2.0-rc7+ #56
[   98.503039] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[   98.503039]  0000000000000000 00000000e96ba230 ffff880020c236b8 ffffffff8183f105
[   98.503039]  0000000000000000 0000000000000000 ffff880020c236f8 ffffffff810a9496
[   98.503039]  ffff88002ea99e08 0000000000000200 ffffffffa02a8e06 ffff88002ea99e08
[   98.503039] Call Trace:
[   98.503039]  [<ffffffff8183f105>] dump_stack+0x4c/0x65
[   98.503039]  [<ffffffff810a9496>] warn_slowpath_common+0x86/0xc0
[   98.503039]  [<ffffffffa02a8e06>] ? bond_poll_controller+0x146/0x250 [bonding]
[   98.503039]  [<ffffffff810a95ca>] warn_slowpath_null+0x1a/0x20
[   98.503039]  [<ffffffff810ae376>] __local_bh_enable_ip+0x96/0xc0
[   98.503039]  [<ffffffffa02a8e2f>] bond_poll_controller+0x16f/0x250 [bonding]
[   98.503039]  [<ffffffffa02a8cf3>] ? bond_poll_controller+0x33/0x250 [bonding]
[   98.503039]  [<ffffffff810feaed>] ? trace_hardirqs_off+0xd/0x10
[   98.503039]  [<ffffffff81848afb>] ? _raw_spin_unlock_irqrestore+0x5b/0x60
[   98.503039]  [<ffffffff816ec48e>] netpoll_poll_dev+0x6e/0x350
[   98.503039]  [<ffffffff816eb977>] ? netpoll_start_xmit+0x137/0x1d0
[   98.503039]  [<ffffffff816b2e8b>] ? __alloc_skb+0x5b/0x210
[   98.503039]  [<ffffffff816ec89d>] netpoll_send_skb_on_dev+0x12d/0x2a0
[   98.503039]  [<ffffffff816eccde>] netpoll_send_udp+0x2ce/0x430
[   98.503039]  [<ffffffffa0190850>] write_msg+0xb0/0xf0 [netconsole]
[   98.503039]  [<ffffffff81116b63>] call_console_drivers.constprop.25+0x133/0x260
[   98.503039]  [<ffffffff81117934>] console_unlock+0x2f4/0x580
[   98.503039]  [<ffffffff81117ea5>] ? vprintk_emit+0x2e5/0x630
[   98.503039]  [<ffffffff81117ee5>] vprintk_emit+0x325/0x630
[   98.503039]  [<ffffffff81118379>] vprintk_default+0x29/0x40
[   98.503039]  [<ffffffff8183de4f>] printk+0x55/0x6b
[   98.503039]  [<ffffffff816c754c>] __netdev_printk+0x16c/0x260
[   98.503039]  [<ffffffff816c7a12>] netdev_info+0x62/0x80
[   98.503039]  [<ffffffffa02ab464>] bond_change_active_slave+0x134/0x6a0 [bonding]
[   98.503039]  [<ffffffffa02aba95>] bond_select_active_slave+0xc5/0x310 [bonding]
[   98.503039]  [<ffffffffa02aeb78>] bond_enslave+0x1088/0x10c0 [bonding]
[   98.503039]  [<ffffffffa02af46b>] bond_do_ioctl+0x37b/0x400 [bonding]
[   98.503039]  [<ffffffff81101d8d>] ? trace_hardirqs_on+0xd/0x10
[   98.503039]  [<ffffffff816dc437>] ? rtnl_lock+0x17/0x20
[   98.503039]  [<ffffffff816e5fd1>] dev_ifsioc+0x331/0x3e0
[   98.503039]  [<ffffffff816e62dc>] dev_ioctl+0xec/0x6c0
[   98.503039]  [<ffffffff816a6c6a>] sock_do_ioctl+0x4a/0x60
[   98.503039]  [<ffffffff816a7300>] sock_ioctl+0x1c0/0x250
[   98.503039]  [<ffffffff81271bfe>] do_vfs_ioctl+0x2ee/0x540
[   98.503039]  [<ffffffff810fd943>] ? up_read+0x23/0x40
[   98.503039]  [<ffffffff81070993>] ? __do_page_fault+0x1d3/0x420
[   98.503039]  [<ffffffff8127e246>] ? __fget_light+0x66/0x90
[   98.503039]  [<ffffffff81271ec9>] SyS_ioctl+0x79/0x90
[   98.503039]  [<ffffffff8184936e>] entry_SYSCALL_64_fastpath+0x12/0x76
[   98.503039] ---[ end trace 00cfa804b0670051 ]---

Fixes: 616f45416ca0 ("bonding: implement bond_poll_controller()")
Signed-off-by: Nikolay Aleksandrov <nikolay@cumulusnetworks.com>
---
v3: After Dave made it clear that poll_controller should always be called
with interrupts disabled we can simply drop the rcu bh lock.

 drivers/net/bonding/bond_main.c | 2 --
 1 file changed, 2 deletions(-)

diff --git a/drivers/net/bonding/bond_main.c b/drivers/net/bonding/bond_main.c
index a98dd4f1b0e3..7ab72692d7fd 100644
--- a/drivers/net/bonding/bond_main.c
+++ b/drivers/net/bonding/bond_main.c
@@ -979,7 +979,6 @@ static void bond_poll_controller(struct net_device *bond_dev)
 		if (bond_3ad_get_active_agg_info(bond, &ad_info))
 			return;
 
-	rcu_read_lock_bh();
 	bond_for_each_slave_rcu(bond, slave, iter) {
 		ops = slave->dev->netdev_ops;
 		if (!bond_slave_is_up(slave) || !ops->ndo_poll_controller)
@@ -1000,7 +999,6 @@ static void bond_poll_controller(struct net_device *bond_dev)
 		ops->ndo_poll_controller(slave->dev);
 		up(&ni->dev_lock);
 	}
-	rcu_read_unlock_bh();
 }
 
 static void bond_netpoll_cleanup(struct net_device *bond_dev)
-- 
2.4.3

Re: [PATCH net v3] bonding: fix bond_poll_controller bh_enable warning

[Mahesh Bandewar]

On Fri, Aug 28, 2015 at 3:05 PM, Nikolay Aleksandrov
<razor@blackwall.org> wrote:
>
> From: Nikolay Aleksandrov <nikolay@cumulusnetworks.com>
>
> The problem is rcu_read_unlock_bh() which triggers a warning when irqs are
> disabled. ndo_poll_controller should run with irqs disabled always so we
> can drop the rcu_read_lock_bh.
>
> [   98.502922] bond0: making interface eth1 the new active one
> [   98.503039] ------------[ cut here ]------------
> [   98.503039] WARNING: CPU: 0 PID: 1744 at kernel/softirq.c:150 __local_bh_enable_ip+0x96/0xc0()
> [   98.503039] Modules linked in: bonding(OE) rpcsec_gss_krb5 nfsv4 dns_resolver nfs fscache netconsole ppdev joydev parport_pc serio_raw parport i2c_piix4 video acpi_cpufreq nfsd auth_rpcgss nfs_acl lockd grace sunrpc virtio_net e1000 ata_generic pcnet32 mii virtio_pci virtio_ring virtio pata_acpi
> [   98.503039] CPU: 0 PID: 1744 Comm: ifenslave Tainted: G           OE   4.2.0-rc7+ #56
> [   98.503039] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [   98.503039]  0000000000000000 00000000e96ba230 ffff880020c236b8 ffffffff8183f105
> [   98.503039]  0000000000000000 0000000000000000 ffff880020c236f8 ffffffff810a9496
> [   98.503039]  ffff88002ea99e08 0000000000000200 ffffffffa02a8e06 ffff88002ea99e08
> [   98.503039] Call Trace:
> [   98.503039]  [<ffffffff8183f105>] dump_stack+0x4c/0x65
> [   98.503039]  [<ffffffff810a9496>] warn_slowpath_common+0x86/0xc0
> [   98.503039]  [<ffffffffa02a8e06>] ? bond_poll_controller+0x146/0x250 [bonding]
> [   98.503039]  [<ffffffff810a95ca>] warn_slowpath_null+0x1a/0x20
> [   98.503039]  [<ffffffff810ae376>] __local_bh_enable_ip+0x96/0xc0
> [   98.503039]  [<ffffffffa02a8e2f>] bond_poll_controller+0x16f/0x250 [bonding]
> [   98.503039]  [<ffffffffa02a8cf3>] ? bond_poll_controller+0x33/0x250 [bonding]
> [   98.503039]  [<ffffffff810feaed>] ? trace_hardirqs_off+0xd/0x10
> [   98.503039]  [<ffffffff81848afb>] ? _raw_spin_unlock_irqrestore+0x5b/0x60
> [   98.503039]  [<ffffffff816ec48e>] netpoll_poll_dev+0x6e/0x350
> [   98.503039]  [<ffffffff816eb977>] ? netpoll_start_xmit+0x137/0x1d0
> [   98.503039]  [<ffffffff816b2e8b>] ? __alloc_skb+0x5b/0x210
> [   98.503039]  [<ffffffff816ec89d>] netpoll_send_skb_on_dev+0x12d/0x2a0
> [   98.503039]  [<ffffffff816eccde>] netpoll_send_udp+0x2ce/0x430
> [   98.503039]  [<ffffffffa0190850>] write_msg+0xb0/0xf0 [netconsole]
> [   98.503039]  [<ffffffff81116b63>] call_console_drivers.constprop.25+0x133/0x260
> [   98.503039]  [<ffffffff81117934>] console_unlock+0x2f4/0x580
> [   98.503039]  [<ffffffff81117ea5>] ? vprintk_emit+0x2e5/0x630
> [   98.503039]  [<ffffffff81117ee5>] vprintk_emit+0x325/0x630
> [   98.503039]  [<ffffffff81118379>] vprintk_default+0x29/0x40
> [   98.503039]  [<ffffffff8183de4f>] printk+0x55/0x6b
> [   98.503039]  [<ffffffff816c754c>] __netdev_printk+0x16c/0x260
> [   98.503039]  [<ffffffff816c7a12>] netdev_info+0x62/0x80
> [   98.503039]  [<ffffffffa02ab464>] bond_change_active_slave+0x134/0x6a0 [bonding]
> [   98.503039]  [<ffffffffa02aba95>] bond_select_active_slave+0xc5/0x310 [bonding]
> [   98.503039]  [<ffffffffa02aeb78>] bond_enslave+0x1088/0x10c0 [bonding]
> [   98.503039]  [<ffffffffa02af46b>] bond_do_ioctl+0x37b/0x400 [bonding]
> [   98.503039]  [<ffffffff81101d8d>] ? trace_hardirqs_on+0xd/0x10
> [   98.503039]  [<ffffffff816dc437>] ? rtnl_lock+0x17/0x20
> [   98.503039]  [<ffffffff816e5fd1>] dev_ifsioc+0x331/0x3e0
> [   98.503039]  [<ffffffff816e62dc>] dev_ioctl+0xec/0x6c0
> [   98.503039]  [<ffffffff816a6c6a>] sock_do_ioctl+0x4a/0x60
> [   98.503039]  [<ffffffff816a7300>] sock_ioctl+0x1c0/0x250
> [   98.503039]  [<ffffffff81271bfe>] do_vfs_ioctl+0x2ee/0x540
> [   98.503039]  [<ffffffff810fd943>] ? up_read+0x23/0x40
> [   98.503039]  [<ffffffff81070993>] ? __do_page_fault+0x1d3/0x420
> [   98.503039]  [<ffffffff8127e246>] ? __fget_light+0x66/0x90
> [   98.503039]  [<ffffffff81271ec9>] SyS_ioctl+0x79/0x90
> [   98.503039]  [<ffffffff8184936e>] entry_SYSCALL_64_fastpath+0x12/0x76
> [   98.503039] ---[ end trace 00cfa804b0670051 ]---
>
> Fixes: 616f45416ca0 ("bonding: implement bond_poll_controller()")
> Signed-off-by: Nikolay Aleksandrov <nikolay@cumulusnetworks.com>
Acked-by: Mahesh Bandewar <maheshb@google.com>
> ---
> v3: After Dave made it clear that poll_controller should always be called
> with interrupts disabled we can simply drop the rcu bh lock.
>
I agree with Dave's logic and future users probably have to follow the
same logic.

>  drivers/net/bonding/bond_main.c | 2 --
>  1 file changed, 2 deletions(-)
>
> diff --git a/drivers/net/bonding/bond_main.c b/drivers/net/bonding/bond_main.c
> index a98dd4f1b0e3..7ab72692d7fd 100644
> --- a/drivers/net/bonding/bond_main.c
> +++ b/drivers/net/bonding/bond_main.c
> @@ -979,7 +979,6 @@ static void bond_poll_controller(struct net_device *bond_dev)
>                 if (bond_3ad_get_active_agg_info(bond, &ad_info))
>                         return;
>
> -       rcu_read_lock_bh();
>         bond_for_each_slave_rcu(bond, slave, iter) {
>                 ops = slave->dev->netdev_ops;
>                 if (!bond_slave_is_up(slave) || !ops->ndo_poll_controller)
> @@ -1000,7 +999,6 @@ static void bond_poll_controller(struct net_device *bond_dev)
>                 ops->ndo_poll_controller(slave->dev);
>                 up(&ni->dev_lock);
>         }
> -       rcu_read_unlock_bh();
>  }
>
>  static void bond_netpoll_cleanup(struct net_device *bond_dev)
> --
> 2.4.3
>

Re: [PATCH net v3] bonding: fix bond_poll_controller bh_enable warning

[David Miller]

From: Nikolay Aleksandrov <razor@blackwall.org>
Date: Fri, 28 Aug 2015 15:05:32 -0700

> From: Nikolay Aleksandrov <nikolay@cumulusnetworks.com>
> 
> The problem is rcu_read_unlock_bh() which triggers a warning when irqs are
> disabled. ndo_poll_controller should run with irqs disabled always so we
> can drop the rcu_read_lock_bh.
 ...
> Fixes: 616f45416ca0 ("bonding: implement bond_poll_controller()")
> Signed-off-by: Nikolay Aleksandrov <nikolay@cumulusnetworks.com>
> ---
> v3: After Dave made it clear that poll_controller should always be called
> with interrupts disabled we can simply drop the rcu bh lock.

Applied.