Snapshot ar79: unable to add virtual wireless interface

bluewavenet · November 14, 2019, 11:04am

With the latest snapshot (at 13th Nov 2019) it is not possible to add a virtual wireless interface eg for an 80211s mesh or a guest ssid.

On a snapshot image from 22nd October it works fine.

I have tried on both gl-ar300m and gl-ar750.

A typical logread output trying to add wlan0-1 to an ar300m (via uci config) is:

Tue Nov 12 15:47:18 2019 kern.debug kernel: [  255.017233] ath: EEPROM regdomain: 0x833a
Tue Nov 12 15:47:18 2019 kern.debug kernel: [  255.017242] ath: EEPROM indicates we should expect a country code
Tue Nov 12 15:47:18 2019 kern.debug kernel: [  255.017249] ath: doing EEPROM country->regdmn map search
Tue Nov 12 15:47:18 2019 kern.debug kernel: [  255.017255] ath: country maps to regdmn code: 0x37
Tue Nov 12 15:47:18 2019 kern.debug kernel: [  255.017261] ath: Country alpha2 being used: GB
Tue Nov 12 15:47:18 2019 kern.debug kernel: [  255.017264] ath: Regpair used: 0x37
Tue Nov 12 15:47:18 2019 kern.debug kernel: [  255.017270] ath: regdomain 0x833a dynamically updated by user
Tue Nov 12 15:47:19 2019 daemon.notice netifd: radio0 (1500): command failed: Too many open files in system (-23)
Tue Nov 12 15:47:19 2019 user.notice mac80211: Failed command: iw phy phy0 interface add wlan0 type __ap
Tue Nov 12 15:47:19 2019 daemon.notice hostapd: Configuration file: /var/run/hostapd-phy0.conf (phy wlan0) --> new PHY
Tue Nov 12 15:47:19 2019 kern.info kernel: [  256.369718] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Tue Nov 12 15:47:19 2019 kern.info kernel: [  256.380263] br-lan: port 2(wlan0) entered blocking state
Tue Nov 12 15:47:19 2019 kern.info kernel: [  256.385760] br-lan: port 2(wlan0) entered disabled state
Tue Nov 12 15:47:19 2019 kern.info kernel: [  256.391672] device wlan0 entered promiscuous mode
Tue Nov 12 15:47:19 2019 daemon.notice hostapd: wlan0: interface state UNINITIALIZED->COUNTRY_UPDATE
Tue Nov 12 15:47:19 2019 daemon.err hostapd: Using interface wlan0 with hwaddr e4:95:6e:44:cf:37 and ssid "BlueWaveFreeWiFi"
Tue Nov 12 15:47:19 2019 kern.info kernel: [  256.414414] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Tue Nov 12 15:47:19 2019 kern.info kernel: [  256.421273] br-lan: port 2(wlan0) entered blocking state
Tue Nov 12 15:47:19 2019 kern.info kernel: [  256.426833] br-lan: port 2(wlan0) entered forwarding state
Tue Nov 12 15:47:19 2019 daemon.notice hostapd: wlan0: interface state COUNTRY_UPDATE->ENABLED
Tue Nov 12 15:47:19 2019 daemon.notice hostapd: wlan0: AP-ENABLED
Tue Nov 12 15:47:20 2019 user.notice root: ip link set dev wlan0 up
Tue Nov 12 15:47:31 2019 user.notice mac80211: Failed command: iw phy phy0 set antenna 0xffffffff 0xffffffff
Tue Nov 12 15:47:31 2019 user.notice root: ip link set dev wlan0 up
Tue Nov 12 15:47:31 2019 daemon.notice netifd: Network device 'wlan0' link is up

Something has gone astray and it seems "it" is asking iw do something incorrect.

@jeff fyi as you are actively developing for gl-inet devices

I will try the same on a non ath79 device later

lantis1008 · November 14, 2019, 11:41am

More likely (but not confirming in any way)
https://git.openwrt.org/?p=openwrt/openwrt.git;a=commit;h=155ede4f1fdb192b11f8ae2dbffda5f7ef4903bd
https://git.openwrt.org/?p=openwrt/openwrt.git;a=commit;h=60fb4c92b6b0d1582d31e02167b90b424185f3a2
https://git.openwrt.org/?p=openwrt/openwrt.git;a=commit;h=a5bc9787d4ef89c9e2593a191b3c4cf8702b41a3
https://git.openwrt.org/?p=openwrt/openwrt.git;a=commit;h=6becc37f33be4c2f2b5d58467bdda41c251d9e2e

