RTNL: assertion failed at net/core/dev.c (4494) and RTNL: assertion failed at net/core/rtnetlink.c (940)

RTNL: assertion failed at net/core/dev.c (4494) and RTNL: assertion failed at net/core/rtnetlink.c (940)

[Thomas Glanzmann]

Hello,
this morning I checked out Linus tip and compiled it after booting my
dmesg is full of:

[    8.944991] RTNL: assertion failed at net/core/dev.c (4494)
[    8.950640] CPU: 3 PID: 388 Comm: kworker/u24:4 Not tainted 3.14.0-rc1+ #3
[    8.950642] Hardware name: Supermicro X9SRD-F/X9SRD-F, BIOS 1.0a 10/15/2012
[    8.950654] Workqueue: bond0 bond_3ad_state_machine_handler [bonding]
[    8.950658]  0000000000000000 ffff881020c88000 ffffffff8138e219 ffff881020c88000
[    8.950664]  ffffffff812d3091 ffff881023961040 ffffffff812e3132 0000000000000246
[    8.950670]  0000000000000020 ffff881020ab1be8 0000000020ab1ba8 0000000000000000
[    8.950675] Call Trace:
[    8.950686]  [<ffffffff8138e219>] ? dump_stack+0x41/0x51
[    8.950694]  [<ffffffff812d3091>] ? netdev_master_upper_dev_get+0x2a/0x4d
[    8.950699]  [<ffffffff812e3132>] ? rtnl_fill_ifinfo+0x2c/0xac4
[    8.950707]  [<ffffffff81072211>] ? print_time.part.5+0x50/0x54
[    8.950715]  [<ffffffff812caf94>] ? __kmalloc_reserve.isra.42+0x2a/0x6d
[    8.950721]  [<ffffffff81102040>] ? ksize+0x12/0x1e
[    8.950726]  [<ffffffff812cb2b7>] ? __alloc_skb+0xb5/0x1a9
[    8.950731]  [<ffffffff812e4626>] ? rtmsg_ifinfo+0x6c/0xd6
[    8.950739]  [<ffffffffa035f4f9>] ? __enable_port.isra.17+0x51/0x5a [bonding]
[    8.950747]  [<ffffffffa0360463>] ? ad_agg_selection_logic+0x3d3/0x3ed [bonding]
[    8.950754]  [<ffffffffa0360d40>] ? bond_3ad_state_machine_handler+0x555/0x918 [bonding]
[    8.950761]  [<ffffffff8104db2d>] ? process_one_work+0x191/0x293
[    8.950766]  [<ffffffff8104dfde>] ? worker_thread+0x121/0x1e7
[    8.950770]  [<ffffffff8104debd>] ? rescuer_thread+0x269/0x269
[    8.950777]  [<ffffffff810527b6>] ? kthread+0x99/0xa1
[    8.950782]  [<ffffffff8105271d>] ? __kthread_parkme+0x59/0x59
[    8.950789]  [<ffffffff8139733c>] ? ret_from_fork+0x7c/0xb0
[    8.950794]  [<ffffffff8105271d>] ? __kthread_parkme+0x59/0x59
[    8.950797] RTNL: assertion failed at net/core/rtnetlink.c (940)
[    8.956863] CPU: 3 PID: 388 Comm: kworker/u24:4 Not tainted 3.14.0-rc1+ #3
[    8.956871] Hardware name: Supermicro X9SRD-F/X9SRD-F, BIOS 1.0a 10/15/2012
[    8.956877] Workqueue: bond0 bond_3ad_state_machine_handler [bonding]
[    8.956879]  0000000000000000 ffff881020c88000 ffffffff8138e219 ffff881023961040
[    8.956884]  ffffffff812e315e 0000000000000246 0000000000000020 ffff881020ab1be8
[    8.956890]  0000000020ab1ba8 0000000000000000 ffffffff817ef530 0000000000000008
[    8.956895] Call Trace:
[    8.956899]  [<ffffffff8138e219>] ? dump_stack+0x41/0x51
[    8.956903]  [<ffffffff812e315e>] ? rtnl_fill_ifinfo+0x58/0xac4
[    8.956909]  [<ffffffff81072211>] ? print_time.part.5+0x50/0x54
[    8.956915]  [<ffffffff812caf94>] ? __kmalloc_reserve.isra.42+0x2a/0x6d
[    8.956920]  [<ffffffff81102040>] ? ksize+0x12/0x1e
[    8.956925]  [<ffffffff812cb2b7>] ? __alloc_skb+0xb5/0x1a9
[    8.956929]  [<ffffffff812e4626>] ? rtmsg_ifinfo+0x6c/0xd6
[    8.956936]  [<ffffffffa035f4f9>] ? __enable_port.isra.17+0x51/0x5a [bonding]
[    8.956942]  [<ffffffffa0360463>] ? ad_agg_selection_logic+0x3d3/0x3ed [bonding]
[    8.956949]  [<ffffffffa0360d40>] ? bond_3ad_state_machine_handler+0x555/0x918 [bonding]
[    8.956954]  [<ffffffff8104db2d>] ? process_one_work+0x191/0x293
[    8.956958]  [<ffffffff8104dfde>] ? worker_thread+0x121/0x1e7
[    8.956962]  [<ffffffff8104debd>] ? rescuer_thread+0x269/0x269
[    8.956968]  [<ffffffff810527b6>] ? kthread+0x99/0xa1
[    8.956973]  [<ffffffff8105271d>] ? __kthread_parkme+0x59/0x59
[    8.956978]  [<ffffffff8139733c>] ? ret_from_fork+0x7c/0xb0
[    8.956983]  [<ffffffff8105271d>] ? __kthread_parkme+0x59/0x59

