Re: wlan: UP but not RUNNING ?

From: Andriy Gapon <avg_at_FreeBSD.org>
Date: Tue, 21 Oct 2025 15:24:29 UTC
On 21/10/2025 18:11, Andriy Gapon wrote:
> On 21/10/2025 17:10, Adrian Chadd wrote:
>> hi,
>>
>> Ok, let's file a PR with what you have and then dig into it a bit more!
> 
> Okay, I can / should do that.
> But just now I've got a little bit lucky and got some trace.
> It contains only state transitions and only for wlan0, so a lot of the picture 
> is missing, but maybe there is something in it.
> 
> wlan0: start running, 0 vaps running
> wlan0: ieee80211_start_locked: up parent ath0
> wlan0: start running, 1 vaps running
>         ^^^^^ these look like competing calls to ieee80211_start_locked
> 
> wlan0: ieee80211_new_state_locked:2751: starting state update INIT -> INIT (SCAN)
> wlan0: ieee80211_new_state_locked: INIT -> SCAN (arg 0) (nrunning 0 nscanning 0)
> wlan0: ieee80211_newstate_cb:2567: running state update INIT -> SCAN (1)
> wlan0: ieee80211_newstate_cb: INIT -> INIT arg 0 -> SCAN arg 0
> wlan0: hostap_newstate: INIT -> INIT (0)
> wlan0: ieee80211_swscan_cancel_scan: called; F_SCAN=0, vap=nomatch, signal=0
> wlan0: ieee80211_new_state_locked:2751: starting state update INIT -> INIT (SCAN)
> wlan0: ieee80211_new_state_locked: INIT -> SCAN (arg 0) (nrunning 0 nscanning 0)
> wlan0: ieee80211_newstate_cb:2567: running state update INIT -> SCAN (1)
> wlan0: ieee80211_newstate_cb: INIT -> SCAN arg 0
> wlan0: hostap_newstate: INIT -> SCAN (0)
> wlan0: ieee80211_swscan_cancel_scan: called; F_SCAN=0, vap=nomatch, signal=0
> wlan0: ieee80211_create_ibss: creating HOSTAP on channel 11n flags 0x00010480
> wlan0: ieee80211_new_state_locked:2751: starting state update SCAN -> SCAN (RUN)
> wlan0: ieee80211_new_state_locked: SCAN -> RUN (arg -1) (nrunning 0 nscanning 0)
> wlan0: ieee80211_init
> wlan0: start running, 1 vaps running
>         ^^^^^ ieee80211_start_locked is called yet again
> 
> wlan0: ieee80211_new_state_locked:2751: starting state update SCAN -> SCAN (SCAN)
> wlan0: ieee80211_new_state_locked: RUN -> SCAN (arg 0) (nrunning 0 nscanning 0)
> wlan0: stop running, 1 vaps running
>         ^^^^ ieee80211_stop_locked is called, it would clear IFF_DRV_RUNNING
> 
> wlan0: ieee80211_new_state_locked:2751: starting state update SCAN -> SCAN (INIT)
> wlan0: ieee80211_new_state_locked: SCAN -> INIT (arg -1) (nrunning 0 nscanning 0)
> wlan0: ieee80211_swscan_cancel_scan: called; F_SCAN=0, vap=nomatch, signal=0
> wlan0: down parent ath0
>         ^^^^ there was only one running VAP so the driver is stopped

So, much investigation and now I kind of circled back to my local change...
I think that the problem is with hostapd_poststart() function in 
/etc/rc.d/hostapd and my change to it:
         if [ -n "$ifn" ]; then
                 ifconfig ${ifn} down
                 #sleep 2
                 ifconfig ${ifn} up
         fi

My change was commenting out the sleep.

So, two observations:
- there was / is some bad interaction with hostapd that made the down+up dance 
necessary;
- there is some race that the dance without the sleep exposes.

Bcc-ed Cy, just in case.