bluewavenet · November 14, 2019, 11:47am

I've tested now on a gl-b1300 (ipq40xx) and it works fine, so it looks like it may be more of an ar79 issue...

@lantis1008 Thanks, I will take a closer look.

jeff · November 14, 2019, 4:41pm

Just did a quick check on the GL-AR750S i have up and running and I'm not seeing it at my current SPI-NAND PR's code. Will move to master next

Current build based off

git log -1 $(git merge-base openwrt/master HEAD)
commit edbadec843
Author: Martin Schiller <redacted>
Date:   Fri Oct 25 09:22:29 2019 +0200

config wifi-device 'radio0'
	option type 'mac80211'
	option channel '36'
	option hwmode '11a'
	option path 'pci0000:00/0000:00:00.0'
	option htmode 'VHT80'
#	option disabled '1'

config wifi-iface 'default_radio0'
	option device 'radio0'
	option network 'lan'
	option mode 'ap'
	option ssid 'OpenWrt_0'
	option encryption 'none'

config wifi-iface 'default_radio0b'
        option device 'radio0'
        option network 'lan'
        option mode 'ap'
        option ssid 'OpenWrt_0b'
        option encryption 'none'

config wifi-device 'radio1'
	option type 'mac80211'
	option channel '11'
	option hwmode '11g'
	option path 'platform/ahb/18100000.wmac'
	option htmode 'HT20'
#	option disabled '1'

config wifi-iface 'default_radio1'
	option device 'radio1'
	option network 'lan'
	option mode 'ap'
	option ssid 'OpenWrt_1'
	option encryption 'none'

config wifi-iface 'default_radio1b'
        option device 'radio1'
        option network 'lan'
        option mode 'ap'     
        option ssid 'OpenWrt_1b'   
        option encryption 'none'

juppin · November 14, 2019, 4:42pm

As the mentioned commits are very new, the non ath79 target snapshot is probably a older revision without this commits...

jeff · November 14, 2019, 5:05pm

I see the -23 error on master (of today). Interestingly, the four interfaces seem to be up.

Edit: I do not see the -23 error based off master at commit edbadec843. Bisection testing underway.

