Modify

Opened 4 years ago

#15540 new defect

Race condition with VLANs over mesh wireless networks in Netifd

Reported by: VittGam <openwrt@…> Owned by: developers
Priority: normal Milestone: Netifd Implementation
Component: packages Version: Trunk
Keywords: Cc:

Description

I'm using this config. Sometimes when I do wifi the VLANs don't come up.

It seems like a race condition: if daemon.notice netifd: Network device 'mesh0' link is up comes before daemon.notice netifd: Network device 'wlan0' link is up, the VLANs don't get loaded. Otherwise it's fine.

Also, when the race condition gets fired and I do wifi again, it seems to catch the interfaces up, then bring them down again and recognize them (but this time because wlan0 came before mesh0...)

Please note that I applied my ​patch 5149 for the authsae, but this problem happens consistently even without that. I just need to run wifi until the problem triggers.

logread when wifi is successful:

Fri Apr 11 22:42:36 2014 kern.info kernel: [ 8919.600000] device wlan0 left promiscuous mode
Fri Apr 11 22:42:36 2014 kern.info kernel: [ 8919.600000] br-lan: port 2(wlan0) entered disabled state
Fri Apr 11 22:42:36 2014 daemon.notice netifd: Network device 'wlan0' link is down
Fri Apr 11 22:42:36 2014 daemon.notice netifd: Network device 'mesh0' link is down
Fri Apr 11 22:42:36 2014 daemon.notice netifd: Network alias 'mesh0' link is down
Fri Apr 11 22:42:36 2014 daemon.notice netifd: VLAN 'mesh0.2' link is down
Fri Apr 11 22:42:36 2014 daemon.notice netifd: VLAN 'mesh0.1' link is down
Fri Apr 11 22:42:36 2014 daemon.notice netifd: Interface 'mesh' has link connectivity loss
Fri Apr 11 22:42:36 2014 kern.info kernel: [ 8919.660000] br-mgmt: port 1(mesh0.1) entered disabled state
Fri Apr 11 22:42:36 2014 kern.info kernel: [ 8919.660000] device mesh0 left promiscuous mode
Fri Apr 11 22:42:36 2014 kern.info kernel: [ 8919.670000] br-lan: port 3(mesh0.2) entered disabled state
Fri Apr 11 22:42:36 2014 kern.info kernel: [ 8919.680000] IPv6: ADDRCONF(NETDEV_UP): mesh0.2: link is not ready
Fri Apr 11 22:42:36 2014 kern.info kernel: [ 8919.680000] br-lan: port 3(mesh0.2) entered disabled state
Fri Apr 11 22:42:36 2014 kern.info kernel: [ 8919.710000] br-mgmt: port 1(mesh0.1) entered disabled state
Fri Apr 11 22:42:36 2014 daemon.notice netifd: Interface 'mgmt' is now down
Fri Apr 11 22:42:36 2014 daemon.notice netifd: Interface 'mgmt' is disabled
Fri Apr 11 22:42:36 2014 daemon.notice netifd: Interface 'mesh' is disabled
Fri Apr 11 22:42:36 2014 daemon.notice netifd: Bridge 'br-mgmt' link is down
Fri Apr 11 22:42:36 2014 daemon.notice netifd: Interface 'mgmt' has link connectivity loss
Fri Apr 11 22:42:37 2014 kern.info kernel: [ 8920.930000] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Fri Apr 11 22:42:37 2014 kern.info kernel: [ 8920.970000] device wlan0 entered promiscuous mode
Fri Apr 11 22:42:37 2014 kern.info kernel: [ 8920.970000] br-lan: port 2(wlan0) entered forwarding state
Fri Apr 11 22:42:37 2014 kern.info kernel: [ 8920.980000] br-lan: port 2(wlan0) entered forwarding state
Fri Apr 11 22:42:38 2014 kern.info kernel: [ 8921.610000] br-lan: port 2(wlan0) entered disabled state
Fri Apr 11 22:42:38 2014 kern.info kernel: [ 8921.640000] br-lan: port 2(wlan0) entered forwarding state
Fri Apr 11 22:42:38 2014 kern.info kernel: [ 8921.640000] br-lan: port 2(wlan0) entered forwarding state
Fri Apr 11 22:42:38 2014 kern.info kernel: [ 8921.650000] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Fri Apr 11 22:42:38 2014 kern.info kernel: [ 8921.810000] IPv6: ADDRCONF(NETDEV_UP): mesh0: link is not ready
Fri Apr 11 22:42:38 2014 kern.info kernel: [ 8921.890000] IPv6: ADDRCONF(NETDEV_CHANGE): mesh0: link becomes ready
Fri Apr 11 22:42:38 2014 daemon.notice netifd: Network device 'wlan0' link is up
Fri Apr 11 22:42:38 2014 daemon.notice netifd: Network device 'mesh0' link is up
Fri Apr 11 22:42:38 2014 daemon.notice netifd: Interface 'mesh' is enabled
Fri Apr 11 22:42:38 2014 daemon.notice netifd: Interface 'mesh' has link connectivity 
Fri Apr 11 22:42:38 2014 daemon.notice netifd: Interface 'mesh' is setting up now
Fri Apr 11 22:42:38 2014 kern.info kernel: [ 8922.070000] device mesh0.2 entered promiscuous mode
Fri Apr 11 22:42:38 2014 kern.info kernel: [ 8922.080000] device mesh0 entered promiscuous mode
Fri Apr 11 22:42:38 2014 kern.info kernel: [ 8922.080000] br-lan: port 3(mesh0.2) entered forwarding state
Fri Apr 11 22:42:38 2014 kern.info kernel: [ 8922.090000] br-lan: port 3(mesh0.2) entered forwarding state
Fri Apr 11 22:42:38 2014 kern.info kernel: [ 8922.130000] device mesh0.1 entered promiscuous mode
Fri Apr 11 22:42:38 2014 kern.info kernel: [ 8922.160000] br-mgmt: port 1(mesh0.1) entered forwarding state
Fri Apr 11 22:42:38 2014 kern.info kernel: [ 8922.160000] br-mgmt: port 1(mesh0.1) entered forwarding state
Fri Apr 11 22:42:38 2014 daemon.notice netifd: Interface 'mgmt' is enabled
Fri Apr 11 22:42:38 2014 daemon.notice netifd: Network alias 'mesh0' link is up
Fri Apr 11 22:42:38 2014 daemon.notice netifd: VLAN 'mesh0.2' link is up
Fri Apr 11 22:42:38 2014 daemon.notice netifd: VLAN 'mesh0.1' link is up
Fri Apr 11 22:42:38 2014 daemon.notice netifd: Interface 'mesh' is now up
Fri Apr 11 22:42:38 2014 daemon.notice netifd: Bridge 'br-mgmt' link is up
Fri Apr 11 22:42:38 2014 daemon.notice netifd: Interface 'mgmt' has link connectivity 
Fri Apr 11 22:42:38 2014 daemon.notice netifd: Interface 'mgmt' is setting up now
Fri Apr 11 22:42:38 2014 daemon.notice netifd: Interface 'mgmt' is now up
Fri Apr 11 22:42:39 2014 kern.info kernel: [ 8922.610000] IPv6: ADDRCONF(NETDEV_CHANGE): mesh0.2: link becomes ready
Fri Apr 11 22:42:39 2014 kern.info kernel: [ 8922.610000] IPv6: ADDRCONF(NETDEV_CHANGE): mesh0.1: link becomes ready
Fri Apr 11 22:42:40 2014 kern.info kernel: [ 8923.640000] br-lan: port 2(wlan0) entered forwarding state
Fri Apr 11 22:42:40 2014 user.notice firewall: Reloading firewall due to ifup of mgmt (br-mgmt)
Fri Apr 11 22:42:40 2014 kern.info kernel: [ 8924.090000] br-lan: port 3(mesh0.2) entered forwarding state
Fri Apr 11 22:42:40 2014 kern.info kernel: [ 8924.160000] br-mgmt: port 1(mesh0.1) entered forwarding state