Full dmesg is at: http://pbot.rmdir.de/dJZsX0d71RFPaZAAjcTBWQ

I'm running Debian Wheezy and my Interface Konfiguration is:

auto lo
iface lo inet loopback

auto bond0
iface bond0 inet static
       address 10.100.4.62
       netmask 255.255.0.0
       gateway 10.100.0.1
       slaves eth0 eth1
       bond-mode 802.3ad
       bond-miimon 100

auto bond0.101
iface bond0.101 inet static
       address 10.101.99.4
       netmask 255.255.0.0

auto bond0.102
iface bond0.102 inet static
       address 10.102.99.4
       netmask 255.255.0.0

auto bond0.103
iface bond0.103 inet static
       address 10.103.99.4
       netmask 255.255.0.0

auto bond1
iface bond1 inet static
       address 10.100.5.62
       netmask 255.255.0.0
       slaves eth2 eth3
       bond-mode 802.3ad
       bond-miimon 100

auto bond1.101
iface bond1.101 inet static
       address 10.101.99.5
       netmask 255.255.0.0

auto bond1.102
iface bond1.102 inet static
       address 10.102.99.5
       netmask 255.255.0.0

auto bond1.103
iface bond1.103 inet static
       address 10.103.99.5
       netmask 255.255.0.0

My IPv4 interface Konfiguration is:

(node-62) [~/work/linux-2.6] ip -4 a s
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
6: bond0: <BROADCAST,MULTICAST,MASTER,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP
    inet 10.100.4.62/16 brd 10.100.255.255 scope global bond0
       valid_lft forever preferred_lft forever
7: bond0.101@bond0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP
    inet 10.101.99.4/16 brd 10.101.255.255 scope global bond0.101
       valid_lft forever preferred_lft forever
8: bond0.102@bond0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP
    inet 10.102.99.4/16 brd 10.102.255.255 scope global bond0.102
       valid_lft forever preferred_lft forever
9: bond0.103@bond0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP
    inet 10.103.99.4/16 brd 10.103.255.255 scope global bond0.103
       valid_lft forever preferred_lft forever
10: bond1: <BROADCAST,MULTICAST,MASTER,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP
    inet 10.100.5.62/16 brd 10.100.255.255 scope global bond1
       valid_lft forever preferred_lft forever
11: bond1.101@bond1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP
    inet 10.101.99.5/16 brd 10.101.255.255 scope global bond1.101
       valid_lft forever preferred_lft forever
12: bond1.102@bond1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP
    inet 10.102.99.5/16 brd 10.102.255.255 scope global bond1.102
       valid_lft forever preferred_lft forever
13: bond1.103@bond1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP
    inet 10.103.99.5/16 brd 10.103.255.255 scope global bond1.103
       valid_lft forever preferred_lft forever

I also have IPv6 with link-local and global addresses configured.

Kernel Config is at: http://pbot.rmdir.de/VTAnhVv8ECP7a7SPaxMsFA

I'm available for testing fixes or providing ssh access to the system if you
want to do further tests. I have the same config running on 3.13.0 on the same
machine without any problems whatsoever. If I should bisect it, let me know.

Cheers,
        Thomas

Re: RTNL: assertion failed at net/core/dev.c (4494) and RTNL: assertion failed at net/core/rtnetlink.c (940)

[Cong Wang]

