Date: Tue, 21 Oct 2025 08:40:31 -0700 From: Cy Schubert <Cy.Schubert@cschubert.com> To: Andriy Gapon <avg@FreeBSD.org> Cc: Adrian Chadd <adrian.chadd@gmail.com>, "freebsd-wireless@freebsd.org" <wireless@freebsd.org> Subject: Re: wlan: UP but not RUNNING ? Message-ID: <20251021154031.89840380@slippy.cwsent.com> In-Reply-To: <c621ce9d-9956-4a14-bf7f-d37aa7cd4b0e@FreeBSD.org> References: <8ed936d2-242a-4dca-a38b-1117b41e87ef@FreeBSD.org> <6a2e22ae-b8f9-46de-8a0f-881d7c01ceb0@FreeBSD.org> <81321964-801f-497b-ab46-d8866401e900@FreeBSD.org> <CAJ-VmonbRK1-mVcHs83sHNQYwXqxoy3nAGiQDmJ0mNaBw_eP8A@mail.gmail.com> <fb65a8f3-bfa6-46a7-82ca-58eebbc65cff@freebsd.org> <c621ce9d-9956-4a14-bf7f-d37aa7cd4b0e@FreeBSD.org>
index | next in thread | previous in thread | raw e-mail
In message <c621ce9d-9956-4a14-bf7f-d37aa7cd4b0e@FreeBSD.org>, Andriy Gapon
wri
tes:
> 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 pict
> ure
> > 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_lock
> ed
> >
> > wlan0: ieee80211_new_state_locked:2751: starting state update INIT -> INIT
> (SCAN)
> > wlan0: ieee80211_new_state_locked: INIT -> SCAN (arg 0) (nrunning 0 nscanni
> ng 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 nscanni
> ng 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 0x000104
> 80
> > wlan0: ieee80211_new_state_locked:2751: starting state update SCAN -> SCAN
> (RUN)
> > wlan0: ieee80211_new_state_locked: SCAN -> RUN (arg -1) (nrunning 0 nscanni
> ng 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 nscannin
> g 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 nscann
> ing 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.
This was inserted by 0da2c91e6452 after an update. I don't recall which
version of hostap.
>
> So, two observations:
> - there was / is some bad interaction with hostapd that made the down+up danc
Yes, there was at the time. Looking at the commit log, it was you who
reported the initial problem.
> e
> necessary;
> - there is some race that the dance without the sleep exposes.
There may be. A lot has changed in the kernel since then. We should test
removing the down/up. It may no longer be necessary.
>
> 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 nscanni
> ng 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 0x000104
> 80
> > wlan0: ieee80211_new_state_locked:2751: starting state update SCAN -> SCAN
> (RUN)
> > wlan0: ieee80211_new_state_locked: RUN -> RUN (arg -1) (nrunning 0 nscannin
> g 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 0x000104
> 80
> > wlan0: ieee80211_new_state_locked:2751: starting state update RUN -> RUN (R
> UN)
> > wlan0: ieee80211_new_state_locked: RUN -> RUN (arg -1) (nrunning 0 nscannin
> g 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 doi
> ng
> > 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, obvious
> ly, 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 stat
> e
> >> machinery.
> >>
> >> I tried to catch the state transitions with wlandebug_wlan0 in rc.c
> onf but
> >> apparently that changes timing enough to mask the issue.
> >>
> >> -- Andriy Gapon
> >>
> >
> >
>
>
> --
> Andriy Gapon
--
Cheers,
Cy Schubert <Cy.Schubert@cschubert.com>
FreeBSD UNIX: <cy@FreeBSD.org> Web: https://FreeBSD.org
NTP: <cy@nwtime.org> Web: https://nwtime.org
e**(i*pi)+1=0
help
Want to link to this message? Use this
URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20251021154031.89840380>