logread when wifi is NOT successful:

Fri Apr 11 22:42:44 2014 kern.info kernel: [ 8927.880000] device wlan0 left promiscuous mode
Fri Apr 11 22:42:44 2014 kern.info kernel: [ 8927.880000] br-lan: port 2(wlan0) entered disabled state
Fri Apr 11 22:42:44 2014 daemon.notice netifd: Network device 'wlan0' link is down
Fri Apr 11 22:42:44 2014 daemon.notice netifd: Network device 'mesh0' link is down
Fri Apr 11 22:42:44 2014 daemon.notice netifd: Network alias 'mesh0' link is down
Fri Apr 11 22:42:44 2014 daemon.notice netifd: VLAN 'mesh0.2' link is down
Fri Apr 11 22:42:44 2014 daemon.notice netifd: VLAN 'mesh0.1' link is down
Fri Apr 11 22:42:44 2014 daemon.notice netifd: Interface 'mesh' has link connectivity loss
Fri Apr 11 22:42:44 2014 kern.info kernel: [ 8927.940000] br-mgmt: port 1(mesh0.1) entered disabled state
Fri Apr 11 22:42:44 2014 kern.info kernel: [ 8927.940000] device mesh0 left promiscuous mode
Fri Apr 11 22:42:44 2014 kern.info kernel: [ 8927.950000] br-lan: port 3(mesh0.2) entered disabled state
Fri Apr 11 22:42:44 2014 kern.info kernel: [ 8927.960000] IPv6: ADDRCONF(NETDEV_UP): mesh0.2: link is not ready
Fri Apr 11 22:42:44 2014 kern.info kernel: [ 8927.960000] br-lan: port 3(mesh0.2) entered disabled state
Fri Apr 11 22:42:44 2014 kern.info kernel: [ 8928.010000] br-mgmt: port 1(mesh0.1) entered disabled state
Fri Apr 11 22:42:44 2014 daemon.notice netifd: Interface 'mgmt' is now down
Fri Apr 11 22:42:44 2014 daemon.notice netifd: Interface 'mgmt' is disabled
Fri Apr 11 22:42:44 2014 daemon.notice netifd: Interface 'mesh' is disabled
Fri Apr 11 22:42:44 2014 daemon.notice netifd: Bridge 'br-mgmt' link is down
Fri Apr 11 22:42:44 2014 daemon.notice netifd: Interface 'mgmt' has link connectivity loss
Fri Apr 11 22:42:45 2014 kern.info kernel: [ 8929.210000] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Fri Apr 11 22:42:45 2014 kern.info kernel: [ 8929.240000] device wlan0 entered promiscuous mode
Fri Apr 11 22:42:45 2014 kern.info kernel: [ 8929.240000] br-lan: port 2(wlan0) entered forwarding state
Fri Apr 11 22:42:45 2014 kern.info kernel: [ 8929.240000] br-lan: port 2(wlan0) entered forwarding state
Fri Apr 11 22:42:46 2014 kern.info kernel: [ 8929.890000] br-lan: port 2(wlan0) entered disabled state
Fri Apr 11 22:42:46 2014 kern.info kernel: [ 8929.920000] br-lan: port 2(wlan0) entered forwarding state
Fri Apr 11 22:42:46 2014 kern.info kernel: [ 8929.920000] br-lan: port 2(wlan0) entered forwarding state
Fri Apr 11 22:42:46 2014 kern.info kernel: [ 8929.930000] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Fri Apr 11 22:42:46 2014 kern.info kernel: [ 8930.100000] IPv6: ADDRCONF(NETDEV_UP): mesh0: link is not ready
Fri Apr 11 22:42:46 2014 daemon.notice netifd: Network device 'mesh0' link is up
Fri Apr 11 22:42:46 2014 kern.info kernel: [ 8930.200000] IPv6: ADDRCONF(NETDEV_CHANGE): mesh0: link becomes ready
Fri Apr 11 22:42:46 2014 daemon.notice netifd: Network device 'wlan0' link is up
Fri Apr 11 22:42:46 2014 daemon.notice netifd: Interface 'mesh' has link connectivity 
Fri Apr 11 22:42:48 2014 kern.info kernel: [ 8931.920000] br-lan: port 2(wlan0) entered forwarding state