On Thu, Feb 6, 2014 at 12:51 PM, Thomas Glanzmann <thomas@glanzmann.de> wrote:
> Hello,
> this morning I checked out Linus tip and compiled it after booting my
> dmesg is full of:
>
> [    8.944991] RTNL: assertion failed at net/core/dev.c (4494)
> [    8.950640] CPU: 3 PID: 388 Comm: kworker/u24:4 Not tainted 3.14.0-rc1+ #3
> [    8.950642] Hardware name: Supermicro X9SRD-F/X9SRD-F, BIOS 1.0a 10/15/2012
> [    8.950654] Workqueue: bond0 bond_3ad_state_machine_handler [bonding]
> [    8.950658]  0000000000000000 ffff881020c88000 ffffffff8138e219 ffff881020c88000
> [    8.950664]  ffffffff812d3091 ffff881023961040 ffffffff812e3132 0000000000000246
> [    8.950670]  0000000000000020 ffff881020ab1be8 0000000020ab1ba8 0000000000000000
> [    8.950675] Call Trace:
> [    8.950686]  [<ffffffff8138e219>] ? dump_stack+0x41/0x51
> [    8.950694]  [<ffffffff812d3091>] ? netdev_master_upper_dev_get+0x2a/0x4d
> [    8.950699]  [<ffffffff812e3132>] ? rtnl_fill_ifinfo+0x2c/0xac4
> [    8.950707]  [<ffffffff81072211>] ? print_time.part.5+0x50/0x54
> [    8.950715]  [<ffffffff812caf94>] ? __kmalloc_reserve.isra.42+0x2a/0x6d
> [    8.950721]  [<ffffffff81102040>] ? ksize+0x12/0x1e
> [    8.950726]  [<ffffffff812cb2b7>] ? __alloc_skb+0xb5/0x1a9
> [    8.950731]  [<ffffffff812e4626>] ? rtmsg_ifinfo+0x6c/0xd6
> [    8.950739]  [<ffffffffa035f4f9>] ? __enable_port.isra.17+0x51/0x5a [bonding]
> [    8.950747]  [<ffffffffa0360463>] ? ad_agg_selection_logic+0x3d3/0x3ed [bonding]
> [    8.950754]  [<ffffffffa0360d40>] ? bond_3ad_state_machine_handler+0x555/0x918 [bonding]
> [    8.950761]  [<ffffffff8104db2d>] ? process_one_work+0x191/0x293
> [    8.950766]  [<ffffffff8104dfde>] ? worker_thread+0x121/0x1e7
> [    8.950770]  [<ffffffff8104debd>] ? rescuer_thread+0x269/0x269
> [    8.950777]  [<ffffffff810527b6>] ? kthread+0x99/0xa1
> [    8.950782]  [<ffffffff8105271d>] ? __kthread_parkme+0x59/0x59
> [    8.950789]  [<ffffffff8139733c>] ? ret_from_fork+0x7c/0xb0
> [    8.950794]  [<ffffffff8105271d>] ? __kthread_parkme+0x59/0x59


Hmm, rtmsg_ifinfo() should be called with rtnl lock, but
__enable_port() is called
with rcu_read_lock() which means we can't block inside it, therefore we probably
should take rtnl lock outside:

diff --git a/drivers/net/bonding/bond_3ad.c b/drivers/net/bonding/bond_3ad.c
index cce1f1b..3c09ffa 100644
--- a/drivers/net/bonding/bond_3ad.c
+++ b/drivers/net/bonding/bond_3ad.c
@@ -2065,6 +2065,7 @@ void bond_3ad_state_machine_handler(struct
work_struct *work)
        struct slave *slave;
        struct port *port;

+       rtnl_lock();
        read_lock(&bond->lock);
        rcu_read_lock();

@@ -2123,6 +2124,7 @@ void bond_3ad_state_machine_handler(struct
work_struct *work)
 re_arm:
        rcu_read_unlock();
        read_unlock(&bond->lock);
+       rtnl_unlock();
        queue_delayed_work(bond->wq, &bond->ad_work, ad_delta_in_ticks);
 }

Re: RTNL: assertion failed at net/core/dev.c (4494) and RTNL: assertion failed at net/core/rtnetlink.c (940)

[Jay Vosburgh]

Cong Wang <cwang@twopensource.com> wrote:

>On Thu, Feb 6, 2014 at 12:51 PM, Thomas Glanzmann <thomas@glanzmann.de> wrote:
>> Hello,
>> this morning I checked out Linus tip and compiled it after booting my
>> dmesg is full of:
>>
>> [    8.944991] RTNL: assertion failed at net/core/dev.c (4494)
>> [    8.950640] CPU: 3 PID: 388 Comm: kworker/u24:4 Not tainted 3.14.0-rc1+ #3
>> [    8.950642] Hardware name: Supermicro X9SRD-F/X9SRD-F, BIOS 1.0a 10/15/2012
>> [    8.950654] Workqueue: bond0 bond_3ad_state_machine_handler [bonding]
>> [    8.950658]  0000000000000000 ffff881020c88000 ffffffff8138e219 ffff881020c88000
>> [    8.950664]  ffffffff812d3091 ffff881023961040 ffffffff812e3132 0000000000000246
>> [    8.950670]  0000000000000020 ffff881020ab1be8 0000000020ab1ba8 0000000000000000
>> [    8.950675] Call Trace:
>> [    8.950686]  [<ffffffff8138e219>] ? dump_stack+0x41/0x51
>> [    8.950694]  [<ffffffff812d3091>] ? netdev_master_upper_dev_get+0x2a/0x4d
>> [    8.950699]  [<ffffffff812e3132>] ? rtnl_fill_ifinfo+0x2c/0xac4
>> [    8.950707]  [<ffffffff81072211>] ? print_time.part.5+0x50/0x54
>> [    8.950715]  [<ffffffff812caf94>] ? __kmalloc_reserve.isra.42+0x2a/0x6d
>> [    8.950721]  [<ffffffff81102040>] ? ksize+0x12/0x1e
>> [    8.950726]  [<ffffffff812cb2b7>] ? __alloc_skb+0xb5/0x1a9
>> [    8.950731]  [<ffffffff812e4626>] ? rtmsg_ifinfo+0x6c/0xd6
>> [    8.950739]  [<ffffffffa035f4f9>] ? __enable_port.isra.17+0x51/0x5a [bonding]
>> [    8.950747]  [<ffffffffa0360463>] ? ad_agg_selection_logic+0x3d3/0x3ed [bonding]
>> [    8.950754]  [<ffffffffa0360d40>] ? bond_3ad_state_machine_handler+0x555/0x918 [bonding]
>> [    8.950761]  [<ffffffff8104db2d>] ? process_one_work+0x191/0x293
>> [    8.950766]  [<ffffffff8104dfde>] ? worker_thread+0x121/0x1e7
>> [    8.950770]  [<ffffffff8104debd>] ? rescuer_thread+0x269/0x269
>> [    8.950777]  [<ffffffff810527b6>] ? kthread+0x99/0xa1
>> [    8.950782]  [<ffffffff8105271d>] ? __kthread_parkme+0x59/0x59
>> [    8.950789]  [<ffffffff8139733c>] ? ret_from_fork+0x7c/0xb0
>> [    8.950794]  [<ffffffff8105271d>] ? __kthread_parkme+0x59/0x59
>
>
>Hmm, rtmsg_ifinfo() should be called with rtnl lock, but
>__enable_port() is called
>with rcu_read_lock() which means we can't block inside it, therefore we probably
>should take rtnl lock outside:
>
>diff --git a/drivers/net/bonding/bond_3ad.c b/drivers/net/bonding/bond_3ad.c
>index cce1f1b..3c09ffa 100644
>--- a/drivers/net/bonding/bond_3ad.c
>+++ b/drivers/net/bonding/bond_3ad.c
>@@ -2065,6 +2065,7 @@ void bond_3ad_state_machine_handler(struct
>work_struct *work)
>        struct slave *slave;
>        struct port *port;
>
>+       rtnl_lock();
>        read_lock(&bond->lock);
>        rcu_read_lock();
>
>@@ -2123,6 +2124,7 @@ void bond_3ad_state_machine_handler(struct
>work_struct *work)
> re_arm:
>        rcu_read_unlock();
>        read_unlock(&bond->lock);
>+       rtnl_unlock();
>        queue_delayed_work(bond->wq, &bond->ad_work, ad_delta_in_ticks);
> }

	That would eliminate the warning, but is suboptimal.  Acquiring
RTNL is not necessary on the vast majority of state machine runs
(because no state changes take place, i.e., no ports are disabled or
enabled).  The above change would add 10 round trips per second to RTNL,
which seems excessive.

	Also, we cannot unconditionally acquire RTNL in this function,
as it would race with the call to cancel_delayed_work_sync from
bond_close (via bond_work_cancel_all).

	-J

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

Re: RTNL: assertion failed at net/core/dev.c (4494) and RTNL: assertion failed at net/core/rtnetlink.c (940)

[Jay Vosburgh]

Jay Vosburgh <fubar@us.ibm.com> wrote:

>Cong Wang <cwang@twopensource.com> wrote:
>
>>On Thu, Feb 6, 2014 at 12:51 PM, Thomas Glanzmann <thomas@glanzmann.de> wrote:
>>> Hello,
>>> this morning I checked out Linus tip and compiled it after booting my
>>> dmesg is full of:
>>>
>>> [    8.944991] RTNL: assertion failed at net/core/dev.c (4494)
>>> [    8.950640] CPU: 3 PID: 388 Comm: kworker/u24:4 Not tainted 3.14.0-rc1+ #3
>>> [    8.950642] Hardware name: Supermicro X9SRD-F/X9SRD-F, BIOS 1.0a 10/15/2012
>>> [    8.950654] Workqueue: bond0 bond_3ad_state_machine_handler [bonding]
>>> [    8.950658]  0000000000000000 ffff881020c88000 ffffffff8138e219 ffff881020c88000
>>> [    8.950664]  ffffffff812d3091 ffff881023961040 ffffffff812e3132 0000000000000246
>>> [    8.950670]  0000000000000020 ffff881020ab1be8 0000000020ab1ba8 0000000000000000
>>> [    8.950675] Call Trace:
>>> [    8.950686]  [<ffffffff8138e219>] ? dump_stack+0x41/0x51
>>> [    8.950694]  [<ffffffff812d3091>] ? netdev_master_upper_dev_get+0x2a/0x4d
>>> [    8.950699]  [<ffffffff812e3132>] ? rtnl_fill_ifinfo+0x2c/0xac4
>>> [    8.950707]  [<ffffffff81072211>] ? print_time.part.5+0x50/0x54
>>> [    8.950715]  [<ffffffff812caf94>] ? __kmalloc_reserve.isra.42+0x2a/0x6d
>>> [    8.950721]  [<ffffffff81102040>] ? ksize+0x12/0x1e
>>> [    8.950726]  [<ffffffff812cb2b7>] ? __alloc_skb+0xb5/0x1a9
>>> [    8.950731]  [<ffffffff812e4626>] ? rtmsg_ifinfo+0x6c/0xd6
>>> [    8.950739]  [<ffffffffa035f4f9>] ? __enable_port.isra.17+0x51/0x5a [bonding]
>>> [    8.950747]  [<ffffffffa0360463>] ? ad_agg_selection_logic+0x3d3/0x3ed [bonding]
>>> [    8.950754]  [<ffffffffa0360d40>] ? bond_3ad_state_machine_handler+0x555/0x918 [bonding]
>>> [    8.950761]  [<ffffffff8104db2d>] ? process_one_work+0x191/0x293
>>> [    8.950766]  [<ffffffff8104dfde>] ? worker_thread+0x121/0x1e7
>>> [    8.950770]  [<ffffffff8104debd>] ? rescuer_thread+0x269/0x269
>>> [    8.950777]  [<ffffffff810527b6>] ? kthread+0x99/0xa1
>>> [    8.950782]  [<ffffffff8105271d>] ? __kthread_parkme+0x59/0x59
>>> [    8.950789]  [<ffffffff8139733c>] ? ret_from_fork+0x7c/0xb0
>>> [    8.950794]  [<ffffffff8105271d>] ? __kthread_parkme+0x59/0x59
>>
>>
>>Hmm, rtmsg_ifinfo() should be called with rtnl lock, but
>>__enable_port() is called
>>with rcu_read_lock() which means we can't block inside it, therefore we probably
>>should take rtnl lock outside:
>>
>>diff --git a/drivers/net/bonding/bond_3ad.c b/drivers/net/bonding/bond_3ad.c
>>index cce1f1b..3c09ffa 100644
>>--- a/drivers/net/bonding/bond_3ad.c
>>+++ b/drivers/net/bonding/bond_3ad.c
>>@@ -2065,6 +2065,7 @@ void bond_3ad_state_machine_handler(struct
>>work_struct *work)
>>        struct slave *slave;
>>        struct port *port;
>>
>>+       rtnl_lock();
>>        read_lock(&bond->lock);
>>        rcu_read_lock();
>>
>>@@ -2123,6 +2124,7 @@ void bond_3ad_state_machine_handler(struct
>>work_struct *work)
>> re_arm:
>>        rcu_read_unlock();
>>        read_unlock(&bond->lock);
>>+       rtnl_unlock();
>>        queue_delayed_work(bond->wq, &bond->ad_work, ad_delta_in_ticks);
>> }
>
>	That would eliminate the warning, but is suboptimal.  Acquiring
>RTNL is not necessary on the vast majority of state machine runs
>(because no state changes take place, i.e., no ports are disabled or
>enabled).  The above change would add 10 round trips per second to RTNL,
>which seems excessive.
>
>	Also, we cannot unconditionally acquire RTNL in this function,
>as it would race with the call to cancel_delayed_work_sync from
>bond_close (via bond_work_cancel_all).

	Thought of one more problem: we can't hold a regular lock while
calling rtmsg_ifinfo, as it may sleep in alloc_skb.  The rtmsg_ifinfo
call has to be RTNL and nothing else.

	-J

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

Re: RTNL: assertion failed at net/core/dev.c (4494) and RTNL: assertion failed at net/core/rtnetlink.c (940)

[Cong Wang]

On Thu, Feb 6, 2014 at 2:07 PM, Jay Vosburgh <fubar@us.ibm.com> wrote:
> Jay Vosburgh <fubar@us.ibm.com> wrote:
>
>>Cong Wang <cwang@twopensource.com> wrote:
>>
>>
>>       That would eliminate the warning, but is suboptimal.  Acquiring
>>RTNL is not necessary on the vast majority of state machine runs
>>(because no state changes take place, i.e., no ports are disabled or
>>enabled).  The above change would add 10 round trips per second to RTNL,
>>which seems excessive.
>>
>>       Also, we cannot unconditionally acquire RTNL in this function,
>>as it would race with the call to cancel_delayed_work_sync from
>>bond_close (via bond_work_cancel_all).

OK.

>
>         Thought of one more problem: we can't hold a regular lock while
> calling rtmsg_ifinfo, as it may sleep in alloc_skb.  The rtmsg_ifinfo
> call has to be RTNL and nothing else.
>

s/GFP_KERNEL/GFP_ATOMIC/

Re: RTNL: assertion failed at net/core/dev.c (4494) and RTNL: assertion failed at net/core/rtnetlink.c (940)

