Wireless interface stays up after disabled, netdev LED control fails

dchard · March 23, 2023, 4:59pm

Dear Developers,

I am noticing the same phenomena on two platforms already (ath9k and ath10k (mips and ipq4019):

When the device boots with the radio (phy0-ap0) disabled, the interface is down and the associated LED is off. If I enable the radio, the associated LED turns on. But once I turn the same radio off again, the radio goes down, but the phy0-ap0 interface stays up, and the netdev trigger fails to disable the associated LED.

This definitely worked on 5.10 before, now it fails on two platforms.

This is the LED config:

config led 'led_wlan'
        option name 'WLAN'
        option sysfs 'green:wlan'
        option trigger 'netdev'
        option mode 'link tx rx'
        option dev 'phy0-ap0'

Or maybe something changed and this needs to be configured differently?

Ansuel · April 23, 2023, 4:17pm

Hi, can you give more info? Specific device?

I'm trying to repro this on ath10k with r7800 and with the netdev trigger led it does correctly turn off...
Also can't find a device on ipq4019 that use netdev trigger to handle wifi led.

dchard · April 24, 2023, 8:21am

Of course.

I reproduced this with two devices:

GLI-NET MIFI, which is a MIPS based ath9k device (has mainline Openwrt support)
Mikrotik Chateua 12LTE which does not have mainline support yet, I am "developing" it:

In both cases the same thing happens:

This is how the LED is set up:

system.@led[6]=led
system.@led[6].name='WLAN2'
system.@led[6].sysfs='green:ethernet'
system.@led[6].trigger='netdev'
system.@led[6].dev='phy0-ap0'
system.@led[6].mode='link tx rx'

Default state is radio disabled, 'phy0-ap0' is in "DOWN" state.
Turn on 'phy0-ap0' under Luci --> the LED turns on correctly, 'phy0-ap0' is in "UP state.
Turn off 'phy0-ap0' under Luci --> the LED is still ON, 'phy0-ap0' is still in "UP state, BSSID broadcasted but cannot connect to it.
If I restart the router in this state, it all goes back to normal after reboot (interafce disabled, LED is off, no BSSID broadcasted).

MOD: this is how logread looks like when I hit the "Disable" button under luci:

Mon Apr 24 11:26:54 2023 daemon.notice netifd: Wireless device 'radio1' is now up
Mon Apr 24 11:26:54 2023 daemon.notice netifd: Network device 'phy1-ap0' link is up
Mon Apr 24 11:26:54 2023 kern.info kernel: [  881.778597] br-lan: port 6(phy1-ap0) entered blocking state
Mon Apr 24 11:26:54 2023 kern.info kernel: [  881.778660] br-lan: port 6(phy1-ap0) entered disabled state
Mon Apr 24 11:26:54 2023 kern.info kernel: [  881.783690] device phy1-ap0 entered promiscuous mode
Mon Apr 24 11:26:54 2023 kern.info kernel: [  881.788901] br-lan: port 6(phy1-ap0) entered blocking state
Mon Apr 24 11:26:54 2023 kern.info kernel: [  881.793858] br-lan: port 6(phy1-ap0) entered forwarding state
Mon Apr 24 11:26:55 2023 daemon.info dnsmasq[1]: read /etc/hosts - 12 names
Mon Apr 24 11:26:55 2023 daemon.info dnsmasq[1]: read /tmp/hosts/dhcp.cfg01411c - 2 names
Mon Apr 24 11:26:55 2023 daemon.info dnsmasq-dhcp[1]: read /etc/ethers - 0 addresses
Mon Apr 24 11:27:26 2023 kern.info kernel: [  913.777410] device phy1-ap0 left promiscuous mode
Mon Apr 24 11:27:26 2023 kern.info kernel: [  913.777696] br-lan: port 6(phy1-ap0) entered disabled state
Mon Apr 24 11:27:26 2023 daemon.notice netifd: radio1 (4551): WARNING: Variable 'data' does not exist or is not an array/object
Mon Apr 24 11:27:26 2023 daemon.notice netifd: radio1 (4551): Bug: PHY is undefined for device 'radio1'
Mon Apr 24 11:27:26 2023 daemon.notice netifd: Wireless device 'radio1' is now down
Mon Apr 24 11:27:29 2023 daemon.info dnsmasq[1]: read /etc/hosts - 12 names
Mon Apr 24 11:27:29 2023 daemon.info dnsmasq[1]: read /tmp/hosts/dhcp.cfg01411c - 2 names
Mon Apr 24 11:27:29 2023 daemon.info dnsmasq-dhcp[1]: read /etc/ethers - 0 addresses

There is a netifd warning which might be related?

MOD2:

This is the radio config:

root@cpe00005:~# uci show wireless
wireless.radio0=wifi-device
wireless.radio0.type='mac80211'
wireless.radio0.path='platform/soc/a000000.wifi'
wireless.radio0.channel='auto'
wireless.radio0.band='2g'
wireless.radio0.htmode='HT20'
wireless.radio0.txpower='17'
wireless.radio0.country='NL'
wireless.radio0.cell_density='0'
wireless.radio0.disabled='1'
wireless.default_radio0=wifi-iface
wireless.default_radio0.device='radio0'
wireless.default_radio0.network='lan'
wireless.default_radio0.mode='ap'
wireless.default_radio0.ssid='mifi_default'
wireless.default_radio0.encryption='psk-mixed'
wireless.default_radio0.key='password'
wireless.default_radio0.disabled='1'
wireless.radio1=wifi-device
wireless.radio1.type='mac80211'
wireless.radio1.path='platform/soc/a800000.wifi'
wireless.radio1.channel='auto'
wireless.radio1.band='5g'
wireless.radio1.htmode='VHT20'
wireless.radio1.txpower='17'
wireless.radio1.country='NL'
wireless.radio1.cell_density='0'
wireless.radio1.disabled='1'
wireless.default_radio1=wifi-iface
wireless.default_radio1.device='radio1'
wireless.default_radio1.network='lan'
wireless.default_radio1.mode='ap'
wireless.default_radio1.ssid='mifi_default_5GHz'
wireless.default_radio1.encryption='psk-mixed'
wireless.default_radio1.key='password'
wireless.default_radio1.disabled='1'

MOD3:

The exact same netifd "BUG" is displayed on the GLI-MIFI as well:

Thu Mar 23 18:31:45 2023 daemon.notice netifd: radio0 (6905): WARNING: Variable 'data' does not exist or is not an array/object
Thu Mar 23 18:31:45 2023 daemon.notice netifd: radio0 (6905): Bug: PHY is undefined for device 'radio0'
Thu Mar 23 18:31:45 2023 daemon.notice netifd: Wireless device 'radio0' is now down

Interface is not down of course.

Ansuel · April 24, 2023, 11:57am

ip link output? if you use wifi down does the led turn off?

dchard · April 24, 2023, 2:48pm

root@cpe00005:~# ip link
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel master br-lan state UP qlen 1000
    link/ether e4:95:6e:43:f3:b7 brd ff:ff:ff:ff:ff:ff
3: eth1: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc fq_codel master br-lan state DOWN qlen 1000
    link/ether e4:95:6e:43:f3:b7 brd ff:ff:ff:ff:ff:ff
4: wwan0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1000
    link/ether ba:df:6e:13:2d:f9 brd ff:ff:ff:ff:ff:ff
6: br-lan: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP qlen 1000
    link/ether e4:95:6e:43:f3:b7 brd ff:ff:ff:ff:ff:ff
15: phy0-ap0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue master br-lan state UP qlen 1000
    link/ether e4:95:6e:43:f3:b7 brd ff:ff:ff:ff:ff:ff
root@cpe00005:~#
root@cpe00005:~#
root@cpe00005:~# wifi down
root@cpe00005:~#
root@cpe00005:~# ip link
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel master br-lan state UP qlen 1000
    link/ether e4:95:6e:43:f3:b7 brd ff:ff:ff:ff:ff:ff
3: eth1: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc fq_codel master br-lan state DOWN qlen 1000
    link/ether e4:95:6e:43:f3:b7 brd ff:ff:ff:ff:ff:ff
4: wwan0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1000
    link/ether ba:df:6e:13:2d:f9 brd ff:ff:ff:ff:ff:ff
6: br-lan: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP qlen 1000
    link/ether e4:95:6e:43:f3:b7 brd ff:ff:ff:ff:ff:ff
15: phy0-ap0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP qlen 1000
    link/ether e4:95:6e:43:f3:b7 brd ff:ff:ff:ff:ff:ff

Even after "wifi down" the interface stays up.

Ansuel · April 24, 2023, 2:50pm

logread -f
run wifi down
give output after the command

Something very wrong is happening here???? (netdev trigger react on interface put down so the real problem is the interface still UP)

dchard · April 25, 2023, 9:39am

Yeah, it is clear that it is not the LED trig where the problem is but the interface state handling.

This is the requested output:


Thu Mar 23 18:48:04 2023 daemon.notice netifd: radio0 (11231): WARNING: Variable 'data' does not exist or is not an array/object
Thu Mar 23 18:48:04 2023 daemon.notice netifd: radio0 (11231): Bug: PHY is undefined for device 'radio0'
Thu Mar 23 18:48:04 2023 daemon.notice netifd: Wireless device 'radio0' is now down
Thu Mar 23 18:48:04 2023 kern.info kernel: [  848.403022] device phy0-ap0 left promiscuous mode
Thu Mar 23 18:48:04 2023 kern.info kernel: [  848.406526] br-lan: port 3(phy0-ap0) entered disabled state

MOD: FYI, after "wifi down" this is how Luci looks like:

and the interface is not down of course.

dchard · May 3, 2023, 4:43pm

As this seems to be a Netifd issue, lets see if @hauke or @nbd can join us, hopefully they can shed some lite on this.

dchard · June 9, 2023, 6:59pm

Today LED control just got worse.

The previous issue with the Wireless interface not going down when disabled is still happening on latest master, but today I noticed that something changed recently (last 2-3 weeks) and the PPP interface also triggers the netdev led trig somehow although the interface never reaches UP state:

Fri Jun  9 19:52:37 2023 daemon.notice pppd[17021]: Modem hangup
Fri Jun  9 19:52:37 2023 daemon.notice pppd[17021]: Connection terminated.
Fri Jun  9 19:52:38 2023 daemon.info pppd[17021]: Exit.
Fri Jun  9 19:52:38 2023 daemon.notice netifd: Interface 'LTE' is now down
Fri Jun  9 19:52:38 2023 daemon.notice netifd: Interface 'LTE' is setting up now
Fri Jun  9 19:52:40 2023 daemon.notice pppd[17155]: pppd 2.4.9 started by root, uid 0
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: abort on (BUSY)
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: abort on (NO CARRIER)
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: abort on (ERROR)
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: report (CONNECT)
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: timeout set to 10 seconds
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: send (AT&F^M)
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: expect (OK)
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: AT&F^M^M
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: OK
Fri Jun  9 19:52:41 2023 local2.info chat[17156]:  -- got it
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: send (ATE1^M)
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: expect (OK)
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: ^M
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: ATE1^M^M
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: OK
Fri Jun  9 19:52:41 2023 local2.info chat[17156]:  -- got it
Fri Jun  9 19:52:41 2023 local2.info chat[17156]: send (AT+CGDCONT=1,"IP",""^M)
Fri Jun  9 19:52:42 2023 local2.info chat[17156]: timeout set to 30 seconds
Fri Jun  9 19:52:42 2023 local2.info chat[17156]: expect (OK)
Fri Jun  9 19:52:42 2023 local2.info chat[17156]: ^M
Fri Jun  9 19:52:42 2023 local2.info chat[17156]: AT+CGDCONT=1,"IP",""^M^M
Fri Jun  9 19:52:42 2023 local2.info chat[17156]: OK
Fri Jun  9 19:52:42 2023 local2.info chat[17156]:  -- got it
Fri Jun  9 19:52:42 2023 local2.info chat[17156]: send (ATD*99***1#^M)
Fri Jun  9 19:52:42 2023 local2.info chat[17156]: expect (CONNECT)
Fri Jun  9 19:52:42 2023 local2.info chat[17156]: ^M
Fri Jun  9 19:52:42 2023 local2.info chat[17156]: ATD*99***1#^M^M
Fri Jun  9 19:52:42 2023 local2.info chat[17156]: CONNECT
Fri Jun  9 19:52:42 2023 local2.info chat[17156]:  -- got it
Fri Jun  9 19:52:42 2023 local2.info chat[17156]: send ( ^M)
Fri Jun  9 19:52:42 2023 daemon.info pppd[17155]: Serial connection established.
Fri Jun  9 19:52:42 2023 kern.info kernel: [ 8590.393083] 3g-LTE: renamed from ppp0
Fri Jun  9 19:52:42 2023 daemon.info pppd[17155]: Renamed interface ppp0 to 3g-LTE
Fri Jun  9 19:52:42 2023 daemon.info pppd[17155]: Using interface 3g-LTE
Fri Jun  9 19:52:42 2023 daemon.notice pppd[17155]: Connect: 3g-LTE <--> /dev/ttyUSB3

The LED is only off between Interface 'LTE' is now down and Serial connection established. and stays ON during the 15 seconds redial timeout. Again: this modem never reaches connected state so the LED should be (and always been) OFF.

The difference between thetwo issues is that the Wireless IF never goes to a DOWN state, in this case PPP never reaches UP state yet the LED is ON.

Would be really nice to get some help with this @nbd @hauke

dchard · June 10, 2023, 8:39am

@Ansuel Reverting to commit 223004b4d6e5d17c0ae99e15d0f4c591676b4f44 (kernel: bump 5.15 to 5.15.114) fixes the PPP interface LED issue, this proves that this was really a recent change from the last 10 days. I will try to narrow down on it.

Ansuel · July 17, 2023, 8:40pm

@dchard https://git.openwrt.org/?p=openwrt/openwrt.git;a=commit;h=b993a00b82b1bdd682199e44eb81a70dee78e5c9

can you test this new commit?

dchard · July 19, 2023, 10:19am

Just tried latest master, same behavior as before.

dchard · September 26, 2023, 10:41pm

FYI, I tested an IPQ4019 target on the new 6.1 kernel and even with routerboot-v7 (John's patch sets for routerboot-v7 and LZ77) it works fine. This was just a quick compile and flash test, more in depth perf tests will follow in the next couple weeks.

And the netdev problem seems to be solved in the last 2 weeks by Felix's patches of netifd.