logread doing wifi after that:

Fri Apr 11 22:52:21 2014 daemon.notice netifd: Interface 'mesh' is enabled
Fri Apr 11 22:52:21 2014 daemon.notice netifd: Interface 'mesh' is setting up now
Fri Apr 11 22:52:21 2014 kern.info kernel: [ 9505.130000] device mesh0.2 entered promiscuous mode
Fri Apr 11 22:52:21 2014 kern.info kernel: [ 9505.130000] device mesh0 entered promiscuous mode
Fri Apr 11 22:52:21 2014 kern.info kernel: [ 9505.140000] br-lan: port 3(mesh0.2) entered forwarding state
Fri Apr 11 22:52:21 2014 kern.info kernel: [ 9505.140000] br-lan: port 3(mesh0.2) entered forwarding state
Fri Apr 11 22:52:21 2014 kern.info kernel: [ 9505.180000] device mesh0.1 entered promiscuous mode
Fri Apr 11 22:52:21 2014 kern.info kernel: [ 9505.230000] br-mgmt: port 1(mesh0.1) entered forwarding state
Fri Apr 11 22:52:21 2014 kern.info kernel: [ 9505.230000] br-mgmt: port 1(mesh0.1) entered forwarding state
Fri Apr 11 22:52:21 2014 daemon.notice netifd: Interface 'mgmt' is enabled
Fri Apr 11 22:52:21 2014 daemon.notice netifd: Network alias 'mesh0' link is up
Fri Apr 11 22:52:21 2014 daemon.notice netifd: VLAN 'mesh0.2' link is up
Fri Apr 11 22:52:21 2014 daemon.notice netifd: VLAN 'mesh0.1' link is up
Fri Apr 11 22:52:21 2014 daemon.notice netifd: Interface 'mesh' is now up
Fri Apr 11 22:52:21 2014 daemon.notice netifd: Bridge 'br-mgmt' link is up
Fri Apr 11 22:52:21 2014 daemon.notice netifd: Interface 'mgmt' has link connectivity 
Fri Apr 11 22:52:21 2014 daemon.notice netifd: Interface 'mgmt' is setting up now
Fri Apr 11 22:52:21 2014 daemon.notice netifd: Interface 'mgmt' is now up
Fri Apr 11 22:52:22 2014 kern.info kernel: [ 9505.660000] device wlan0 left promiscuous mode
Fri Apr 11 22:52:22 2014 kern.info kernel: [ 9505.670000] br-lan: port 2(wlan0) entered disabled state
Fri Apr 11 22:52:22 2014 daemon.notice netifd: Network device 'wlan0' link is down
Fri Apr 11 22:52:22 2014 daemon.notice netifd: Network device 'mesh0' link is down
Fri Apr 11 22:52:22 2014 daemon.notice netifd: Network alias 'mesh0' link is down
Fri Apr 11 22:52:22 2014 daemon.notice netifd: VLAN 'mesh0.2' link is down
Fri Apr 11 22:52:22 2014 daemon.notice netifd: VLAN 'mesh0.1' link is down
Fri Apr 11 22:52:22 2014 daemon.notice netifd: Interface 'mesh' has link connectivity loss
Fri Apr 11 22:52:22 2014 kern.info kernel: [ 9505.800000] br-mgmt: port 1(mesh0.1) entered disabled state
Fri Apr 11 22:52:22 2014 kern.info kernel: [ 9505.800000] device mesh0 left promiscuous mode
Fri Apr 11 22:52:22 2014 kern.info kernel: [ 9505.800000] br-lan: port 3(mesh0.2) entered disabled state
Fri Apr 11 22:52:22 2014 kern.info kernel: [ 9505.820000] IPv6: ADDRCONF(NETDEV_UP): mesh0.2: link is not ready
Fri Apr 11 22:52:22 2014 kern.info kernel: [ 9505.820000] br-lan: port 3(mesh0.2) entered disabled state
Fri Apr 11 22:52:22 2014 kern.info kernel: [ 9505.850000] br-mgmt: port 1(mesh0.1) entered disabled state
Fri Apr 11 22:52:22 2014 daemon.notice netifd: Interface 'mgmt' is now down
Fri Apr 11 22:52:22 2014 daemon.notice netifd: Interface 'mgmt' is disabled
Fri Apr 11 22:52:22 2014 daemon.notice netifd: Interface 'mesh' is disabled
Fri Apr 11 22:52:22 2014 daemon.notice netifd: Bridge 'br-mgmt' link is down
Fri Apr 11 22:52:22 2014 daemon.notice netifd: Interface 'mgmt' has link connectivity loss
Fri Apr 11 22:52:24 2014 kern.info kernel: [ 9507.590000] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Fri Apr 11 22:52:24 2014 kern.info kernel: [ 9507.610000] device wlan0 entered promiscuous mode
Fri Apr 11 22:52:25 2014 kern.info kernel: [ 9508.830000] br-lan: port 2(wlan0) entered forwarding state
Fri Apr 11 22:52:25 2014 kern.info kernel: [ 9508.840000] br-lan: port 2(wlan0) entered forwarding state
Fri Apr 11 22:52:25 2014 kern.info kernel: [ 9508.840000] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Fri Apr 11 22:52:25 2014 kern.info kernel: [ 9509.000000] IPv6: ADDRCONF(NETDEV_UP): mesh0: link is not ready
Fri Apr 11 22:52:25 2014 kern.info kernel: [ 9509.090000] IPv6: ADDRCONF(NETDEV_CHANGE): mesh0: link becomes ready
Fri Apr 11 22:52:25 2014 daemon.notice netifd: Network device 'wlan0' link is up
Fri Apr 11 22:52:25 2014 daemon.notice netifd: Network device 'mesh0' link is up
Fri Apr 11 22:52:25 2014 daemon.notice netifd: Interface 'mesh' is enabled
Fri Apr 11 22:52:25 2014 daemon.notice netifd: Interface 'mesh' has link connectivity 
Fri Apr 11 22:52:25 2014 daemon.notice netifd: Interface 'mesh' is setting up now
Fri Apr 11 22:52:25 2014 kern.info kernel: [ 9509.270000] device mesh0.2 entered promiscuous mode
Fri Apr 11 22:52:25 2014 kern.info kernel: [ 9509.270000] device mesh0 entered promiscuous mode
Fri Apr 11 22:52:25 2014 kern.info kernel: [ 9509.280000] br-lan: port 3(mesh0.2) entered forwarding state
Fri Apr 11 22:52:25 2014 kern.info kernel: [ 9509.280000] br-lan: port 3(mesh0.2) entered forwarding state
Fri Apr 11 22:52:25 2014 kern.info kernel: [ 9509.330000] device mesh0.1 entered promiscuous mode
Fri Apr 11 22:52:25 2014 kern.info kernel: [ 9509.330000] br-mgmt: port 1(mesh0.1) entered forwarding state
Fri Apr 11 22:52:25 2014 kern.info kernel: [ 9509.340000] br-mgmt: port 1(mesh0.1) entered forwarding state
Fri Apr 11 22:52:25 2014 daemon.notice netifd: Interface 'mgmt' is enabled
Fri Apr 11 22:52:25 2014 daemon.notice netifd: Network alias 'mesh0' link is up
Fri Apr 11 22:52:25 2014 daemon.notice netifd: VLAN 'mesh0.2' link is up
Fri Apr 11 22:52:25 2014 daemon.notice netifd: VLAN 'mesh0.1' link is up
Fri Apr 11 22:52:25 2014 daemon.notice netifd: Interface 'mesh' is now up
Fri Apr 11 22:52:25 2014 daemon.notice netifd: Bridge 'br-mgmt' link is up
Fri Apr 11 22:52:25 2014 daemon.notice netifd: Interface 'mgmt' has link connectivity 
Fri Apr 11 22:52:25 2014 daemon.notice netifd: Interface 'mgmt' is setting up now
Fri Apr 11 22:52:25 2014 daemon.notice netifd: Interface 'mgmt' is now up
Fri Apr 11 22:52:26 2014 kern.info kernel: [ 9509.830000] IPv6: ADDRCONF(NETDEV_CHANGE): mesh0.2: link becomes ready
Fri Apr 11 22:52:26 2014 kern.info kernel: [ 9509.830000] IPv6: ADDRCONF(NETDEV_CHANGE): mesh0.1: link becomes ready
Fri Apr 11 22:52:27 2014 kern.info kernel: [ 9510.840000] br-lan: port 2(wlan0) entered forwarding state
Fri Apr 11 22:52:27 2014 user.notice firewall: Reloading firewall due to ifup of mgmt (br-mgmt)
Fri Apr 11 22:52:27 2014 kern.info kernel: [ 9511.280000] br-lan: port 3(mesh0.2) entered forwarding state
Fri Apr 11 22:52:27 2014 kern.info kernel: [ 9511.340000] br-mgmt: port 1(mesh0.1) entered forwarding state

(This was on a wr703n so the config for the mgmt network only has option ifname '@mesh.1', without eth1.)

Attachments (0)

Change History (0)

Add Comment

Modify Ticket

Action
as new .
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.