>         vvvv state transitions continue, though
> wlan0: ieee80211_newstate_cb:2567: running state update SCAN -> RUN (1)
> wlan0: ieee80211_newstate_cb: SCAN -> INIT arg 0 -> RUN arg -1
> wlan0: hostap_newstate: SCAN -> INIT (0)
> wlan0: ieee80211_swscan_cancel_scan: called; F_SCAN=0, vap=nomatch, signal=0
> wlan0: ieee80211_new_state_locked:2751: starting state update INIT -> INIT (RUN)
> wlan0: ieee80211_new_state_locked: INIT -> RUN (arg -1) (nrunning 0 nscanning 0)
> wlan0: ieee80211_newstate_cb:2567: running state update INIT -> SCAN (1)
> wlan0: ieee80211_newstate_cb: INIT -> SCAN arg 0
> wlan0: hostap_newstate: INIT -> SCAN (0)
> wlan0: ieee80211_swscan_cancel_scan: called; F_SCAN=0, vap=nomatch, signal=0
> wlan0: ieee80211_create_ibss: creating HOSTAP on channel 11n flags 0x00010480
> wlan0: ieee80211_new_state_locked:2751: starting state update SCAN -> SCAN (RUN)
> wlan0: ieee80211_new_state_locked: RUN -> RUN (arg -1) (nrunning 0 nscanning 0)
> wlan0: ieee80211_newstate_cb:2567: running state update SCAN -> INIT (1)
> wlan0: ieee80211_newstate_cb: SCAN -> INIT arg -1
> wlan0: hostap_newstate: SCAN -> INIT (-1)
> wlan0: ieee80211_swscan_cancel_scan: called; F_SCAN=0, vap=nomatch, signal=0
> wlan0: ieee80211_newstate_cb:2567: running state update INIT -> RUN (1)
> wlan0: ieee80211_newstate_cb: INIT -> RUN arg -1
> wlan0: hostap_newstate: INIT -> RUN (-1)
> wlan0: ieee80211_swscan_cancel_scan: called; F_SCAN=0, vap=nomatch, signal=0
> wlan0: ieee80211_create_ibss: creating HOSTAP on channel 11n flags 0x00010480
> wlan0: ieee80211_new_state_locked:2751: starting state update RUN -> RUN (RUN)
> wlan0: ieee80211_new_state_locked: RUN -> RUN (arg -1) (nrunning 0 nscanning 0)
> wlan0: ieee80211_newstate_cb:2567: running state update RUN -> RUN (1)
> wlan0: ieee80211_newstate_cb: RUN -> RUN arg -1
> wlan0: hostap_newstate: RUN -> RUN (-1)
> wlan0: ieee80211_swscan_cancel_scan: called; F_SCAN=0, vap=nomatch, signal=0
> wlan0: ieee80211_newstate_cb:2567: running state update RUN -> RUN (1)
> wlan0: ieee80211_newstate_cb: RUN -> RUN arg -1
> wlan0: hostap_newstate: RUN -> RUN (-1)
> wlan0: ieee80211_swscan_cancel_scan: called; F_SCAN=0, vap=nomatch, signal=0
> 
> The VAP ends up in RUN state, but there hasn't been another 
> ieee80211_start_locked call since the ieee80211_stop_locked call, so the 
> interface is not RUNNING.
> 
> Now, the only thing is to figure out what hostapd and network.subr were doing 
> with wlan0... :-)
>> On Tue, 21 Oct 2025 at 06:30, Andriy Gapon <avg@freebsd.org 
>> <mailto:avg@freebsd.org>> wrote:
>>
>>     On 21/10/2025 16:05, Andriy Gapon wrote:
>>      > It seems that the problem happens because the VAP is already in
>>     IEEE80211_S_RUN
>>      > state somehow and ieee80211_start_locked is not called, obviously, in
>>      > SIOCSIFFLAGS handling code.
>>
>>     I have this DTrace output to confirm that:
>>
>>     ieee80211_ioctl:entry wlan0 cmd 0x80206910 flags 0x8902 drv flags 0 state 5
>>     ieee80211_ioctl:entry wlan0 cmd 0x80206910 flags 0x8903 drv flags 0 state 5
>>
>>     So, the VAP state is indeed IEEE80211_S_RUN.
>>     But IFF_RUNNING / IFF_DRV_RUNNING is not set in either if_flags or 
>> if_drv_flags.
>>
>>     Looks like something set the VAP state bypassing the interface state 
>> machinery.
>>
>>     I tried to catch the state transitions with wlandebug_wlan0 in rc.conf but
>>     apparently that changes timing enough to mask the issue.
>>
>>     --     Andriy Gapon
>>
> 
> 


-- 
Andriy Gapon