root@OpenWrt:~# logread | egrep 'netifd|hostapd'
Thu Nov 14 16:46:41 2019 daemon.notice netifd: Interface 'lan' is enabled
Thu Nov 14 16:46:41 2019 daemon.notice netifd: Interface 'lan' is setting up now
Thu Nov 14 16:46:41 2019 daemon.notice netifd: Interface 'lan' is now up
Thu Nov 14 16:46:41 2019 daemon.notice netifd: Interface 'loopback' is enabled
Thu Nov 14 16:46:41 2019 daemon.notice netifd: Interface 'loopback' is setting up now
Thu Nov 14 16:46:41 2019 daemon.notice netifd: Interface 'loopback' is now up
Thu Nov 14 16:46:41 2019 daemon.notice netifd: Interface 'wan' is enabled
Thu Nov 14 16:46:41 2019 daemon.notice netifd: Interface 'wan6' is enabled
Thu Nov 14 16:46:42 2019 daemon.notice netifd: Network device 'lo' link is up
Thu Nov 14 16:46:42 2019 daemon.notice netifd: Interface 'loopback' has link connectivity
Thu Nov 14 16:46:42 2019 daemon.notice netifd: VLAN 'eth0.1' link is up
Thu Nov 14 16:46:42 2019 daemon.notice netifd: VLAN 'eth0.2' link is up
Thu Nov 14 16:46:42 2019 daemon.notice netifd: Interface 'wan' has link connectivity
Thu Nov 14 16:46:42 2019 daemon.notice netifd: Interface 'wan' is setting up now
Thu Nov 14 16:46:42 2019 daemon.notice netifd: Interface 'wan6' has link connectivity
Thu Nov 14 16:46:42 2019 daemon.notice netifd: Interface 'wan6' is setting up now
Thu Nov 14 16:46:42 2019 daemon.notice netifd: Network device 'eth0' link is up
Thu Nov 14 16:46:43 2019 daemon.notice netifd: wan (1687): udhcpc: started, v1.31.1
Thu Nov 14 16:46:43 2019 daemon.notice netifd: bridge 'br-lan' link is up
Thu Nov 14 16:46:43 2019 daemon.notice netifd: Interface 'lan' has link connectivity
Thu Nov 14 16:46:44 2019 daemon.notice netifd: radio1 (1530): sh: out of range
Thu Nov 14 16:46:44 2019 daemon.notice netifd: wan (1687): udhcpc: sending discover
Thu Nov 14 16:46:44 2019 daemon.notice netifd: radio0 (1529): sh: out of range
Thu Nov 14 16:46:45 2019 daemon.notice netifd: radio1 (1530): command failed: Too many open files in system (-23)
Thu Nov 14 16:46:45 2019 daemon.notice hostapd: Configuration file: /var/run/hostapd-phy1.conf (phy wlan1) --> new PHY
Thu Nov 14 16:46:45 2019 daemon.err hostapd: Using interface wlan1 with hwaddr e4:95:6e:xx:xx:xx and ssid "OpenWrt_1"
Thu Nov 14 16:46:45 2019 daemon.notice netifd: radio0 (1529): command failed: Too many open files in system (-23)
Thu Nov 14 16:46:45 2019 daemon.notice hostapd: Configuration file: /var/run/hostapd-phy0.conf (phy wlan0) --> new PHY
Thu Nov 14 16:46:46 2019 daemon.err hostapd: Using interface wlan1-1 with hwaddr e6:95:6e:xx:xx:xx and ssid "OpenWrt_1b"
Thu Nov 14 16:46:46 2019 daemon.notice hostapd: wlan1: interface state UNINITIALIZED->ENABLED
Thu Nov 14 16:46:46 2019 daemon.notice hostapd: wlan1: AP-ENABLED
Thu Nov 14 16:46:47 2019 daemon.notice hostapd: wlan0: interface state UNINITIALIZED->HT_SCAN
Thu Nov 14 16:46:47 2019 daemon.err hostapd: Using interface wlan0 with hwaddr e4:95:6e:xx:xx:xx and ssid "OpenWrt_0"
Thu Nov 14 16:46:47 2019 daemon.err hostapd: Using interface wlan0-1 with hwaddr e6:95:6e:xx:xx:xx and ssid "OpenWrt_0b"
Thu Nov 14 16:46:47 2019 daemon.notice hostapd: wlan0: interface state HT_SCAN->ENABLED
Thu Nov 14 16:46:47 2019 daemon.notice hostapd: wlan0: AP-ENABLED
Thu Nov 14 16:46:47 2019 daemon.notice netifd: wan (1687): udhcpc: sending discover
Thu Nov 14 16:46:48 2019 daemon.notice netifd: Network device 'wlan1' link is up
Thu Nov 14 16:46:48 2019 daemon.notice netifd: Network device 'wlan1-1' link is up
Thu Nov 14 16:46:48 2019 daemon.notice netifd: Network device 'wlan0' link is up
Thu Nov 14 16:46:48 2019 daemon.notice netifd: Network device 'wlan0-1' link is up

lantis1008 · November 14, 2019, 8:17pm

New commit sounds like it addresses this issue.
https://git.openwrt.org/?p=openwrt/openwrt.git;a=commit;h=000b7687bc50be5b0f1161f4bf8ceb85c495c395

bluewavenet · November 14, 2019, 8:26pm

Indeed, looks promising!

lantis1008 · November 14, 2019, 10:13pm

It's an ambitious set of changes. I'm not surprised there were teething issues.

The future possibilities it unlocks (e.g. single hostapd instance) sound great though, so well done to Daniel and John.

jeff · November 14, 2019, 10:38pm

git bisect didn't go as planned, with the -23 error perhaps not being a telltale sign. Rechecking the "first bad" commit didn't show the error. Worse, I soft-bricked my test router and I'm not physically there to power-cycle it. (I failed to follow my own advice, Do not use "force" with sysupgrade).

bluewavenet · November 17, 2019, 8:38pm

Well today's build (Nov 17th) with the latest commits will allow two ap mode interfaces on the same radio so getting close