[Jay Vosburgh]

Cong Wang <cwang@twopensource.com> wrote:

>On Thu, Feb 6, 2014 at 2:07 PM, Jay Vosburgh <fubar@us.ibm.com> wrote:
>> Jay Vosburgh <fubar@us.ibm.com> wrote:
>>
>>>Cong Wang <cwang@twopensource.com> wrote:
>>>
>>>
>>>       That would eliminate the warning, but is suboptimal.  Acquiring
>>>RTNL is not necessary on the vast majority of state machine runs
>>>(because no state changes take place, i.e., no ports are disabled or
>>>enabled).  The above change would add 10 round trips per second to RTNL,
>>>which seems excessive.
>>>
>>>       Also, we cannot unconditionally acquire RTNL in this function,
>>>as it would race with the call to cancel_delayed_work_sync from
>>>bond_close (via bond_work_cancel_all).
>
>OK.
>
>>
>>         Thought of one more problem: we can't hold a regular lock while
>> calling rtmsg_ifinfo, as it may sleep in alloc_skb.  The rtmsg_ifinfo
>> call has to be RTNL and nothing else.
>>
>
>s/GFP_KERNEL/GFP_ATOMIC/

	Yah, that would help with extra locks, but not totally solve
things.  I'm looking around, and seeing a number of other places that
will end up at one of these rtmsg_ifinfo calls with incorrect locking:

	bond_ab_arp_probe calls via bond_set_slave_active_flags and
bond_set_slave_inactive_flags without RTNL.

	bond_change_active_slave calls via bond_set_slave_inactive_flags
and bond_set_slave_active_flags with other locks held, and maybe without
RTNL; I'm not sure if bond_option_active_slave_set holds RTNL when it
calls bond_select_active_slave.

	bond_open calls via bond_set_slave_active_flags and
bond_set_slave_inactive_flags with RTNL, but also with other locks held.

	bond_loadbalance_arp_mon calls bond_set_active_slave and
bond_set_backup_slave without RTNL.

	This is in addition to the cases in the 802.3ad code from
__enable_port and __disable_port calls.

	-J

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

Re: RTNL: assertion failed at net/core/dev.c (4494) and RTNL: assertion failed at net/core/rtnetlink.c (940)

[Jay Vosburgh]

Jay Vosburgh <fubar@us.ibm.com> wrote:

>
>Cong Wang <cwang@twopensource.com> wrote:
>
>>On Thu, Feb 6, 2014 at 2:07 PM, Jay Vosburgh <fubar@us.ibm.com> wrote:
>>> Jay Vosburgh <fubar@us.ibm.com> wrote:
>>>
>>>>Cong Wang <cwang@twopensource.com> wrote:
>>>>
>>>>
>>>>       That would eliminate the warning, but is suboptimal.  Acquiring
>>>>RTNL is not necessary on the vast majority of state machine runs
>>>>(because no state changes take place, i.e., no ports are disabled or
>>>>enabled).  The above change would add 10 round trips per second to RTNL,
>>>>which seems excessive.
>>>>
>>>>       Also, we cannot unconditionally acquire RTNL in this function,
>>>>as it would race with the call to cancel_delayed_work_sync from
>>>>bond_close (via bond_work_cancel_all).
>>
>>OK.
>>
>>>
>>>         Thought of one more problem: we can't hold a regular lock while
>>> calling rtmsg_ifinfo, as it may sleep in alloc_skb.  The rtmsg_ifinfo
>>> call has to be RTNL and nothing else.
>>>
>>
>>s/GFP_KERNEL/GFP_ATOMIC/
>
>	Yah, that would help with extra locks, but not totally solve
>things.  I'm looking around, and seeing a number of other places that
>will end up at one of these rtmsg_ifinfo calls with incorrect locking:
>
>	bond_ab_arp_probe calls via bond_set_slave_active_flags and
>bond_set_slave_inactive_flags without RTNL.
>
>	bond_change_active_slave calls via bond_set_slave_inactive_flags
>and bond_set_slave_active_flags with other locks held, and maybe without
>RTNL; I'm not sure if bond_option_active_slave_set holds RTNL when it
>calls bond_select_active_slave.
>
>	bond_open calls via bond_set_slave_active_flags and
>bond_set_slave_inactive_flags with RTNL, but also with other locks held.
>
>	bond_loadbalance_arp_mon calls bond_set_active_slave and
>bond_set_backup_slave without RTNL.
>
>	This is in addition to the cases in the 802.3ad code from
>__enable_port and __disable_port calls.

	Just an update in case anybody else is looking into this, and
some questions for Scott.

	Acquiring RTNL for the __enable_port and __disable_port cases is
