R7800 bridge discrepancies between boots

mha · April 10, 2020, 9:33pm

Hi!

I've been running dd-wrt (both stock and Kong builds) on my Netgear R7800's at home for quite some time. I thought it might be time to switch camp and try out what OpenWRT has to offer.

My use case is extremely simple;

The WAN port has 5 tagged WLANs. One for management and 8 for different SSIDs (4x 2.4GHz and 4x 5GHz). I've disabled everything in startup that is unrelated to these very basic features. Namely the following services are disabled:

dnsmasq
firewall
banip
adblock
odhcpd
minidlna
acme
qos
nlbwmon
etherwake
http-dns-proxy
e2guardian
openvpn
vpnbypass
miniupnpd
ddns
privoxy
samba4

I've defined 5 interfaces whereof 4 bridge types and one just for management. The bridged interfaces has the following configuration;

Device: br-500
Physical interfaces: eth0.500, wlan0-3, wlan1-3

Everything is pretty much working. But I notice that when rebooting the device different bridges get different wlanX-X devices added randomly. Example:

root@wifi:~# brctl show
bridge name     bridge id               STP enabled     interfaces
br-200          7fff.3c37862ac466       no              eth0.200
                                                        wlan1-1
                                                        wlan0-1
br-300          7fff.3c37862ac466       no              eth0.300
br-400          7fff.3c37862ac466       no              eth0.400
br-403          7fff.3c37862ac466       no              eth0.403
br-500          7fff.3c37862ac466       no              eth0.500
                                                        wlan1-3
                                                        wlan0-3

Where a correct list would look like;

bridge name     bridge id               STP enabled     interfaces
br-200          7fff.3c37862ac466       no              eth0.200
                                                        wlan1-1
                                                        wlan0-1
br-300          7fff.3c37862ac466       no              eth0.300
                                                        wlan1-2
                                                        wlan0-2
br-400          7fff.3c37862ac466       no              eth0.400
                                                        wlan0
                                                        wlan1
br-403          7fff.3c37862ac466       no              eth0.403
br-500          7fff.3c37862ac466       no              eth0.500
                                                        wlan1-3
                                                        wlan0-3

Now, adding them after boot has completed is not an issue using brctl addif. And my workaround has been to add a custom startup script essentially starting by doing sleep 60 then all the addif's.

It seems to bottle down to that the wlanX-X interfaces are not fully ready / brought up before attemted to be added to the bridge. If it's not ready, it's not added and will never be after boot has completed.

This is however just a theory.

I'm running Kong's latest build of OpenWRT, if this is an issue for any testing let me know

Firmware Version

KONG 19 2020-01 / LuCI branch git-20.067.56216-e71f6b1

Sparks · April 11, 2020, 12:29am

Interesting, sounds like a timing/race condition.

Does the issue happen on vanilla openwrt as well ?

mha · April 12, 2020, 9:11am

Flashed the latest snapshot of OpenWRT on to the device and installed LuCI. Had to reconfigure wireless interfaces as they would not come up at all. But after first boot the issue was replicated on the following build aswell;

OpenWrt SNAPSHOT r12911-e66becb490 / LuCI Master git-20.099.28711-ae5cd59

brctl output;

bridge name     bridge id               STP enabled     interfaces
br-200          7fff.3c37862ac466       no              eth0.200
br-500          7fff.3c37862ac466       no              wlan1-3
                                                        eth0.500
br-400          7fff.3c37862ac466       no              eth0.400
br-300          7fff.3c37862ac466       no              eth0.300
br-403          7fff.3c37862ac466       no              eth0.403

Kernel output;