However it fails with one ap mode and one mesh mode. In fact just a single mesh mode fails.
Config:

config wifi-device 'radio0'
	option type 'mac80211'
	option channel '11'
	option hwmode '11g'
	option path 'platform/ahb/18100000.wmac'
	option htmode 'HT20'
	option disabled '0'

config wifi-iface 'mesh0'
	option device 'radio0'
	option network 'lan'
	option encryption 'none'
	option mode 'mesh'
	option mesh_id 'Mesh'
	option ifname 'wlan0'

Logread:

Sun Nov 17 00:42:08 2019 daemon.notice netifd: radio0 (4176): command failed: Too many open files in system (-23)
Sun Nov 17 00:42:09 2019 daemon.notice netifd: radio0 (4176): command failed: Too many open files in system (-23)
Sun Nov 17 00:42:09 2019 daemon.notice netifd: radio0 (4176): md5sum: can't open '/var/run/hostapd-phy0.conf': No such file or directory
Sun Nov 17 00:42:09 2019 daemon.notice netifd: radio0 (4176): Command failed: Invalid argument
Sun Nov 17 00:42:10 2019 daemon.notice netifd: radio0 (4176): command failed: No such device (-19)
Sun Nov 17 00:42:10 2019 daemon.notice netifd: radio0 (4220): WARNING: Variable 'data' does not exist or is not an array/object
Sun Nov 17 00:42:10 2019 daemon.notice netifd: radio0 (4228): command failed: Too many open files in system (-23)
Sun Nov 17 00:42:11 2019 daemon.notice netifd: radio0 (4228): command failed: Too many open files in system (-23)
Sun Nov 17 00:42:11 2019 daemon.notice netifd: radio0 (4228): md5sum: can't open '/var/run/hostapd-phy0.conf': No such file or directory
Sun Nov 17 00:42:11 2019 daemon.notice netifd: radio0 (4228): Command failed: Invalid argument
Sun Nov 17 00:42:11 2019 daemon.notice netifd: radio0 (4228): command failed: No such device (-19)
Sun Nov 17 00:42:11 2019 daemon.notice netifd: radio0 (4270): WARNING: Variable 'data' does not exist or is not an array/object
Sun Nov 17 00:42:12 2019 daemon.notice netifd: radio0 (4278): command failed: Too many open files in system (-23)

@lantis1008 how do we pass this on to Daniel and John?

bluewavenet · November 17, 2019, 9:19pm

After a reboot it page faults:

Sun Nov 17 21:11:21 2019 user.notice root: ip link set dev wlan0 up
Sun Nov 17 21:11:21 2019 user.notice root: ip link set dev wlan0-1 up
Sun Nov 17 21:11:21 2019 kern.info kernel: [   29.708840] IPv6: ADDRCONF(NETDEV_UP): wlan0-1: link is not ready
Sun Nov 17 21:11:22 2019 daemon.notice netifd: radio0 (1135): command failed: Link has been severed (-67)
Sun Nov 17 21:11:22 2019 daemon.notice netifd: radio0 (1135): command failed: Link has been severed (-67)
Sun Nov 17 21:11:22 2019 kern.info kernel: [   30.648404] br-lan: port 3(wlan0-1) entered blocking state
Sun Nov 17 21:11:22 2019 kern.info kernel: [   30.654079] br-lan: port 3(wlan0-1) entered disabled state
Sun Nov 17 21:11:22 2019 kern.info kernel: [   30.660231] device wlan0-1 entered promiscuous mode
Sun Nov 17 21:11:22 2019 kern.info kernel: [   30.746464] br-lan: port 2(wlan0) entered disabled state
Sun Nov 17 21:11:23 2019 kern.info kernel: [   31.611282] do_page_fault(): sending SIGSEGV to wpa_supplicant for invalid read access from 000005fc
Sun Nov 17 21:11:23 2019 kern.info kernel: [   31.620769] epc = 00485fad in wpad[400000+b7000]
Sun Nov 17 21:11:23 2019 kern.info kernel: [   31.625552] ra  = 00485f97 in wpad[400000+b7000]

lantis1008 · November 18, 2019, 12:27am

They both monitor the mailing list, but could try pinging @dangowrt and @blogic

bluewavenet · November 18, 2019, 4:15pm

Cheers. I've opened a task on Flyspray