difficult, as those calls generally already hold the state machine lock,
and cannot unconditionally call rtnl_lock because either they already
hold RTNL (for calls via bond_3ad_unbind_slave) or due to the potential
for deadlock with bond_3ad_adapter_speed_changed,
bond_3ad_adapter_duplex_changed, bond_3ad_link_change, or
bond_3ad_update_lacp_rate.  All four of those are called with RTNL held,
and acquire the state machine lock second.  The calling contexts for
__enable_port and __disable_port already hold the state machine lock,
and may or may not need RTNL.

	Scott: you added these calls, so can you explain what they're
for?  I'm asking for two reasons:

	First, if they do not occur synchronously is it going to be a
problem?  E.g., for the 802.3ad case, if the rtmsg_ifinfo is called
either at the end of the state machine run, or for non-state machine
events, at the next run of the state machine (which is every 100 ms),
would that be a problem?  Setting a flag in the slave somewhere that an
rtmsg_ifinfo is needed should be doable for the 802.3ad case.

	Second, what do the messages mean?  That the slave is now
"active and usable"?  I'm asking because I suspect the bond_ab_arp_probe
usage wherein it adjusts the flags and curr_active_slave should not
actually call rtmsg_ifinfo, as the slave there is not really "up."
What's going on there is that the ARP monitor cycles through each slave
one by one, and tests to see if that slave works.  If it does work, then
it is set as the active elsewhere in the monitor code.  This function
adjusts the flags so that the ARP monitor will treat the "testing" slave
as "active" for purposes of determining whether or not it is up.  I
suspect this adjustment to the flags should not actually generate an
rtmsg_ifinfo.

	I think the remaining cases can be dealt with, but clarification
on the above two questions would be very helpful.

	-J

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

Re: RTNL: assertion failed at net/core/dev.c (4494) and RTNL: assertion failed at net/core/rtnetlink.c (940)

[Ding Tianhong]

On 2014/2/8 9:21, Jay Vosburgh wrote:
> Jay Vosburgh <fubar@us.ibm.com> wrote:
> 
>>
>> Cong Wang <cwang@twopensource.com> wrote:
>>
>>> On Thu, Feb 6, 2014 at 2:07 PM, Jay Vosburgh <fubar@us.ibm.com> wrote:
>>>> Jay Vosburgh <fubar@us.ibm.com> wrote:
>>>>
>>>>> Cong Wang <cwang@twopensource.com> wrote:
>>>>>
>>>>>
>>>>>       That would eliminate the warning, but is suboptimal.  Acquiring
>>>>> RTNL is not necessary on the vast majority of state machine runs
>>>>> (because no state changes take place, i.e., no ports are disabled or
>>>>> enabled).  The above change would add 10 round trips per second to RTNL,
>>>>> which seems excessive.
>>>>>
>>>>>       Also, we cannot unconditionally acquire RTNL in this function,
>>>>> as it would race with the call to cancel_delayed_work_sync from
>>>>> bond_close (via bond_work_cancel_all).
>>>
>>> OK.
>>>
>>>>
>>>>         Thought of one more problem: we can't hold a regular lock while
>>>> calling rtmsg_ifinfo, as it may sleep in alloc_skb.  The rtmsg_ifinfo
>>>> call has to be RTNL and nothing else.
>>>>
>>>
>>> s/GFP_KERNEL/GFP_ATOMIC/
>>
>> 	Yah, that would help with extra locks, but not totally solve
>> things.  I'm looking around, and seeing a number of other places that
>> will end up at one of these rtmsg_ifinfo calls with incorrect locking:
>>
>> 	bond_ab_arp_probe calls via bond_set_slave_active_flags and
>> bond_set_slave_inactive_flags without RTNL.
>>
>> 	bond_change_active_slave calls via bond_set_slave_inactive_flags
>> and bond_set_slave_active_flags with other locks held, and maybe without
>> RTNL; I'm not sure if bond_option_active_slave_set holds RTNL when it
>> calls bond_select_active_slave.
>>
>> 	bond_open calls via bond_set_slave_active_flags and
>> bond_set_slave_inactive_flags with RTNL, but also with other locks held.
>>
>> 	bond_loadbalance_arp_mon calls bond_set_active_slave and
>> bond_set_backup_slave without RTNL.
>>
>> 	This is in addition to the cases in the 802.3ad code from
>> __enable_port and __disable_port calls.
> 
> 	Just an update in case anybody else is looking into this, and
> some questions for Scott.
> 
> 	Acquiring RTNL for the __enable_port and __disable_port cases is
> difficult, as those calls generally already hold the state machine lock,
> and cannot unconditionally call rtnl_lock because either they already
> hold RTNL (for calls via bond_3ad_unbind_slave) or due to the potential
> for deadlock with bond_3ad_adapter_speed_changed,
> bond_3ad_adapter_duplex_changed, bond_3ad_link_change, or
> bond_3ad_update_lacp_rate.  All four of those are called with RTNL held,
> and acquire the state machine lock second.  The calling contexts for
> __enable_port and __disable_port already hold the state machine lock,
> and may or may not need RTNL.

Agree, it is hard to add RTNL here, deadlock is easily happened.

