Bug 272732 - hostapd error with rtwn0: MAC/BB RTL8192EU, RF 6052 2T2R
Summary: hostapd error with rtwn0: MAC/BB RTL8192EU, RF 6052 2T2R
Status: Open
Alias: None
Product: Base System
Classification: Unclassified
Component: wireless (show other bugs)
Version: 13.2-STABLE
Hardware: arm64 Any
: --- Affects Some People
Assignee: freebsd-wireless (Nobody)
URL:
Keywords:
Depends on:
Blocks: 283172
  Show dependency treegraph
 
Reported: 2023-07-26 10:33 UTC by Henri Hennebert
Modified: 2024-12-07 01:07 UTC (History)
5 users (show)

See Also:


Attachments
another kp (81.16 KB, image/png)
2024-03-15 10:43 UTC, zxystd
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Henri Hennebert 2023-07-26 10:33:12 UTC
uname -a
FreeBSD norquay.restart.bel 13.2-STABLE FreeBSD 13.2-STABLE #0 stable/13-n255878-7938d643d227: Tue Jul 25 04:11:57 CEST 2023     root@norquay.restart.bel:/usr/obj/usr/src/arm64.aarch64/sys/ROCKPRO64 arm64

ifconfig wlan0
wlan0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
	ether 50:3e:aa:7a:f5:19
	inet 192.168.20.1 netmask 0xffffff00 broadcast 192.168.20.255
	groups: wlan
	ssid norquay channel 6 (2437 MHz 11g ht/20) bssid 50:3e:aa:7a:f5:19
	regdomain FCC country US authmode OPEN privacy OFF txpower 30
	scanvalid 60 protmode CTS ht20 ampdulimit 64k ampdudensity 16 shortgi
	-stbc -ldpc -uapsd wme dtimperiod 1 -dfs
	parent interface: rtwn0
	media: IEEE 802.11 Wireless Ethernet autoselect mode 11ng <hostap>
	status: running
	nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>

Starting hostapd.
ioctl[SIOCS80211, op=17, val=1, arg_len=0]: Network is down
Could not set PrivacyInvoked for interface wlan0
ioctl[SIOCS80211, op=21, val=0, arg_len=42]: Network is down
wlan0: Could not connect to kernel driver
ioctl[SIOCS80211, op=21, val=0, arg_len=42]: Network is down
ioctl[SIOCS80211, op=17, val=0, arg_len=0]: Network is down
ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Network is down
ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Network is down
ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Network is down
ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Network is down
ioctl[SIOCS80211, op=17, val=0, arg_len=0]: Network is down
ioctl[SIOCS80211, op=95, val=208, arg_len=0]: Network is down
ioctl[SIOCS80211, op=7, val=4, arg_len=0]: Network is down
Interface initialization failed
wlan0: interface state UNINITIALIZED->DISABLED
wlan0: AP-DISABLED 
wlan0: Unable to setup interface.
wlan0: interface state DISABLED->DISABLED
ioctl[SIOCS80211, op=21, val=0, arg_len=42]: Network is down
wlan0: Could not connect to kernel driver
ioctl[SIOCS80211, op=21, val=0, arg_len=42]: Network is down
ioctl[SIOCS80211, op=17, val=0, arg_len=0]: Network is down
ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Network is down
ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Network is down
ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Network is down
ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Network is down
wlan0: AP-DISABLED 
wlan0: CTRL-EVENT-TERMINATING 
hostapd_free_hapd_data: Interface wlan0 wasn't started
/etc/rc.d/hostapd: WARNING: failed to start hostapd

copying hostapd from a previous version: stable/13-n254933-298d6896b0ac

solve the problem:

service hostapd restart
hostapd not running? (check /var/run/hostapd.pid).
Starting hostapd.
wlan0: interface state UNINITIALIZED->ENABLED
wlan0: AP-ENABLED 

I check the git repository and I can't find update to usr.sbin/wpa since stable/13-n254933-298d6896b0ac
Comment 1 Stéphane Rochoy 2024-03-05 07:57:15 UTC
Same problem here. The `usr/sbin/hostapd` taken from 13.2-RELEASE is OK while the 13.3-RELEASE's one is not.
Comment 2 Stéphane Rochoy 2024-03-05 08:15:13 UTC
The only change I see in `contrib/wpa` between release/13.2.0 and release/13.3.0 revolve around the fact that we now disable the interface (clear IFF_UP via SIOCSIFFLAGS) while configuring it. This new behavior ring a bell with regard to the `Network is down` errors ;)
Comment 3 Stéphane Rochoy 2024-03-05 08:26:50 UTC
Blaming show that IFF_UP is cleared due to ded53e898c7be6d610e94c1746fd22304f5c5988. Here is an extract from the commit message that suggest we're probably chasing a race condition:

There is a hypothesis still pondered that the entire IFF_UP toggling
only exploits a race in net80211 (see further discssussions for more
debugging and alternative solutions see D38508 and D38753).
That may also explain why the changes to the rc startup script [1]
only helped partially for some people to no longer see the
continuous CTRL-EVENT-SCAN-FAILED.
Comment 4 Bjoern A. Zeeb freebsd_committer freebsd_triage 2024-03-05 20:07:30 UTC
(In reply to Stéphane Rochoy from comment #3)

I checked the window of commits from the original report (narrows it down a lot more than the two releases) and didn't spot any relevant net80211 changes which would report ENETDOWN.

Assuming it was that contrib/wpa change (unclear why no one sees the problem on other branches):

- what is the status of wlan0 after starting hostpad?  Is it still UP?

- has hostapd logged any changes of the interface status (to log or syslog, not the console); search for IFF_UP.

And out of curiosity, same hardware or different one?
Comment 5 Cy Schubert freebsd_committer freebsd_triage 2024-03-05 20:24:10 UTC
A lot of fixes have been MFCed since 7938d643d227 (Fri Jul 7 00:21:01 2023). Let's update to the the latest 13-STABLE first.

Also, please post your hostapd.conf.

Also, I had just tested this with this chipset last week on 15-CURRENT. 15-CURRENT has WPA commits that 7938d643d227 does not (which are already in stable/13 HEAD already). So we don't chase bugs that have already been fixed, let's update to the latest 13-STABLE first. If the problem persists we can chase this bug down.
Comment 6 Cy Schubert freebsd_committer freebsd_triage 2024-03-05 20:33:18 UTC
Another option, is to install net/hostapd. It contains all the fixes that have been MFCed to stable/13 + one pending fix that will be MFCed in a month. This will help isolate the problem if updating to the latest stable/13 cannot be performed for one reason or another.
Comment 7 Stéphane Rochoy 2024-03-06 07:36:11 UTC
I'll try both: upgrade to latest stable/13 and in case of no relevant change, install net/hostapd. I'll also provide the requested info: chip name, hostapd.conf, hostapd logs and interface IFF_up changes.
Comment 8 Stéphane Rochoy 2024-03-07 07:26:05 UTC
I upgraded (using handbook's procedure[1]) to latest stable/13, namely 8c6964b779ce (2024-03-05 00:18:58 +0000) and didn't notice any improvement. 

[1] https://docs.freebsd.org/en/books/handbook/cutting-edge/

When the hardware is plugged, its LED start to blink and here's what written to msgbuf:

rtwn0 on uhub2
rtwn0: <802.11n NIC > on usbus2
rtwn0: MAC/BB RTL8192EU, RF 6052 2T2R
rtwn0: 11b rates: 1Mbps 2Mbps 5.5Mbps 11Mbps
rtwn0: 11g rates: 1Mbps 2Mbps 5.5Mbps 11Mbps 6Mbps 9Mbps 12Mbps 18Mbps 24Mbps 36Mbps 48Mbps 54Mbps
rtwn0: 2T2R
rtwn0: 11ng MCS 20MHz
rtwn0: MCS 0-7: 6.5Mbps - 65Mbps
rtwn0: MCS 8-15: 13Mbps - 130Mbps
rtwn0: 11ng MCS 20MHz SGI
rtwn0: MCS 0-7: 7Mbps - 72Mbps
rtwn0: MCS 8-15: 14.5Mbps - 144.5Mbps
wlan0: bpf attached
wlan0: Ethernet address: 28:87:ba:77:e2:0c
firmware: 'rtwn-rtl8192eufw' version 111: 31818 bytes loaded at 0xffffffff82ef7000
pflog0: bpf attached
pflog0: promiscuous mode enabled
rtwn0: rtwn_tx_beacon_check: cannot push beacon into chip, error 60!
rtwn0: unable to push beacon into the chip, error 60
rtwn0: rtwn_newstate: could not move to RUN state

and here's what `ifconfig wlan0` say:

wlan0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
	ether 28:87:ba:77:e2:0c
	inet 172.28.199.56 netmask 0xfffc0000 broadcast 172.31.255.255
	groups: wlan
	ssid Hu0eenee channel 10 (2457 MHz 11g ht/20) bssid 28:87:ba:77:e2:0c
	regdomain ETSI country FR authmode OPEN privacy OFF txpower 30
	scanvalid 60 protmode CTS ht20 ampdulimit 64k ampdudensity 16 shortgi
	-stbc -ldpc -uapsd wme dtimperiod 1 -dfs
	parent interface: rtwn0
	media: IEEE 802.11 Wireless Ethernet autoselect mode 11ng <hostap>
	status: running
	nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL>

As vendor and product IDs cannot be seen in msgbuf, here's content of the `dev.rtwn.0` sysctl node:

dev.rtwn.0.rx_buf_size: 24
dev.rtwn.0.ratectl_selected: 1
dev.rtwn.0.ratectl: 1
dev.rtwn.0.hwcrypto: 1
dev.rtwn.0.debug: 0
dev.rtwn.0.ht40: 0
dev.rtwn.0.%parent: uhub1
dev.rtwn.0.%pnpinfo: vendor=0x2357 product=0x0109 devclass=0x00 devsubclass=0x00 devproto=0x00 sernum="00e04c000001" release=0x0200 mode=host intclass=0xff intsubclass=0xff intprotocol=0xff
dev.rtwn.0.%location: bus=2 hubaddr=1 port=4 devaddr=4 interface=0 ugen=ugen2.4
dev.rtwn.0.%driver: rtwn
dev.rtwn.0.%desc: 802.11n NIC

My /etc/hostapd.conf is as follow:

debug=2
accept_mac_file=/etc/hostapd.accept
ap_isolate=1
auth_algs=3
#channel=0
ctrl_interface=/var/run/hostapd
#driver=bsd
hw_mode=g
#ignore_broadcast_ssid=0
interface=wlan0
macaddr_acl=1
wpa=2
wpa_pairwise=CCMP
wpa_passphrase=PASSWORD
wpa_key_mgmt=WPA-PSK

(I tried to be clever by adding `debug=2` to later discover it is deprecated x_x)
And here's what happen when I `service start hostapd`:

Starting hostapd.
Configuration file: /etc/hostapd.conf
Line 2: DEPRECATED: 'debug' configuration variable is not used anymore
bsd_ctrl_iface: if wlan0 (changed) enable 0 IFF_UP 0
BSS count 1, BSSID mask 00:00:00:00:00:00 (0 bits)
Completing interface initialization
hostapd_setup_bss(hapd=0x16dc9433f000 (wlan0), first=1)
bsd_set_privacy: enabled=0
bsd_set_key: alg=0 addr=0x0 key_idx=0 set_tx=0 seq_len=0 key_len=0
bsd_del_key: key_idx=0
bsd_set_key: alg=0 addr=0x0 key_idx=1 set_tx=0 seq_len=0 key_len=0
bsd_del_key: key_idx=1
bsd_set_key: alg=0 addr=0x0 key_idx=2 set_tx=0 seq_len=0 key_len=0
bsd_del_key: key_idx=2
bsd_set_key: alg=0 addr=0x0 key_idx=3 set_tx=0 seq_len=0 key_len=0
bsd_del_key: key_idx=3
Using interface wlan0 with hwaddr 28:87:ba:77:e2:0c and ssid "Hu0eenee"
Deriving WPA PSK based on passphrase
SSID - hexdump_ascii(len=8):
     48 75 30 65 65 6e 65 65
PSK (ASCII passphrase) - hexdump_ascii(len=8) [REMOVED]
PSK (from passphrase) - hexdump_ascii(len=32) [REMOVED]
bsd_set_ieee8021x: enabled=1
bsd_configure_wpa: enable WPA= 0x2

From here, the LED on the device is OFF and there's a delay of ~30 seconds before:

…
Could not remove generic information element from interface wlan0
bsd_set_ieee8021x: enabled=0
ioctl[SIOCS80211, op=7, val=4, arg_len=0]: Network is down
Interface initialization failed
wlan0: interface state UNINITIALIZED->DISABLED
wlan0: AP-DISABLED
wlan0: Unable to setup interface.
…

(I transcribed most of the messages from a screenshot, I didn't investigate the reason why all this messages were not part of /var/log/daemon.log or /var/log/debug.log)

I didn't have time to install net/hostapd. I'll try that today or tomorrow.
Comment 9 Bjoern A. Zeeb freebsd_committer freebsd_triage 2024-03-09 19:31:11 UTC
Given it's USB you get the information with

usbconfig -d 2.4 dump_device_desc

but the sysctl has most of that.

The problem seems to be:

rtwn_tx_beacon_check: cannot push beacon into chip, error 60!

which comes from sys/dev/rtwn/if_rtwn_beacon.c

I would try to start enabling debug in the driver (and you need to re-compile your kernel again and install it afterwards):

diff --git sys/dev/rtwn/if_rtwn_debug.h sys/dev/rtwn/if_rtwn_debug.h
index fa1b50b551b5..67d4ed1c60b9 100644
--- sys/dev/rtwn/if_rtwn_debug.h
+++ sys/dev/rtwn/if_rtwn_debug.h
@@ -23,6 +23,7 @@
 
 #include "opt_rtwn.h"
 
+#define RTWN_DEBUG
 #ifdef RTWN_DEBUG
 enum {
        RTWN_DEBUG_XMIT         = 0x00000001,   /* basic xmit operation */



With that a sysctl dev.rtwn.0.debug should show up which one can set according to the values in the  if_rtwn_debug.h file to gather more data;  I would start with

sysctl dev.rtwn.0.debug=0x101   # BEACON | TX
Comment 10 zxystd 2024-03-15 10:43:05 UTC
Created attachment 249184 [details]
another kp

I can reproduce this issue in vmware machine, the device initials normal at first time, but after `service hostapd restart` command, the issue reproduced. When I unplug and plug again, the device working again.

There is another kernel panic issue as the attachment shows, I don't know if it can be reproduced, just add a record here.

BTW, my device is RTL88EU, freebsd 15.0-current.
Comment 11 zxystd 2024-03-15 10:44:38 UTC
I can reproduce this issue in vmware machine, the device initials normal at first time, but after `service hostapd restart` command, the issue reproduced. When I unplug and plug again, the device working again.

There is another kernel panic issue as the attachment shows, I don't know if it can be reproduced, just add a record here.

BTW, my device is RTL88EU, freebsd 15.0-current.