[   13.295532] ath10k_pci 0000:01:00.0: assign IRQ: got 35
[   13.295554] ath10k 5.1 driver, optimized for CT firmware, probing pci device: 0x46.
[   13.296264] ath10k_pci 0000:01:00.0: enabling device (0140 -> 0142)
[   13.302148] ath10k_pci 0000:01:00.0: enabling bus mastering
[   13.302664] ath10k_pci 0000:01:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0
[   14.029496] ath10k_pci 0000:01:00.0: qca9984/qca9994 hw1.0 target 0x01000000 chip_id 0x00000000 sub 168c:cafe
[   14.029528] ath10k_pci 0000:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 0
[   14.040026] ath10k_pci 0000:01:00.0: firmware ver 10.4b-ct-9984-fW-013-b63cea875 api 5 features mfp,peer-flow-ctrl,txstatus-noack,wmi-10.x-CT,ratemask-CT,regdump-CT,txrate-CT,flush-all-CT,pingpong-CT,ch-regs-CT,nop-CT,set-special-CT,tx-rc-CT,cust-stats-CT,txrate2-CT,beacon-cb-CT,wmi-block-ack-CT,wmi-bcn-rc-CT crc32 d36ca749
[   16.368388] ath10k_pci 0000:01:00.0: board_file api 2 bmi_id 0:1 crc32 85498734
[   22.210635] ath10k_pci 0000:01:00.0: unsupported HTC service id: 1536
[   22.211795] ath10k_pci 0000:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   22.216051] ath10k_pci 0000:01:00.0: msdu-desc: 2500  skid: 32
[   22.299462] ath10k_pci 0000:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   22.300319] ath10k_pci 0000:01:00.0: wmi print 'free: 81824 iram: 13124 sram: 14440'
[   22.589099] ath10k_pci 0000:01:00.0: htt-ver 2.2 wmi-op 6 htt-op 4 cal pre-cal-file max-sta 32 raw 0 hwcrypto 1
[   22.682510] ath: EEPROM regdomain: 0x0
[   22.682524] ath: EEPROM indicates default country code should be used
[   22.682533] ath: doing EEPROM country->regdmn map search
[   22.682551] ath: country maps to regdmn code: 0x3a
[   22.682564] ath: Country alpha2 being used: US
[   22.682573] ath: Regpair used: 0x3a
[   22.687983] ath10k_pci 0001:01:00.0: assign IRQ: got 37
[   22.688013] ath10k 5.1 driver, optimized for CT firmware, probing pci device: 0x46.
[   22.688917] ath10k_pci 0001:01:00.0: enabling device (0140 -> 0142)
[   22.694644] ath10k_pci 0001:01:00.0: enabling bus mastering
[   22.695359] ath10k_pci 0001:01:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0
[   23.235612] ath10k_pci 0001:01:00.0: qca9984/qca9994 hw1.0 target 0x01000000 chip_id 0x00000000 sub 168c:cafe
[   23.235647] ath10k_pci 0001:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 0
[   23.247008] ath10k_pci 0001:01:00.0: firmware ver 10.4b-ct-9984-fW-013-b63cea875 api 5 features mfp,peer-flow-ctrl,txstatus-noack,wmi-10.x-CT,ratemask-CT,regdump-CT,txrate-CT,flush-all-CT,pingpong-CT,ch-regs-CT,nop-CT,set-special-CT,tx-rc-CT,cust-stats-CT,txrate2-CT,beacon-cb-CT,wmi-block-ack-CT,wmi-bcn-rc-CT crc32 d36ca749
[   25.564510] ath10k_pci 0001:01:00.0: board_file api 2 bmi_id 0:2 crc32 85498734
[   31.393495] ath10k_pci 0001:01:00.0: unsupported HTC service id: 1536
[   31.394291] ath10k_pci 0001:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   31.398909] ath10k_pci 0001:01:00.0: msdu-desc: 2500  skid: 32
[   31.484411] ath10k_pci 0001:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   31.485279] ath10k_pci 0001:01:00.0: wmi print 'free: 81824 iram: 13124 sram: 14440'
[   31.878829] ath10k_pci 0001:01:00.0: htt-ver 2.2 wmi-op 6 htt-op 4 cal pre-cal-file max-sta 32 raw 0 hwcrypto 1
[   31.972519] ath: EEPROM regdomain: 0x0
[   31.972534] ath: EEPROM indicates default country code should be used
[   31.972543] ath: doing EEPROM country->regdmn map search
[   31.972561] ath: country maps to regdmn code: 0x3a
[   31.972574] ath: Country alpha2 being used: US
[   31.972584] ath: Regpair used: 0x3a
[   31.987395] kmodloader: done loading kernel modules from /etc/modules.d/*
[   35.563926] dwmac1000: Master AXI performs any burst length
[   35.563955] ipq806x-gmac-dwmac 37200000.ethernet eth0: No Safety Features support found
[   35.568306] ipq806x-gmac-dwmac 37200000.ethernet eth0: IEEE 1588-2008 Advanced Timestamp supported
[   35.576483] ipq806x-gmac-dwmac 37200000.ethernet eth0: registered PTP clock
[   35.585399] ipq806x-gmac-dwmac 37200000.ethernet eth0: configuring for fixed/rgmii link mode
[   35.593270] ipq806x-gmac-dwmac 37200000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
[   35.601503] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   35.615735] br-200: port 1(eth0.200) entered blocking state
[   35.615766] br-200: port 1(eth0.200) entered disabled state
[   35.621490] device eth0.200 entered promiscuous mode
[   35.626804] device eth0 entered promiscuous mode
[   35.635308] br-200: port 1(eth0.200) entered blocking state
[   35.636618] br-200: port 1(eth0.200) entered forwarding state
[   35.706132] br-300: port 1(eth0.300) entered blocking state
[   35.706154] br-300: port 1(eth0.300) entered disabled state
[   35.710764] device eth0.300 entered promiscuous mode
[   35.725392] br-300: port 1(eth0.300) entered blocking state
[   35.725416] br-300: port 1(eth0.300) entered forwarding state
[   35.809881] br-400: port 1(eth0.400) entered blocking state
[   35.809913] br-400: port 1(eth0.400) entered disabled state
[   35.816325] device eth0.400 entered promiscuous mode
[   35.825269] br-400: port 1(eth0.400) entered blocking state
[   35.825293] br-400: port 1(eth0.400) entered forwarding state
[   35.852268] br-403: port 1(eth0.403) entered blocking state
[   35.852296] br-403: port 1(eth0.403) entered disabled state
[   35.856817] device eth0.403 entered promiscuous mode
[   35.868561] br-403: port 1(eth0.403) entered blocking state
[   35.868586] br-403: port 1(eth0.403) entered forwarding state
[   35.911799] br-500: port 1(eth0.500) entered blocking state
[   35.911823] br-500: port 1(eth0.500) entered disabled state
[   35.916374] device eth0.500 entered promiscuous mode
[   35.925648] br-500: port 1(eth0.500) entered blocking state
[   35.926947] br-500: port 1(eth0.500) entered forwarding state
[   36.456471] ath: EEPROM regdomain: 0x8114
[   36.456491] ath: EEPROM indicates we should expect a country code
[   36.459454] ath: doing EEPROM country->regdmn map search
[   36.465627] ath: country maps to regdmn code: 0x37
[   36.470980] ath: Country alpha2 being used: DE
[   36.475510] ath: Regpair used: 0x37
[   36.479939] ath: regdomain 0x8114 dynamically updated by user
[   36.483402] ath: EEPROM regdomain: 0x8114
[   36.489232] ath: EEPROM indicates we should expect a country code
[   36.493284] ath: doing EEPROM country->regdmn map search
[   36.499296] ath: country maps to regdmn code: 0x37
[   36.504751] ath: Country alpha2 being used: DE
[   36.509276] ath: Regpair used: 0x37
[   36.513779] ath: regdomain 0x8114 dynamically updated by user
[   36.650895] IPv6: ADDRCONF(NETDEV_CHANGE): br-200: link becomes ready
[   42.811496] ath10k_pci 0001:01:00.0: unsupported HTC service id: 1536
[   42.811532] ath10k_pci 0001:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   42.816912] ath10k_pci 0001:01:00.0: msdu-desc: 2500  skid: 32
[   42.901921] ath10k_pci 0001:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   42.902784] ath10k_pci 0001:01:00.0: wmi print 'free: 81824 iram: 13124 sram: 14440'
[   43.352438] ath10k_pci 0001:01:00.0: Firmware lacks feature flag indicating a retry limit of > 2 is OK, requested limit: 4
[   43.523291] ath10k_pci 0001:01:00.0: NOTE:  Firmware DBGLOG output disabled in debug_mask: 0x10000000
[   49.604664] ath10k_pci 0000:01:00.0: unsupported HTC service id: 1536
[   49.605408] ath10k_pci 0000:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   49.610081] ath10k_pci 0000:01:00.0: msdu-desc: 2500  skid: 32
[   49.693126] ath10k_pci 0000:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   49.693970] ath10k_pci 0000:01:00.0: wmi print 'free: 81824 iram: 13124 sram: 14440'
[   50.082962] ath10k_pci 0000:01:00.0: Firmware lacks feature flag indicating a retry limit of > 2 is OK, requested limit: 4
[   50.437060] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[   51.079342] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1-1: link becomes ready
[   51.153627] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1-2: link becomes ready
[   51.160951] br-500: port 2(wlan1-3) entered blocking state
[   51.160975] br-500: port 2(wlan1-3) entered disabled state
[   51.165496] device wlan1-3 entered promiscuous mode
[   51.170954] br-500: port 2(wlan1-3) entered blocking state
[   51.175569] br-500: port 2(wlan1-3) entered forwarding state
[  115.698816] ath10k_pci 0000:01:00.0: mac flush null vif, drop 0 queues 0xffff
[  115.766608] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[  115.840918] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0-1: link becomes ready
[  115.914441] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0-2: link becomes ready
[  115.941744] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0-3: link becomes ready

As you can see the bridge is initialized way before the final wlan interfaces are ready, and subsequently they are not included in the bridge output.

I am also worried that even if I have my workaround with a delayed startup script this will be an issue if I for whatever reason make changes to my wireless interfaces and restart them. This would render the router non-working until reboot or manual brctl addif is performed.

Sparks · April 12, 2020, 11:09am

Agreed, definitely a bug here. But I couldn’t comment much with regard to how to fix/improve the design here..

Just in case it’s related to your config, can you past the outputs of these

cat /etc/config/network ; echo ====== ; cat /etc/config/wireless ;

mha · April 12, 2020, 11:34am

Definitely!

root@wifi:~# cat /etc/config/network ; echo ====== ; cat /etc/config/wireless ;

config interface 'loopback'
        option ifname 'lo'
        option proto 'static'
        option ipaddr '127.0.0.1'
        option netmask '255.0.0.0'

config globals 'globals'
        option ula_prefix 'fdca:01c3:3cac::/48'

config switch
        option name 'switch0'
        option reset '1'
        option enable_vlan '1'

config switch_vlan
        option device 'switch0'
        option vlan '1'
        option vid '1'
        option ports '6 4'

config switch_vlan
        option device 'switch0'
        option vlan '2'
        option vid '403'
        option ports '0t 3 2 1 5t'

config switch_vlan
        option device 'switch0'
        option vlan '3'
        option vid '200'
        option ports '0t 5t'

config switch_vlan
        option device 'switch0'
        option vlan '4'
        option vid '300'
        option ports '0t 5t'

config switch_vlan
        option device 'switch0'
        option vlan '5'
        option vid '400'
        option ports '0t 5t'

config switch_vlan
        option device 'switch0'
        option vlan '6'
        option vid '500'
        option ports '0t 5t'

config interface '403'
        option proto 'static'
        option type 'bridge'
        option gateway '172.16.X.X'
        list dns '10.1.X.X'
        option broadcast '172.16.X.X'
        option netmask '255.255.255.224'
        option delegate '0'
        option ipaddr '172.16.X.X'
        option ifname 'eth0.403'

config interface '200'
        option proto 'none'
        option ifname 'eth0.200 wlan0-1 wlan1-1'
        option type 'bridge'
        option delegate '0'

config interface '300'
        option proto 'none'
        option ifname 'eth0.300 wlan0-2 wlan1-2'
        option type 'bridge'
        option delegate '0'

config interface '400'
        option proto 'none'
        option ifname 'eth0.400 wlan0 wlan1'
        option type 'bridge'
        option delegate '0'

config interface '500'
        option proto 'none'
        option ifname 'eth0.500 wlan0-3 wlan1-3'
        option type 'bridge'
        option delegate '0'

======

config wifi-device 'radio0'
        option type 'mac80211'
        option hwmode '11a'
        option path 'soc/1b500000.pci/pci0000:00/0000:00:00.0/0000:01:00.0'
        option legacy_rates '0'
        option country 'DE'
        option htmode 'VHT160'
        option channel '44'

config wifi-iface 'default_radio0'
        option device 'radio0'
        option mode 'ap'
        option wpa_disable_eapol_key_retries '1'
        option key 'XXXXX'
        option ssid 'XXXXX50-test'
        option ieee80211w '1'
        option encryption 'psk2'

config wifi-device 'radio1'
        option type 'mac80211'
        option hwmode '11g'
        option path 'soc/1b700000.pci/pci0001:00/0001:00:00.0/0001:01:00.0'
        option legacy_rates '0'
        option htmode 'HT40'
        option country 'DE'
        option channel '3'

config wifi-iface 'default_radio1'
        option device 'radio1'
        option mode 'ap'
        option wpa_disable_eapol_key_retries '1'
        option key 'XXXXX'
        option ssid 'XXXXX24-test'
        option ieee80211w '1'
        option encryption 'psk2'

config wifi-iface 'wifinet2'
        option ssid 'XXXXX50-test'
        option device 'radio0'
        option mode 'ap'
        option key 'XXXXX'
        option ieee80211w '1'
        option wpa_disable_eapol_key_retries '1'
        option encryption 'psk2'

config wifi-iface 'wifinet3'
        option ssid 'XXXXX24-test'
        option device 'radio1'
        option mode 'ap'
        option ieee80211w '1'
        option key 'XXXXX'
        option wpa_disable_eapol_key_retries '1'
        option encryption 'psk2'

config wifi-iface 'wifinet4'
        option ssid 'XXXXX50-test'
        option device 'radio0'
        option mode 'ap'
        option ieee80211w '1'
        option key 'XXXXX'
        option wpa_disable_eapol_key_retries '1'
        option encryption 'psk2'

config wifi-iface 'wifinet5'
        option ssid 'XXXXX24-test'
        option device 'radio1'
        option mode 'ap'
        option ieee80211w '1'
        option key 'XXXXX'
        option wpa_disable_eapol_key_retries '1'
        option encryption 'psk2'

config wifi-iface 'wifinet6'
        option ssid 'FREE_XXXXX'
        option encryption 'none'
        option device 'radio0'
        option mode 'ap'

config wifi-iface 'wifinet7'
        option ssid 'FREE_XXXXX'
        option encryption 'none'
        option device 'radio1'
        option mode 'ap'

As for the fixing I think that the system needs to be more aware. It's OK that a non-existing device is not added to a bridge, but when it appears something should check where it belongs. This could also improve I guess error handling in case an interface restarts due to a bug or other unforeseen mean.

If similar designs do exist perhaps this is a case not caught which could be improved.

Sparks · April 12, 2020, 9:22pm

Ah, have you tried flashing 19.07.2 firmware? Possible this might only be a bug on master / 5.4 related changes maybe.

I have a 7800 as well and comparing the dmesg output to yours , br-lan appears at 39seconds, and the WiFi radios also appeared after the bridge, but they were still added at around 56 seconds.

Is it always the first and last bridges br200 and br500 that get configured correctly , or is it random which ones succeed?

mha · April 13, 2020, 7:14pm

Thanks a lot for the input.

During the current boot on master I saw a slightly different output;

[   35.982487] br-200: port 1(eth0.200) entered blocking state
[   35.983200] br-200: port 1(eth0.200) entered disabled state
[   35.988891] device eth0.200 entered promiscuous mode
[   35.994408] device eth0 entered promiscuous mode
[   36.001072] br-200: port 1(eth0.200) entered blocking state
[   36.004128] br-200: port 1(eth0.200) entered forwarding state
[   36.066928] br-300: port 1(eth0.300) entered blocking state
[   36.066953] br-300: port 1(eth0.300) entered disabled state
[   36.071599] device eth0.300 entered promiscuous mode
[   36.082968] br-300: port 1(eth0.300) entered blocking state
[   36.082992] br-300: port 1(eth0.300) entered forwarding state
[   36.160151] br-400: port 1(eth0.400) entered blocking state
[   36.160178] br-400: port 1(eth0.400) entered disabled state
[   36.165540] device eth0.400 entered promiscuous mode
[   36.174290] br-400: port 1(eth0.400) entered blocking state
[   36.175292] br-400: port 1(eth0.400) entered forwarding state
[   36.214140] br-403: port 1(eth0.403) entered blocking state
[   36.214170] br-403: port 1(eth0.403) entered disabled state
[   36.218744] device eth0.403 entered promiscuous mode
[   36.225335] br-403: port 1(eth0.403) entered blocking state
[   36.229287] br-403: port 1(eth0.403) entered forwarding state
[   36.262311] br-500: port 1(eth0.500) entered blocking state
[   36.262334] br-500: port 1(eth0.500) entered disabled state
[   36.266882] device eth0.500 entered promiscuous mode
[   36.277478] br-500: port 1(eth0.500) entered blocking state
[   36.277502] br-500: port 1(eth0.500) entered forwarding state
[...]
[   50.755782] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[   51.435322] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1-1: link becomes ready
[   51.524452] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1-2: link becomes ready
[   51.553188] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1-3: link becomes ready
root@wifi:~# brctl show
bridge name     bridge id               STP enabled     interfaces
br-200          7fff.3c37862ac466       no              eth0.200
br-500          7fff.3c37862ac466       no              eth0.500
br-400          7fff.3c37862ac466       no              eth0.400
br-300          7fff.3c37862ac466       no              eth0.300
br-403          7fff.3c37862ac466       no              eth0.403

In this instance bringing up wlan1 "only" took 51 seconds and bridges initialized at 36s. Still as show above no bridges got WLAN interfaces added. Very weird.

After flashing OpenWrt 19.07.2, r10947-65030d81f3 I see the following;

Boot attempt #1 kernel log:

[   11.366054] ath10k 4.19 driver, optimized for CT firmware, probing pci device: 0x46.
[   11.366565] ath10k_pci 0000:01:00.0: enabling device (0140 -> 0142)
[   11.372911] ath10k_pci 0000:01:00.0: enabling bus mastering
[   11.373366] ath10k_pci 0000:01:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0
[   11.546598] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/fwcfg-pci-0000:01:00.0.txt failed with error -2
[   11.546646] ath10k_pci 0000:01:00.0: Falling back to user helper
[   11.709401] firmware ath10k!fwcfg-pci-0000:01:00.0.txt: firmware_loading_store: map pages failed
[   11.709576] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/pre-cal-pci-0000:01:00.0.bin failed with error -2
[   11.717327] ath10k_pci 0000:01:00.0: Falling back to user helper
[   11.983530] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA9984/hw1.0/ct-firmware-5.bin failed with error -2
[   11.983564] ath10k_pci 0000:01:00.0: Falling back to user helper
[   12.012071] firmware ath10k!QCA9984!hw1.0!ct-firmware-5.bin: firmware_loading_store: map pages failed
[   12.012320] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA9984/hw1.0/ct-firmware-2.bin failed with error -2
[   12.020373] ath10k_pci 0000:01:00.0: Falling back to user helper
[   12.046031] firmware ath10k!QCA9984!hw1.0!ct-firmware-2.bin: firmware_loading_store: map pages failed
[   12.046189] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA9984/hw1.0/firmware-6.bin failed with error -2
[   12.054309] ath10k_pci 0000:01:00.0: Falling back to user helper
[   12.094576] firmware ath10k!QCA9984!hw1.0!firmware-6.bin: firmware_loading_store: map pages failed
[   12.483017] ath10k_pci 0000:01:00.0: qca9984/qca9994 hw1.0 target 0x01000000 chip_id 0x00000000 sub 168c:cafe
[   12.483051] ath10k_pci 0000:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 0
[   12.494227] ath10k_pci 0000:01:00.0: firmware ver 10.4b-ct-9984-fW-012-17ba98334 api 5 features mfp,peer-flow-ctrl,txstatus-noack,wmi-10.x-CT,ratemask-CT,regdump-CT,txrate-CT,flush-all-CT,pingpong-CT,ch-regs-CT,nop-CT,set-special-CT,tx-rc-CT,cust-stats-CT,txrate2-CT,beacon-cb-CT,wmi-block-ack-CT,wmi-bcn-rc-CT crc32 877928bc
[   14.819552] ath10k_pci 0000:01:00.0: board_file api 2 bmi_id 0:1 crc32 85498734
[   20.649804] ath10k_pci 0000:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   20.649833] ath10k_pci 0000:01:00.0: msdu-desc: 2500  skid: 32
[   20.731765] ath10k_pci 0000:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   20.732604] ath10k_pci 0000:01:00.0: wmi print 'free: 81784 iram: 23220 sram: 14440'
[   20.992621] ath10k_pci 0000:01:00.0: htt-ver 2.2 wmi-op 6 htt-op 4 cal pre-cal-file max-sta 32 raw 0 hwcrypto 1
[   21.092943] ath: EEPROM regdomain: 0x0
[   21.092955] ath: EEPROM indicates default country code should be used
[   21.092962] ath: doing EEPROM country->regdmn map search
[   21.092977] ath: country maps to regdmn code: 0x3a
[   21.092988] ath: Country alpha2 being used: US
[   21.092995] ath: Regpair used: 0x3a
[   21.097611] ath10k_pci 0001:01:00.0: assign IRQ: got 100
[   21.097648] ath10k 4.19 driver, optimized for CT firmware, probing pci device: 0x46.
[   21.098517] ath10k_pci 0001:01:00.0: enabling device (0140 -> 0142)
[   21.104673] ath10k_pci 0001:01:00.0: enabling bus mastering
[   21.105315] ath10k_pci 0001:01:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0
[   21.275619] ath10k_pci 0001:01:00.0: Direct firmware load for ath10k/fwcfg-pci-0001:01:00.0.txt failed with error -2
[   21.275658] ath10k_pci 0001:01:00.0: Falling back to user helper
[   21.441112] firmware ath10k!fwcfg-pci-0001:01:00.0.txt: firmware_loading_store: map pages failed
[   21.441362] ath10k_pci 0001:01:00.0: Direct firmware load for ath10k/pre-cal-pci-0001:01:00.0.bin failed with error -2
[   21.449055] ath10k_pci 0001:01:00.0: Falling back to user helper
[   21.662503] ath10k_pci 0001:01:00.0: Direct firmware load for ath10k/QCA9984/hw1.0/ct-firmware-5.bin failed with error -2
[   21.662534] ath10k_pci 0001:01:00.0: Falling back to user helper
[   21.690816] firmware ath10k!QCA9984!hw1.0!ct-firmware-5.bin: firmware_loading_store: map pages failed
[   21.690976] ath10k_pci 0001:01:00.0: Direct firmware load for ath10k/QCA9984/hw1.0/ct-firmware-2.bin failed with error -2
[   21.699150] ath10k_pci 0001:01:00.0: Falling back to user helper
[   21.723486] firmware ath10k!QCA9984!hw1.0!ct-firmware-2.bin: firmware_loading_store: map pages failed
[   21.723636] ath10k_pci 0001:01:00.0: Direct firmware load for ath10k/QCA9984/hw1.0/firmware-6.bin failed with error -2
[   21.731784] ath10k_pci 0001:01:00.0: Falling back to user helper
[   21.758535] firmware ath10k!QCA9984!hw1.0!firmware-6.bin: firmware_loading_store: map pages failed
[   21.758676] ath10k_pci 0001:01:00.0: qca9984/qca9994 hw1.0 target 0x01000000 chip_id 0x00000000 sub 168c:cafe
[   21.766460] ath10k_pci 0001:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 0
[   21.778388] ath10k_pci 0001:01:00.0: firmware ver 10.4b-ct-9984-fW-012-17ba98334 api 5 features mfp,peer-flow-ctrl,txstatus-noack,wmi-10.x-CT,ratemask-CT,regdump-CT,txrate-CT,flush-all-CT,pingpong-CT,ch-regs-CT,nop-CT,set-special-CT,tx-rc-CT,cust-stats-CT,txrate2-CT,beacon-cb-CT,wmi-block-ack-CT,wmi-bcn-rc-CT crc32 877928bc
[   24.097526] ath10k_pci 0001:01:00.0: board_file api 2 bmi_id 0:2 crc32 85498734
[   29.931318] ath10k_pci 0001:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   29.931370] ath10k_pci 0001:01:00.0: msdu-desc: 2500  skid: 32
[   30.015130] ath10k_pci 0001:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   30.016008] ath10k_pci 0001:01:00.0: wmi print 'free: 81784 iram: 23220 sram: 14440'
[   30.291262] ath10k_pci 0001:01:00.0: htt-ver 2.2 wmi-op 6 htt-op 4 cal pre-cal-file max-sta 32 raw 0 hwcrypto 1
[   30.427566] ath: EEPROM regdomain: 0x0
[   30.427581] ath: EEPROM indicates default country code should be used
[   30.427593] ath: doing EEPROM country->regdmn map search
[   30.427611] ath: country maps to regdmn code: 0x3a
[   30.427624] ath: Country alpha2 being used: US
[   30.427635] ath: Regpair used: 0x3a
[   30.437949] kmodloader: done loading kernel modules from /etc/modules.d/*
[   34.221817] Generic PHY fixed-0:00: attached PHY driver [Generic PHY] (mii_bus:phy_addr=fixed-0:00, irq=POLL)
[   34.222643] dwmac1000: Master AXI performs any burst length
[   34.230825] ipq806x-gmac-dwmac 37200000.ethernet eth0: IEEE 1588-2008 Advanced Timestamp supported
[   34.236254] ipq806x-gmac-dwmac 37200000.ethernet eth0: registered PTP clock
[   34.245554] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   34.256106] br-200: port 1(eth0.200) entered blocking state
[   34.257878] br-200: port 1(eth0.200) entered disabled state
[   34.263546] device eth0.200 entered promiscuous mode
[   34.268988] device eth0 entered promiscuous mode
[   34.281259] IPv6: ADDRCONF(NETDEV_UP): br-200: link is not ready
[   34.335081] br-300: port 1(eth0.300) entered blocking state
[   34.335106] br-300: port 1(eth0.300) entered disabled state
[   34.339585] device eth0.300 entered promiscuous mode
[   34.346387] IPv6: ADDRCONF(NETDEV_UP): br-300: link is not ready
[   34.416478] br-400: port 1(eth0.400) entered blocking state
[   34.416507] br-400: port 1(eth0.400) entered disabled state
[   34.421862] device eth0.400 entered promiscuous mode
[   34.429912] IPv6: ADDRCONF(NETDEV_UP): br-400: link is not ready
[   34.451773] br-403: port 1(eth0.403) entered blocking state
[   34.451799] br-403: port 1(eth0.403) entered disabled state
[   34.456966] device eth0.403 entered promiscuous mode
[   34.467429] IPv6: ADDRCONF(NETDEV_UP): br-403: link is not ready
[   34.492372] br-500: port 1(eth0.500) entered blocking state
[   34.492398] br-500: port 1(eth0.500) entered disabled state
[   34.498141] device eth0.500 entered promiscuous mode
[   34.508874] IPv6: ADDRCONF(NETDEV_UP): br-500: link is not ready
[   34.972023] ath: EEPROM regdomain: 0x8114
[   34.972043] ath: EEPROM indicates we should expect a country code
[   34.975139] ath: doing EEPROM country->regdmn map search
[   34.981081] ath: country maps to regdmn code: 0x37
[   34.986523] ath: Country alpha2 being used: DE
[   34.991076] ath: Regpair used: 0x37
[   34.995552] ath: regdomain 0x8114 dynamically updated by user
[   34.998900] ath: EEPROM regdomain: 0x8114
[   35.004827] ath: EEPROM indicates we should expect a country code
[   35.008772] ath: doing EEPROM country->regdmn map search
[   35.014924] ath: country maps to regdmn code: 0x37
[   35.020231] ath: Country alpha2 being used: DE
[   35.024885] ath: Regpair used: 0x37
[   35.029258] ath: regdomain 0x8114 dynamically updated by user
[   35.274296] ipq806x-gmac-dwmac 37200000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
[   35.275402] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   35.282350] br-200: port 1(eth0.200) entered blocking state
[   35.288308] br-200: port 1(eth0.200) entered forwarding state
[   35.294004] br-300: port 1(eth0.300) entered blocking state
[   35.299680] br-300: port 1(eth0.300) entered forwarding state
[   35.305372] br-400: port 1(eth0.400) entered blocking state
[   35.310970] br-400: port 1(eth0.400) entered forwarding state
[   35.316570] br-403: port 1(eth0.403) entered blocking state
[   35.322254] br-403: port 1(eth0.403) entered forwarding state
[   35.327845] br-500: port 1(eth0.500) entered blocking state
[   35.333536] br-500: port 1(eth0.500) entered forwarding state
[   35.340820] IPv6: ADDRCONF(NETDEV_CHANGE): br-200: link becomes ready
[   35.345049] IPv6: ADDRCONF(NETDEV_CHANGE): br-300: link becomes ready
[   35.351324] IPv6: ADDRCONF(NETDEV_CHANGE): br-400: link becomes ready
[   35.357902] IPv6: ADDRCONF(NETDEV_CHANGE): br-403: link becomes ready
[   35.364278] IPv6: ADDRCONF(NETDEV_CHANGE): br-500: link becomes ready
[   42.464472] ath10k_pci 0001:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   42.464500] ath10k_pci 0001:01:00.0: msdu-desc: 2500  skid: 32
[   42.547617] ath10k_pci 0001:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   42.548451] ath10k_pci 0001:01:00.0: wmi print 'free: 81784 iram: 23220 sram: 14440'
[   42.977371] ath10k_pci 0001:01:00.0: Firmware lacks feature flag indicating a retry limit of > 2 is OK, requested limit: 4
[   42.977545] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
[   43.463180] ath10k_pci 0001:01:00.0: NOTE:  Firmware DBGLOG output disabled in debug_mask: 0x10000000
[   47.358894] ath10k_pci 0001:01:00.0: mac-vif-chan had error in htt_rx_h_vdev_channel, peer-id: 0  vdev-id: 0 peer-addr: 3c:37:86:2a:c4:68.
[   48.900876] ath10k_pci 0000:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   48.900904] ath10k_pci 0000:01:00.0: msdu-desc: 2500  skid: 32
[   48.982855] ath10k_pci 0000:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   48.983683] ath10k_pci 0000:01:00.0: wmi print 'free: 81784 iram: 23220 sram: 14440'
[   49.338293] ath10k_pci 0000:01:00.0: Firmware lacks feature flag indicating a retry limit of > 2 is OK, requested limit: 4
[   49.338530] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   51.741376] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[   51.767500] IPv6: ADDRCONF(NETDEV_UP): wlan1-1: link is not ready
[   51.785483] br-200: port 2(wlan1-1) entered blocking state
[   51.785507] br-200: port 2(wlan1-1) entered disabled state
[   51.790082] device wlan1-1 entered promiscuous mode
[   51.795467] br-200: port 2(wlan1-1) entered blocking state
[   51.800096] br-200: port 2(wlan1-1) entered forwarding state
[   51.855163] IPv6: ADDRCONF(NETDEV_UP): wlan1-2: link is not ready
[   51.862684] br-300: port 2(wlan1-2) entered blocking state
[   51.862708] br-300: port 2(wlan1-2) entered disabled state
[   51.867317] device wlan1-2 entered promiscuous mode
[   51.872583] br-300: port 2(wlan1-2) entered blocking state
[   51.877375] br-300: port 2(wlan1-2) entered forwarding state
[   51.938502] IPv6: ADDRCONF(NETDEV_UP): wlan1-3: link is not ready
[   51.965475] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1-3: link becomes ready
[   51.967580] br-500: port 2(wlan1-3) entered blocking state
[   51.970902] br-500: port 2(wlan1-3) entered disabled state
[   51.976616] device wlan1-3 entered promiscuous mode
[   51.981909] br-500: port 2(wlan1-3) entered blocking state
[   51.986681] br-500: port 2(wlan1-3) entered forwarding state
[  110.627145] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[  110.636458] IPv6: ADDRCONF(NETDEV_UP): wlan0-1: link is not ready
[  110.701860] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0-1: link becomes ready
[  110.707767] IPv6: ADDRCONF(NETDEV_UP): wlan0-2: link is not ready
[  110.708197] br-300: port 3(wlan0-2) entered blocking state
[  110.713437] br-300: port 3(wlan0-2) entered disabled state
[  110.719049] device wlan0-2 entered promiscuous mode
[  110.724428] br-300: port 3(wlan0-2) entered blocking state
[  110.729072] br-300: port 3(wlan0-2) entered forwarding state
[  110.806750] IPv6: ADDRCONF(NETDEV_UP): wlan0-3: link is not ready
[  110.807162] br-500: port 3(wlan0-3) entered blocking state
[  110.811827] br-500: port 3(wlan0-3) entered disabled state
[  110.817772] device wlan0-3 entered promiscuous mode
[  110.822759] br-500: port 3(wlan0-3) entered blocking state
[  110.827531] br-500: port 3(wlan0-3) entered forwarding state

brctl show;

# brctl show
bridge name     bridge id               STP enabled     interfaces
br-200          7fff.3c37862ac466       no              eth0.200
                                                        wlan1-1
br-300          7fff.3c37862ac466       no              eth0.300
                                                        wlan1-2
                                                        wlan0-2
br-400          7fff.3c37862ac466       no              eth0.400
br-403          7fff.3c37862ac466       no              eth0.403
br-500          7fff.3c37862ac466       no              eth0.500
                                                        wlan1-3
                                                        wlan0-3

br-400 is missing both wlan0 and wlan1, and br-200 is missing wlan0-1.

Boot attempt #2 kernel log (without any configuration changes):

[   11.245019] ath10k_pci 0000:01:00.0: assign IRQ: got 67
[   11.245040] ath10k 4.19 driver, optimized for CT firmware, probing pci device: 0x46.
[   11.245602] ath10k_pci 0000:01:00.0: enabling device (0140 -> 0142)
[   11.251979] ath10k_pci 0000:01:00.0: enabling bus mastering
[   11.252430] ath10k_pci 0000:01:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0
[   11.428805] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/fwcfg-pci-0000:01:00.0.txt failed with error -2
[   11.428851] ath10k_pci 0000:01:00.0: Falling back to user helper
[   11.540660] firmware ath10k!fwcfg-pci-0000:01:00.0.txt: firmware_loading_store: map pages failed
[   11.544741] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA9984/hw1.0/ct-firmware-5.bin failed with error -2
[   11.548530] ath10k_pci 0000:01:00.0: Falling back to user helper
[   11.574322] firmware ath10k!QCA9984!hw1.0!ct-firmware-5.bin: firmware_loading_store: map pages failed
[   11.574503] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA9984/hw1.0/ct-firmware-2.bin failed with error -2
[   11.582525] ath10k_pci 0000:01:00.0: Falling back to user helper
[   11.609158] firmware ath10k!QCA9984!hw1.0!ct-firmware-2.bin: firmware_loading_store: map pages failed
[   11.609344] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/QCA9984/hw1.0/firmware-6.bin failed with error -2
[   11.617477] ath10k_pci 0000:01:00.0: Falling back to user helper
[   11.643587] firmware ath10k!QCA9984!hw1.0!firmware-6.bin: firmware_loading_store: map pages failed
[   11.980938] ath10k_pci 0000:01:00.0: qca9984/qca9994 hw1.0 target 0x01000000 chip_id 0x00000000 sub 168c:cafe
[   11.980970] ath10k_pci 0000:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 0
[   11.991672] ath10k_pci 0000:01:00.0: firmware ver 10.4b-ct-9984-fW-012-17ba98334 api 5 features mfp,peer-flow-ctrl,txstatus-noack,wmi-10.x-CT,ratemask-CT,regdump-CT,txrate-CT,flush-all-CT,pingpong-CT,ch-regs-CT,nop-CT,set-special-CT,tx-rc-CT,cust-stats-CT,txrate2-CT,beacon-cb-CT,wmi-block-ack-CT,wmi-bcn-rc-CT crc32 877928bc
[   14.317279] ath10k_pci 0000:01:00.0: board_file api 2 bmi_id 0:1 crc32 85498734
[   20.156603] ath10k_pci 0000:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   20.156629] ath10k_pci 0000:01:00.0: msdu-desc: 2500  skid: 32
[   20.238499] ath10k_pci 0000:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   20.239357] ath10k_pci 0000:01:00.0: wmi print 'free: 81784 iram: 23220 sram: 14440'
[   20.495378] ath10k_pci 0000:01:00.0: htt-ver 2.2 wmi-op 6 htt-op 4 cal pre-cal-file max-sta 32 raw 0 hwcrypto 1
[   20.597234] ath: EEPROM regdomain: 0x0
[   20.597248] ath: EEPROM indicates default country code should be used
[   20.597259] ath: doing EEPROM country->regdmn map search
[   20.597278] ath: country maps to regdmn code: 0x3a
[   20.597290] ath: Country alpha2 being used: US
[   20.597300] ath: Regpair used: 0x3a
[   20.602828] ath10k_pci 0001:01:00.0: assign IRQ: got 100
[   20.602867] ath10k 4.19 driver, optimized for CT firmware, probing pci device: 0x46.
[   20.603952] ath10k_pci 0001:01:00.0: enabling device (0140 -> 0142)
[   20.609930] ath10k_pci 0001:01:00.0: enabling bus mastering
[   20.610613] ath10k_pci 0001:01:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0
[   20.785645] ath10k_pci 0001:01:00.0: Direct firmware load for ath10k/fwcfg-pci-0001:01:00.0.txt failed with error -2
[   20.785680] ath10k_pci 0001:01:00.0: Falling back to user helper
[   20.928476] firmware ath10k!fwcfg-pci-0001:01:00.0.txt: firmware_loading_store: map pages failed
[   20.930653] ath10k_pci 0001:01:00.0: Direct firmware load for ath10k/QCA9984/hw1.0/ct-firmware-5.bin failed with error -2
[   20.936492] ath10k_pci 0001:01:00.0: Falling back to user helper
[   20.961665] firmware ath10k!QCA9984!hw1.0!ct-firmware-5.bin: firmware_loading_store: map pages failed
[   20.961809] ath10k_pci 0001:01:00.0: Direct firmware load for ath10k/QCA9984/hw1.0/ct-firmware-2.bin failed with error -2
[   20.969952] ath10k_pci 0001:01:00.0: Falling back to user helper
[   20.996574] firmware ath10k!QCA9984!hw1.0!ct-firmware-2.bin: firmware_loading_store: map pages failed
[   20.996739] ath10k_pci 0001:01:00.0: Direct firmware load for ath10k/QCA9984/hw1.0/firmware-6.bin failed with error -2
[   21.004856] ath10k_pci 0001:01:00.0: Falling back to user helper
[   21.031496] firmware ath10k!QCA9984!hw1.0!firmware-6.bin: firmware_loading_store: map pages failed
[   21.031646] ath10k_pci 0001:01:00.0: qca9984/qca9994 hw1.0 target 0x01000000 chip_id 0x00000000 sub 168c:cafe
[   21.039445] ath10k_pci 0001:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 0
[   21.051630] ath10k_pci 0001:01:00.0: firmware ver 10.4b-ct-9984-fW-012-17ba98334 api 5 features mfp,peer-flow-ctrl,txstatus-noack,wmi-10.x-CT,ratemask-CT,regdump-CT,txrate-CT,flush-all-CT,pingpong-CT,ch-regs-CT,nop-CT,set-special-CT,tx-rc-CT,cust-stats-CT,txrate2-CT,beacon-cb-CT,wmi-block-ack-CT,wmi-bcn-rc-CT crc32 877928bc
[   23.370160] ath10k_pci 0001:01:00.0: board_file api 2 bmi_id 0:2 crc32 85498734
[   29.203484] ath10k_pci 0001:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   29.203517] ath10k_pci 0001:01:00.0: msdu-desc: 2500  skid: 32
[   29.287179] ath10k_pci 0001:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   29.288054] ath10k_pci 0001:01:00.0: wmi print 'free: 81784 iram: 23220 sram: 14440'
[   29.595312] ath10k_pci 0001:01:00.0: htt-ver 2.2 wmi-op 6 htt-op 4 cal pre-cal-file max-sta 32 raw 0 hwcrypto 1
[   29.692990] ath: EEPROM regdomain: 0x0
[   29.693003] ath: EEPROM indicates default country code should be used
[   29.693011] ath: doing EEPROM country->regdmn map search
[   29.693026] ath: country maps to regdmn code: 0x3a
[   29.693036] ath: Country alpha2 being used: US
[   29.693044] ath: Regpair used: 0x3a
[   29.700380] kmodloader: done loading kernel modules from /etc/modules.d/*
[   32.952194] Generic PHY fixed-0:00: attached PHY driver [Generic PHY] (mii_bus:phy_addr=fixed-0:00, irq=POLL)
[   32.952919] dwmac1000: Master AXI performs any burst length
[   32.961202] ipq806x-gmac-dwmac 37200000.ethernet eth0: IEEE 1588-2008 Advanced Timestamp supported
[   32.966668] ipq806x-gmac-dwmac 37200000.ethernet eth0: registered PTP clock
[   32.975964] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   32.989928] br-200: port 1(eth0.200) entered blocking state
[   32.989955] br-200: port 1(eth0.200) entered disabled state
[   32.994564] device eth0.200 entered promiscuous mode
[   32.999854] device eth0 entered promiscuous mode
[   33.006662] IPv6: ADDRCONF(NETDEV_UP): br-200: link is not ready
[   33.065379] br-300: port 1(eth0.300) entered blocking state
[   33.065412] br-300: port 1(eth0.300) entered disabled state
[   33.069931] device eth0.300 entered promiscuous mode
[   33.079293] IPv6: ADDRCONF(NETDEV_UP): br-300: link is not ready
[   33.144959] br-400: port 1(eth0.400) entered blocking state
[   33.144983] br-400: port 1(eth0.400) entered disabled state
[   33.150492] device eth0.400 entered promiscuous mode
[   33.160016] IPv6: ADDRCONF(NETDEV_UP): br-400: link is not ready
[   33.177257] br-403: port 1(eth0.403) entered blocking state
[   33.177288] br-403: port 1(eth0.403) entered disabled state
[   33.181857] device eth0.403 entered promiscuous mode
[   33.189111] IPv6: ADDRCONF(NETDEV_UP): br-403: link is not ready
[   33.219309] br-500: port 1(eth0.500) entered blocking state
[   33.219334] br-500: port 1(eth0.500) entered disabled state
[   33.225934] device eth0.500 entered promiscuous mode
[   33.233429] IPv6: ADDRCONF(NETDEV_UP): br-500: link is not ready
[   33.778822] ath: EEPROM regdomain: 0x8114
[   33.778842] ath: EEPROM indicates we should expect a country code
[   33.781804] ath: doing EEPROM country->regdmn map search
[   33.787985] ath: country maps to regdmn code: 0x37
[   33.793263] ath: Country alpha2 being used: DE
[   33.797932] ath: Regpair used: 0x37
[   33.802289] ath: regdomain 0x8114 dynamically updated by user
[   33.805761] ath: EEPROM regdomain: 0x8114
[   33.811576] ath: EEPROM indicates we should expect a country code
[   33.815644] ath: doing EEPROM country->regdmn map search
[   33.821649] ath: country maps to regdmn code: 0x37
[   33.827110] ath: Country alpha2 being used: DE
[   33.831628] ath: Regpair used: 0x37
[   33.836109] ath: regdomain 0x8114 dynamically updated by user
[   33.994257] ipq806x-gmac-dwmac 37200000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
[   33.996503] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   34.002287] br-200: port 1(eth0.200) entered blocking state
[   34.008249] br-200: port 1(eth0.200) entered forwarding state
[   34.013904] br-300: port 1(eth0.300) entered blocking state
[   34.019707] br-300: port 1(eth0.300) entered forwarding state
[   34.025319] br-400: port 1(eth0.400) entered blocking state
[   34.030928] br-400: port 1(eth0.400) entered forwarding state
[   34.036509] br-403: port 1(eth0.403) entered blocking state
[   34.042213] br-403: port 1(eth0.403) entered forwarding state
[   34.047813] br-500: port 1(eth0.500) entered blocking state
[   34.053497] br-500: port 1(eth0.500) entered forwarding state
[   34.059182] IPv6: ADDRCONF(NETDEV_CHANGE): br-200: link becomes ready
[   34.065020] IPv6: ADDRCONF(NETDEV_CHANGE): br-300: link becomes ready
[   34.071284] IPv6: ADDRCONF(NETDEV_CHANGE): br-400: link becomes ready
[   34.077848] IPv6: ADDRCONF(NETDEV_CHANGE): br-403: link becomes ready
[   34.084257] IPv6: ADDRCONF(NETDEV_CHANGE): br-500: link becomes ready
[   41.161803] ath10k_pci 0000:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   41.161832] ath10k_pci 0000:01:00.0: msdu-desc: 2500  skid: 32
[   41.243747] ath10k_pci 0000:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   41.244575] ath10k_pci 0000:01:00.0: wmi print 'free: 81784 iram: 23220 sram: 14440'
[   41.598453] ath10k_pci 0000:01:00.0: Firmware lacks feature flag indicating a retry limit of > 2 is OK, requested limit: 4
[   41.598696] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   42.160546] ath10k_pci 0000:01:00.0: NOTE:  Firmware DBGLOG output disabled in debug_mask: 0x10000000
[   47.541663] ath10k_pci 0001:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
[   47.541692] ath10k_pci 0001:01:00.0: msdu-desc: 2500  skid: 32
[   47.625496] ath10k_pci 0001:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
[   47.626361] ath10k_pci 0001:01:00.0: wmi print 'free: 81784 iram: 23220 sram: 14440'
[   48.068110] ath10k_pci 0001:01:00.0: Firmware lacks feature flag indicating a retry limit of > 2 is OK, requested limit: 4
[   48.068348] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
[   50.486611] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[   50.513577] IPv6: ADDRCONF(NETDEV_UP): wlan1-1: link is not ready
[   50.598537] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1-1: link becomes ready
[   50.607764] IPv6: ADDRCONF(NETDEV_UP): wlan1-2: link is not ready
[   50.681112] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1-2: link becomes ready
[   50.690746] IPv6: ADDRCONF(NETDEV_UP): wlan1-3: link is not ready
[   50.691349] br-500: port 2(wlan1-3) entered blocking state
[   50.695891] br-500: port 2(wlan1-3) entered disabled state
[   50.701430] device wlan1-3 entered promiscuous mode
[   50.706831] br-500: port 2(wlan1-3) entered blocking state
[   50.711460] br-500: port 2(wlan1-3) entered forwarding state

brctl show;

bridge name     bridge id               STP enabled     interfaces
br-200          7fff.3c37862ac466       no              eth0.200
br-300          7fff.3c37862ac466       no              eth0.300
br-400          7fff.3c37862ac466       no              eth0.400
br-403          7fff.3c37862ac466       no              eth0.403
br-500          7fff.3c37862ac466       no              eth0.500
                                                        wlan1-3

No configuration changes between boots. Boot => wait => sample=> reboot => wait => sample

Could it be related to the amount of interfaces and bridges I have configured? I could imagine most would have maybe one bridge (LAN) and perhaps 2-4 SSIDs depending on whether they have a guest network or not enabled.

I've also opened a task on it referring to this thread; https://bugs.openwrt.org/index.php?do=details&task_id=2998

Sparks · April 13, 2020, 8:55pm

Yeh this is definitely a setup not that many others would have used/tried before.

Perhaps worth trying disabling all except the first bridge’s br200 WiFi interfaces , and reboot a couple times to see if they get added consistently to the bridge.

If that works, enable one more bridge’s WiFi interfaces and repeat the test. Alternateively, you could disable all the 5gz interfaces , or all the 2.4gz interfaces.

Goal is to change as little as possible from one test to the next to try and isolate either a specific interface or threshold where it goes wonky.

mha · April 14, 2020, 9:43pm

Some tests conducted with the prerequisite that I reconfigured br-403 to an unbridged interface where I set the IP directly on eth0.403 as a bridge is not really needed for this purpose which works fine for my use. Also renamed this interface to "mgmt".

I've also done a full reset on the router and started from scratch, despite a quite simplistic configuration is applied. This because I've switched between new/old/off tree branches back and forth. All main tests in this post were done with OpenWrt 19.07.2, r10947-65030d81f3.

Test #1; Consists of br-400 with wlan0 and wlan1. Conducting 5 reboots in a row with just wlan0 and wlan1 defined yielded a 80% success rate. In one boot wlan0 was missing from the bridge. I am unsure if this was an one time off or signs of the same issue.

Test #2; Added br-200 with wlan0-1 and wlan1-1 and conducted 5 reboots. Immediately after save & apply (before any reboot) I noted that br-200 had no WLAN interfaces attached;

# brctl show
bridge name     bridge id               STP enabled     interfaces
br-400          7fff.3c37862ac466       no              eth0.400
                                                        wlan0
                                                        wlan1
br-200          7fff.3c37862ac466       no              eth0.200

Conducting 5 reboots yielded:

40%: br-400 fully configured, br-200 missing one interface.
60%: br-400 fully configured, br-200 missing both interfaces.
0%: Correctly configured

Test #3; Added br-300 with wlan1-2 and wlan0-2 and conducted 5 reboots.

Interesting observation. After adding br-300 and finalizing the bridge br-200 lost one previously added interface prior to first reboot;

# brctl show
bridge name     bridge id               STP enabled     interfaces
br-200          7fff.3c37862ac466       no              eth0.200
                                                        wlan0-1
br-400          7fff.3c37862ac466       no              eth0.400
                                                        wlan0
                                                        wlan1

# brctl show
bridge name     bridge id               STP enabled     interfaces
br-200          7fff.3c37862ac466       no              eth0.200
br-400          7fff.3c37862ac466       no              eth0.400
                                                        wlan0
                                                        wlan1
br-300          7fff.3c37862ac466       no              eth0.300

Conducting 5 reboots;

40%: br-400 fully configured, br-200: 0% configured, br-300 50% configured
40%: br-400 fully configured, br-200 50% configured, br-300 50% configured
20%: br-400 fully configured, br-200 0% configured, br-300 0% configured
0%: fully configured

Note: Except for br-400 the 50% configured bridges only consisted of wlan0 (5GHz) interfaces.

Test #4: Only create 3x 2.4GHz wireless networks and disable 5GHz. Distribute them to the bridges as single interface per bridge. Bridges called test1, test2 and test3.

20%: test1 0% configured, test2 0% configured, test3 100% configured
40%: test1 0% configured, test2 100% configured, test3 100% configured
40%: test1 0% configured, test2 0% configured, test3 0% configured
0%: fully configured

As I did not get a 100% success rate only using 2.4GHz I don't foresee a need to create 6x 2.4GHz and will move on to 5GHz only testing.

Test #5: Only create 3x 5GHz wireless networks and disable 2.4GHz. Distribute them to the bridges as single interface per bridge. Bridges called test1, test2 and test3.

40%: test1 0% configured, test2 100% configured, test3 100% configured
20%: test1 0% configured, test2 0% configured, test3 0% configured
20%: test1 0% configured, test2 0% configured, test3 100% configured

Again, as the test show results all over the place I don't see a need for conducting the same test with 2 wlan interfaces per bridge.

Is it netifd responsible for adding interfaces to the bridge when they become ready? I have attempted to debug it to no good result. I attempted to add the options -d 15 -l 4 according to netifd.h in the startup script, but I am not really getting any additional output in the system log.

Do you or anyone else know how to debug this closer?

Sparks · April 17, 2020, 11:08am

I had a go at trying to reproduce this on my 7800. Had rather mixed results trying to replicate your config... I assume something got left out when you sanitised it.

What ended up with was the following... (probably misunderstanding on my end)

Summary

root@OpenWrtSlave_NH:~# cat /etc/config/network ; echo ====== ; cat /etc/config/wireless ;

config interface 'loopback'
	option ifname 'lo'
	option proto 'static'
	option ipaddr '127.0.0.1'
	option netmask '255.0.0.0'

config globals 'globals'
	option ula_prefix 'fd5a:0ddf:2517::/48'

config switch
	option name 'switch0'
	option reset '1'
	option enable_vlan '1'

config switch_vlan
	option device 'switch0'
	option vlan '1'
	option vid '1'
	option ports '6 4'

config switch_vlan
	option device 'switch0'
	option vlan '2'
	option vid '403'
	option ports '0t 3 2 1 5t'

config switch_vlan
	option device 'switch0'
	option vlan '3'
	option vid '200'
	option ports '0t 5t'

config switch_vlan
	option device 'switch0'
	option vlan '4'
	option vid '300'
	option ports '0t 5t'

config switch_vlan
	option device 'switch0'
	option vlan '5'
	option vid '400'
	option ports '0t 5t'

config switch_vlan
	option device 'switch0'
	option vlan '6'
	option vid '500'
	option ports '0t 5t'

config interface '403'
	option proto 'static'
	option type 'bridge'
	option netmask '255.255.255.0'
	option delegate '0'
	option ipaddr '192.168.0.3'
	option ifname 'eth0.403'

config interface '200'
	option proto 'none'
	option type 'bridge'
	option delegate '0'
	option ifname 'eth0.200 wlan0-1'

config interface '300'
	option proto 'none'
	option ifname 'eth0.300 wlan0-2 wlan1-2'
	option type 'bridge'
	option delegate '0'

config interface '400'
	option proto 'none'
	option type 'bridge'
	option delegate '0'
	option ifname 'eth0.400'

config interface '500'
	option proto 'none'
	option ifname 'eth0.500 wlan0-3 wlan1-3'
	option type 'bridge'
	option delegate '0'

======

config wifi-device 'radio0'
	option type 'mac80211'
	option hwmode '11a'
	option path 'soc/1b500000.pci/pci0000:00/0000:00:00.0/0000:01:00.0'
	option legacy_rates '0'
	option country 'DE'
	option htmode 'VHT40'
	option txpower '23'
	option channel '36'

config wifi-iface 'default_radio0'
	option device 'radio0'
	option mode 'ap'
	option ieee80211w '1'
	option encryption 'psk2'
	option key '1234567890'
	option ssid 'wlan0-50-test'
	option ifname 'wlan0'
	option network '200'

config wifi-device 'radio1'
	option type 'mac80211'
	option channel '6'
	option hwmode '11g'
	option path 'soc/1b700000.pci/pci0001:00/0001:00:00.0/0001:01:00.0'
	option legacy_rates '0'
	option htmode 'HT40'

config wifi-iface 'default_radio1'
	option device 'radio1'
	option mode 'ap'
	option wpa_disable_eapol_key_retries '1'
	option ieee80211w '1'
	option encryption 'psk2'
	option key '1234567890'
	option network '200'
	option ssid 'wlan1-24-test'
	option ifname 'wlan1'

config wifi-iface 'wifinet2'
	option device 'radio0'
	option mode 'ap'
	option ieee80211w '1'
	option wpa_disable_eapol_key_retries '1'
	option encryption 'psk2'
	option key '1234567890'
	option ssid 'wlan0-2-50-test'
	option network '300'
	option ifname 'wlan0-2'

config wifi-iface 'wifinet3'
	option device 'radio1'
	option mode 'ap'
	option ieee80211w '1'
	option wpa_disable_eapol_key_retries '1'
	option encryption 'psk2'
	option key '1234567890'
	option ssid 'wlan1-1-test'
	option ifname 'wlan1-1'
	option network '400'

config wifi-iface 'wifinet4'
	option device 'radio0'
	option mode 'ap'
	option ieee80211w '1'
	option wpa_disable_eapol_key_retries '1'
	option encryption 'psk2'
	option key '1234567890'
	option ssid 'wlan0-3-50-test'
	option network '400'
	option ifname 'wlan0-3'

config wifi-iface 'wifinet5'
	option device 'radio1'
	option mode 'ap'
	option ieee80211w '1'
	option wpa_disable_eapol_key_retries '1'
	option encryption 'psk2'
	option key '1234567890'
	option ssid 'wlan1-2-24-test'
	option ifname 'wlan1-2'

config wifi-iface 'wifinet6'
	option device 'radio0'
	option mode 'ap'
	option key '1234567890'
	option encryption 'psk2'
	option ssid 'FREE0_XXXXX'
	option network '500'
	option ifname 'wlan0-1'

config wifi-iface 'wifinet7'
	option device 'radio1'
	option mode 'ap'
	option key '1234567890'
	option encryption 'psk2'
	option ssid 'wlan1-3-FREE_XXXXX'
	option ifname 'wlan1-3'

root@OpenWrtSlave_NH:~#

When all wlan interfaces are behaving properly, the bridge mappings are as follows (which I think is close enough to your config).

root@OpenWrtSlave_NH:~# brctl show
bridge name	bridge id		STP enabled	interfaces
br-200		7fff.08028e9bc368	no		eth0.200
							wlan1
							wlan0
br-300		7fff.08028e9bc368	no		eth0.300
							wlan1-2
							wlan0-2
br-400		7fff.08028e9bc368	no		eth0.400
							wlan1-1
							wlan0-3
br-403		7fff.08028e9bc368	no		eth0.403
br-500		7fff.08028e9bc368	no		eth0.500
							wlan1-3
							wlan0-1

Now when I rebooted it, I got similar looking issue to yours:

root@OpenWrtSlave_NH:~# brctl show
bridge name	bridge id		STP enabled	interfaces
br-200		7fff.08028e9bc368	no		eth0.200
							wlan0
							wlan1
br-300		7fff.08028e9bc368	no		eth0.300
br-400		7fff.08028e9bc368	no		eth0.400
							wlan1-1
br-403		7fff.08028e9bc368	no		eth0.403
br-500		7fff.08028e9bc368	no		eth0.500

I then tried restarting the network service /etc/init.d/network restart while having logread -f running from another window.

I noticed several of these lines appearing:

ri Apr 17 20:18:23 2020 daemon.notice netifd: radio0 (6015): cat: can't open '/var/run/wifi-phy0.pid': No such file or directory
Fri Apr 17 20:18:23 2020 daemon.notice netifd: radio0 (6015): WARNING (wireless_add_process): executable path /usr/sbin/wpad does not match process  path (/proc/exe)
Fri Apr 17 20:18:23 2020 daemon.notice netifd: radio0 (6015): Command failed: Invalid argument
Fri Apr 17 20:18:29 2020 daemon.notice netifd: radio0 (6015): Cannot find device "wlan0-2"
Fri Apr 17 20:18:29 2020 daemon.notice netifd: radio0 (6015): Interface 1 setup failed: IFUP_ERROR
Fri Apr 17 20:18:29 2020 daemon.notice netifd: radio0 (6015): Cannot find device "wlan0-3"
Fri Apr 17 20:18:29 2020 daemon.notice netifd: radio0 (6015): Interface 2 setup failed: IFUP_ERROR
Fri Apr 17 20:18:29 2020 daemon.notice netifd: radio0 (6015): Cannot find device "wlan0-1"
Fri Apr 17 20:18:29 2020 daemon.notice netifd: radio0 (6015): Interface 3 setup failed: IFUP_ERROR

I then tried ifconfig wlan0-1 and it promptly returns

ifconfig: wlan0-1: error fetching interface information: Device not found

So, all of this to say that I think the issue isn't so much in the timing/delay in the bridge - but rather in that something is failing to initialize these wifi sub-interfaces properly (maybe within the driver/kernel - I dont know).

Can you confirm if when you see missing wifi interfaces in the output from brctl show , do they are also non-existent devices from ifconfig point of view as well?

mha · April 18, 2020, 2:46pm

Thanks a lot for all the troubleshooting you did to replicate! I think you come close to the issues I experience. Also the configuration you have applied is close to identical to mine. The only things I did strip out were exact IPs, SSID names and passwords. Otherwise no lines were otherwise missing or settings changed in my initial config output. If you would like I can of course do a full test config with bogus passwords and just for validation give you the full output again?

I would say one difference in the results are;

When I reboot I almost never get a perfect bridge. When this happens the interfaces are available in ifconfig. Although just not added to the bridge. Hence my workaround of the startupscript doing a sleep 60 then brctl addif <...> works great.
When I have reconfigured a lot of the network/bridges and do an apply (or an /etc/init.d/network restart as you did) I have noticed wifi devices dropping out of the reconfiguration. I have also attributed this to the ath10k driver but also fell back to just rebooting the device during my testing conducted instead of doing a network restart.

Just to confirm; you always get perfect bridges on boot, which later fail when you do network restart? And when they fail, it's always because interfaces are completely missing?

trendy · April 18, 2020, 4:46pm

Why don't you use the option 'network' in wireless configuration?

mha · April 18, 2020, 6:57pm

Simple answer; did not consider to do it it as I found a way to create the bridge by other means. I have seen the option just not considered it's relevance. I have now done a setup where I just create the base bridge in the Interfaces setup and use the network option to attach the wireless network created to the bridge instead of the other way around.

After reconfiguring accordingly this is my output;

# brctl show
bridge name	bridge id		STP enabled	interfaces
br-200		7fff.3c37862ac466	no		eth0.200
							wlan1-1
							wlan0-1
br-300		7fff.3c37862ac466	no		eth0.300
							wlan1-2
							wlan0-2
br-400		7fff.3c37862ac466	no		eth0.400
							wlan0
							wlan1
br-500		7fff.3c37862ac466	no		eth0.500
							wlan1-3
							wlan0-3

Perfect result.

Conducting a reboot to test I noticed what @Sparks noted about wlan0-1 not existing. Though waiting another 65 seconds made these interfaces come up and was then correctly added to the bridge

[   41.228488] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   47.699756] br-400: port 2(wlan0) entered blocking state
[   47.700596] br-400: port 2(wlan0) entered disabled state
[   47.706688] device wlan0 entered promiscuous mode
[...]
[  110.645956] br-200: port 3(wlan0-1) entered blocking state
[  110.645994] br-200: port 3(wlan0-1) entered disabled state

# brctl show
bridge name	bridge id		STP enabled	interfaces
br-200		7fff.3c37862ac466	no		eth0.200
							wlan1-1
							wlan0-1
br-300		7fff.3c37862ac466	no		eth0.300
							wlan1-2
							wlan0-2
br-400		7fff.3c37862ac466	no		eth0.400
							wlan0
							wlan1
br-500		7fff.3c37862ac466	no		eth0.500
							wlan1-3
							wlan0-3

So @trendy, thank you for the input! This solved my issue!

Conclusion of issue TL;DR:

Creating an interface of type bridge and adding devices does not ensure that the devices are initiated properly while creating the bridge. Seems mostly applicable to wireless devices. Instead adding a wireless interface to the network interface created seems to align and make netifd properly keep track of them and add them to the bridge.

mha · April 18, 2020, 7:01pm

Thanks to both @Sparks and @trendy for troubleshooting tips and help. Now I am moving on to configure my other R7800 with OpenWRT and trying to get 802.11r working.

system · April 28, 2020, 7:05pm

This topic was automatically closed 10 days after the last reply. New replies are no longer allowed.