> 
> 	Scott: you added these calls, so can you explain what they're
> for?  I'm asking for two reasons:
> 
> 	First, if they do not occur synchronously is it going to be a
> problem?  E.g., for the 802.3ad case, if the rtmsg_ifinfo is called
> either at the end of the state machine run, or for non-state machine
> events, at the next run of the state machine (which is every 100 ms),
> would that be a problem?  Setting a flag in the slave somewhere that an
> rtmsg_ifinfo is needed should be doable for the 802.3ad case.
> 
> 	Second, what do the messages mean?  That the slave is now
> "active and usable"?  I'm asking because I suspect the bond_ab_arp_probe
> usage wherein it adjusts the flags and curr_active_slave should not
> actually call rtmsg_ifinfo, as the slave there is not really "up."
> What's going on there is that the ARP monitor cycles through each slave
> one by one, and tests to see if that slave works.  If it does work, then
> it is set as the active elsewhere in the monitor code.  This function
> adjusts the flags so that the ARP monitor will treat the "testing" slave
> as "active" for purposes of determining whether or not it is up.  I
> suspect this adjustment to the flags should not actually generate an
> rtmsg_ifinfo.
> 
> 	I think the remaining cases can be dealt with, but clarification
> on the above two questions would be very helpful.
> 
> 	-J
> 

commit 6fde8f037e604e05df1529 fix the problem for bond_loadbalance_arp_mon(),
and commit 66dd1c077a3f3c130d1 fix the problem for bond_activebackup_arp_mon(),
but we still miss the 3ad monitor, I think if the slave should send the message
by netlink, it is better to refer to fdb_notify() for bridge,I doubts that why we need to send so many
message, just slave info is enough, then RTNL is not needed here.

Ding


> ---
> 	-Jay Vosburgh, IBM Linux Technology Center, fubar@us.ibm.com
> 
> --
> To unsubscribe from this list: send the line "unsubscribe netdev" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 
> .
> 

Re: RTNL: assertion failed at net/core/dev.c (4494) and RTNL: assertion failed at net/core/rtnetlink.c (940)

[Jay Vosburgh]

Thomas Glanzmann <thomas@glanzmann.de> wrote:

>Hello,
>this morning I checked out Linus tip and compiled it after booting my
>dmesg is full of:
>
>[    8.944991] RTNL: assertion failed at net/core/dev.c (4494)
>[    8.950640] CPU: 3 PID: 388 Comm: kworker/u24:4 Not tainted 3.14.0-rc1+ #3
>[    8.950642] Hardware name: Supermicro X9SRD-F/X9SRD-F, BIOS 1.0a 10/15/2012
>[    8.950654] Workqueue: bond0 bond_3ad_state_machine_handler [bonding]
>[    8.950658]  0000000000000000 ffff881020c88000 ffffffff8138e219 ffff881020c88000
>[    8.950664]  ffffffff812d3091 ffff881023961040 ffffffff812e3132 0000000000000246
>[    8.950670]  0000000000000020 ffff881020ab1be8 0000000020ab1ba8 0000000000000000
>[    8.950675] Call Trace:
>[    8.950686]  [<ffffffff8138e219>] ? dump_stack+0x41/0x51
>[    8.950694]  [<ffffffff812d3091>] ? netdev_master_upper_dev_get+0x2a/0x4d
>[    8.950699]  [<ffffffff812e3132>] ? rtnl_fill_ifinfo+0x2c/0xac4
>[    8.950707]  [<ffffffff81072211>] ? print_time.part.5+0x50/0x54
>[    8.950715]  [<ffffffff812caf94>] ? __kmalloc_reserve.isra.42+0x2a/0x6d
>[    8.950721]  [<ffffffff81102040>] ? ksize+0x12/0x1e
>[    8.950726]  [<ffffffff812cb2b7>] ? __alloc_skb+0xb5/0x1a9
>[    8.950731]  [<ffffffff812e4626>] ? rtmsg_ifinfo+0x6c/0xd6
>[    8.950739]  [<ffffffffa035f4f9>] ? __enable_port.isra.17+0x51/0x5a [bonding]
>[    8.950747]  [<ffffffffa0360463>] ? ad_agg_selection_logic+0x3d3/0x3ed [bonding]
>[    8.950754]  [<ffffffffa0360d40>] ? bond_3ad_state_machine_handler+0x555/0x918 [bonding]

	This was apparently introduced by commit:

commit 1d3ee88ae0d605629bf369ab0b868dae8ca62a48
Author: sfeldma@cumulusnetworks.com <sfeldma@cumulusnetworks.com>
Date:   Thu Jan 16 22:57:56 2014 -0800

    bonding: add netlink attributes to slave link dev
    

	which adds an "rtmsg_ifinfo" call to bond_set_active_slave and
bond_set_backup_slave, both of which are invoked in several places in
the 802.3ad code without RTNL held (via __enable_port and
__disable_port).

	Still looking into a fix.

	-J

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